Friday, December 3, 2010

Using isInfoEnabled in Java

-Logging using log.info
 Just have the below "if" block before using log.info or log.debug or log.error
  if(log.isInfoEnabled()
 {
  log.info(yourFunctionName + " :--- " + getVeryLargeString() + someVar);
 } 
Why?
Suppose the current log4j level is set to Error then log.info messages will not be displayed, it will take only few nanoseconds to execute log method but it may take time to execute the function call, if any, in the message.
Drawback of not using if condition
1) Unnecessary call to the functions in the log.info message 
2) Many string objects will be created in the string pool
Drawback of using if condition-
1) For each and every log method call u have to have this condition, code will not be readable and not be clear much.
2) Extra if condition in many places.

Jdk1.5 has solution for this problem, it removes log calls automatically removed if they're not being used.

It is possible to do this using bytecode manipulation - searching for and removing calls to the logger as the class is loaded. The new Java 1.5 instrumentation classes make this particularly easy, by allowing ClassTransformer classes to be registered on the command line that are allowed to manipulate class files as they are loaded.

To use this code, launch Java with the arguments:
java -javaagent:net.surguy.logfilter.LogPreloader=debug [your own class]

The argument is optional, and can be one of "debug", "info", "warn", "error" or "fatal", corresponding to the standard Log4J log levels.

How does it work
As Java loads each class, it passes it to each of the registered ClassFileTransformers, which get a chance to alter its bytecode. It uses the ASM bytecode manipulation library to do so.

4 comments:

  1. Great start ... hope to many more comin ...

    ReplyDelete
  2. yeah will try to write one everyday

    ReplyDelete
  3. This is a very good topic to discuss ... Thanks megha for such a nice post ... But don't feel modifying Bytecode is really good idea .. On top of that you have to implement this transformer class .. probably you are refering to this class which uses ASM library which is a opensource version .. It is not wise to let a unsupported tool to do the bytecode manipulation which might cause issues ..
    Also this doesn't allow to modify the log level at runtime ... you can't define two different log level for different set of packages which is a common practice ... So i feel its still better to use checks even if code become clumsy

    ReplyDelete
  4. Yes Tanmoy you are right, but its just a tip i am giving to those people who are preparing for interview or wanted to research on new things. I am not sure as far as i know the implementation is done using dynamic proxy classes (Proxy design pattern).
    As you said the current shortcoming of this approach is that there is no way of changing the log level at runtime. This should be possible to fix - the instrumentation classes do allow classes to be reloaded at runtime, but I don't know how.

    ReplyDelete