log.isTraceEnabled() and performance

[timfox]

In performance critical sections of the code we should avoid code like:

if (log.isTraceEnabled())
{
 log.trace("Something");
}

The problem is that the call to log.isTraceEnabled() actually takes up significant time. This is why you'll see in the code the following:

if (trace)
{
 log.trace("okjok");
}

Instead.

[ataylor]

The trouble is with the second piece of code, changes to the log level at runtime might not get picked up. saying that I'd prefer to have the performance increase and maybe lose some logging.

[trustin]

What about just not calling isTraceEnabled() and call log.trace() directly? It should perform better when the message is simple enough.

[clebert.suconic]

That's terrible.

You would be doing lots of string concatenations to just throw them away on the limbo of the Garbage Collection.


Example:


log.trace("This is a concatenation of " + myObject + " with anthing such as = " + anInteger + " just to show how dumb strings are");

[clebert.suconic]

ok.. I missed the "when the message is simple enough" part.


Still better to not call it when trace is not set IMO.

[timfox]

Still better to not call it when trace is not set IMO.

Yes, log.isTraceEnabled() has a significant overhead.

Actually in JBM 1.4 approx 3% of time was spent in log.isTraceEnabled() calls until we changed it to check a static flag "trace"! (Admittedly we had a lot of log.isTraceEnabled() calls).

Moral of the story: Don't assume that log.isTraceEnabled() (or log.isDebugEnabled()) is a fast call, and never put it in performance critical sections.