7.4. Wrapping Log Statements

Here the discussion is not about the logging of JBoss Enterprise Application Platform but the application's own logging. It's common practice for developers to make liberal use of the code like the following example:

 log.debug(“Some text…” + Object);

There does not seem to be anything obviously wrong with the code. It states that when debug logging is turned on, the message should be written to the log. Since an application is only run with debug logging turned on when debugging is being done, you would not expect any impact on performance. In fact there is a likely impact and it occurs because of the way statements like this are evaluated by the platform. Before the statement itself is evaluated, a lot of activity occurs in preparation: creation of temporary string objects, calling the object's toString() method, creation of an internal LoggingEvent object, formatting data, getting the current date, getting the thread ID of the calling thread and so on. Once all this is complete the statement is finally evaluated and if debug logging is not enabled, the created objects are again destroyed and processing continues to the next statement. The creation of these objects takes system resources, mainly CPU cycles and memory, with the performance impact multiplied by the number of debug statements processed.

There's a method which can reduce the performance impact of using debug statements, in which they're wrapped in a boolean statement. As the following example shows, whether or not debug logging is enabled is first evaluated and only then does the processing of the debug statement occur. There is a trade-off between processing of the boolean statement versus that of the debug statement but fewer system resources are used and so the performance impact is reduced.

if (debugEnabled()) {
   log.debug(“Some text...” + Object);
}

It's not necessary to wrap every debug statement, only those which are often encountered. Take the example of a debug statement placed in a try..catch structure, where the exception is rare. Since the debug statement will only rarely be evaluated, the performance difference between wrapping and not wrapping the statement in a boolean expression is likely to be minimal. As usual, there should be a measurable gain from the effort put into performance improvements.