Hi All:

I master now, I am almost able to duplicate what my custom flow logger does.

We can do this:

   public int zoo(Path p1, String s1) {
      EntryMessage m = logger.traceEntry("zoo(p1={}, p2={})", p1, s1);

      ...
      if (...) {
         return traceExit(x, m);
      }
      ...
      return traceExit(c, m);
  }


which is nice. I am perfectly OK with writing in the method name by hand,
that's just a convention we have established at work, and it costs 0 at
runtime. Also, it can be weaved in when @LogFlow is implemented, and still
would cost 0 at runtime of course.

I describe the @LogFlow annotation in:

https://issues.apache.org/jira/browse/LOG4J2-33?focusedCommentId=15145841&page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#comment-15145841

In our app, we have some multi-threaded use cases, so it becomes important
to know /which/ object does what, not just what API is being
entered/exited.

My flow logging looks like this with:

<Pattern>%d %-5level [%t][%logger] %msg%n%throwable</Pattern>

2016-02-13 17:45:09,247 TRACE
[main][com.rs.jdbc.dv.DvSocketConnection.com.rocketsoftware.rs28.1292]
Enter 
[email protected](socket=7a6a25ab[TLS_RSA_WITH_AES_128_CBC_SHA:
Socket[addr=rs28.rocketsoftware.com/192.168.55.28,port=1292,localport=52424]],
milliseconds=0, prevMillis=0)
2016-02-13 17:45:09,247 TRACE
[main][com.rs.jdbc.dv.DvSocketConnection.com.rocketsoftware.rs28.1292] Exit
[email protected](socket=7a6a25ab[TLS_RSA_WITH_AES_128_CBC_SHA:
Socket[addr=rs28.rocketsoftware.com/192.168.55.28,port=1292,localport=52424]],
milliseconds=0, prevMillis=0) : 0

Our custom logger call site looks like this:

String m = logger.traceEntry(*this*, "zoo(p1={}, p2={})", p1, s1);


Note that "this" is passed in as a first argument, which my message builder
turns into the same format Object.toString() uses but with the class'
simple name: simpleName@hexHashCode.

Which gives us an flow message that looks like:

Enter *DvSocketConnection@4ecf3c56*.setTimeout(foo=1, bar=2)
Exit *DvSocketConnection@4ecf3c56*.setTimeout(foo=1, bar=2)

I do not use the this' toString() method because who knows what that will
give me, so I always use simpleName@hexHashCode which allows me to clearly
ID who does what. This has proved invaluable in debugging.

I would like to allow for this use case with our new traceEntry() APIs. We
could make the code generate "method(...)" vs. "[email protected]()"
depending on whether the value passed in is null vs. an Object. For example:

EntryMessage m = logger.traceEntry(*this*, "zoo(p1={}, p2={})", p1, s1);

vs.

EntryMessage m = logger.traceEntry(*null*, "zoo(p1={}, p2={})", p1, s1);


In order to do this I need to add an Object param to existing traceEntry()
methods. But I do not want to add yet more methods, to account for
traceEntry(Object, String, Object...) vs traceEntry(String, Object...), so
it would be just traceEntry(Object, String, Object...).

Thoughts?

Gary

-- 
E-Mail: [email protected] | [email protected]
Java Persistence with Hibernate, Second Edition
<http://www.manning.com/bauer3/>
JUnit in Action, Second Edition <http://www.manning.com/tahchiev/>
Spring Batch in Action <http://www.manning.com/templier/>
Blog: http://garygregory.wordpress.com
Home: http://garygregory.com/
Tweet! http://twitter.com/GaryGregory

Reply via email to