• Post Reply Bookmark Topic Watch Topic
  • New Topic

Logging and reflection/introspection  RSS feed

 
Jorge Ribeiro
Ranch Hand
Posts: 40
  • Mark post as helpful
  • send pies
  • Quote
  • Report post to moderator
Hi,

My reflection/ introspection skills are a bit rusty so I would like to ask your help. I would like to have a couple of logging methods that could log a method name and its parameters� values and the method�s return value. Let�s assume that my methods will always have a return value with the name �returnValue�. Something like:

public int A(int x, String y) {
logInit();
(�)
longEnd();
return returnValue;
}

public String B() {
logInit();
(�)
longEnd();
return returnValue;
}

Would result in something like:
-Entering method A; x = 10; y=Hello
-Leaving B; return value = 100
-Entering method B
-Leaving B; return value = Hi

Would it be possible by reflection or introspection (or by any other method) to get the method name from where logInit/logEnd was invoked, its parameter names and its values and the return value? If it is possible how could I do it? What would I have to pass as parameter to my logging methods?

Many thanks!
Paulo
 
Jim Yingst
Wanderer
Sheriff
Posts: 18671
  • Mark post as helpful
  • send pies
  • Quote
  • Report post to moderator
Not possible with reflection as far as I know, but there is a technique using getStackTrace() in the Throwable class. See this thread, or search for "getStackTrace" to find several other previous discussions here.
 
Paul Clapham
Sheriff
Posts: 22697
43
Eclipse IDE Firefox Browser MySQL Database
  • Mark post as helpful
  • send pies
  • Quote
  • Report post to moderator
As I understand it, AOP (Aspect Oriented Programming) allows you to do that sort of thing via byte-code modification. However I would question why you need to do that much logging. I can only imagine myself doing that in the last stages of desperation over not being able to track down a bug.
 
Jim Yingst
Wanderer
Sheriff
Posts: 18671
  • Mark post as helpful
  • send pies
  • Quote
  • Report post to moderator
If you're tracking a bug that resulted in a stack trace, then of course you should already have all the info you need about where you were in the code at the time the exception was thrown. But sometimes it's useful to look back at what was going on prior to the exception. Or sometimes there was no exception, but the final value of some operation is wrong, and you'd like to look back at what was happening previously. In such situations it can be convenient to have easy access to the class and line number where each log statement was generated.

Log4J, for example, has this functionalty built in. With a minor change to the log4j.xml file, you can enable it (or disable it). See the PatternLayout API. Note that all the options which rely on this technique (creating a Throwable to get the stack trace) are documented with "WARNING Generating the caller class information is slow. Thus, it's use should be avoided unless execution speed is not an issue.". That sounds a little excessively paranoid to me - even if execution speed is an issue in general, often you've got a bottleneck elsewhere that's big enough that the extra overhead of generating stack traces is trivial. Or maybe it's not trivial, but it's still worthwhile to temporarily enable the extra logging to see what's going on. Either way, the feature is available to turn on or off as you wish.

As for AOP, yes logging with context info is one of the things it's commonly used for. What's cool is that you don't have to bog down the original classes with logging code. You can even add logging to a third-party tool that you don't have source code for, only a jar file. Which can be very useful for understanding or debugging such code. Paulo, I would seriously look into AspectJ if you're going to be doing a lot of this sort of logging. AspectJ in Action has a chapter (#5) devoted to monitoring techniques: logging, tracing, and profiling.
 
Jorge Ribeiro
Ranch Hand
Posts: 40
  • Mark post as helpful
  • send pies
  • Quote
  • Report post to moderator
It seems to me that I have two good options- or I try to use the StactkTraceElement from JDK 5 or I use AspectJ. If my understanding is correct, Log4J allows the same kind of functionality, but since it supports older JDKs it makes use of a even more heavy process- creating a Throwable, printing the StackTrace and then parsing the result. I think I won't be able to force AspectJ into the project so I'll adopt the StactkTraceElement approach. But I'll definitely read the book about AspectJ.

Many thanks for the tips!

Paulo
 
Jim Yingst
Wanderer
Sheriff
Posts: 18671
  • Mark post as helpful
  • send pies
  • Quote
  • Report post to moderator
The getStackTrace() method (and the StackTraceElement class) were introduced in JDK 1.4, not 5, so there's greater backward compatibility than you thought. As for Log4J's approach - yeah, it's a bit ugly that they were forced to use printStackTrace() and parse it. But in terms of performance, the heaviest hit is probably in creating the Throwable, and you have to do that either way. The added overhead of using the pre-JDK 1.4 technique isn't really very big, I think, and Log4J does have a lot of other useful functionality ready-made for you. So I think it's worth considering. But naturally it depends on the needs of your project.
 
  • Post Reply Bookmark Topic Watch Topic
  • New Topic
Boost this thread!