Igor Kromin |   Consultant. Coder. Blogger. Tinkerer. Gamer.

I've been going through a fair amount of code that makes excessive use of log4j guard statements like isDebugEnabled() and began mercilessly removing their use. In my mind, these statements make the code messy and are really not necessary in most situations. In terms of performance, a guard statement does not necessarily give you any kind of boost, except in some odd edge cases. To prove my point however, I wrote some code and collected data to graph, here are the results.

What I did was log a message at the DEBUG level while log4j was configured to log at the INFO level. This means nothing should appear in my logs, however the logging code still runs. I logged the same message in a loop 10,000,000 times and repeated this process 100 times to get some significant numbers. Each message was first logged without a guard statement ('No Check' in the graphs), the timing captured, and then it was logged with an if statement using the isDebugEnabled() guard statement ('Check' in the graphs), and the timing captured.

My first round of testing was with a simple log message like this:
 log4j simple message logging
LOG.debug("A log message");


The results are below. It's actually faster when a guard statement is not used. Although it is faster, it varies by a handful of milliseconds over 10 million log messages. I would call that not a significant enough to compare, so using and not using a guard statement for a simple message is identical in terms of performance. The bonus however is that your code becomes at least 2 lines shorter, and easier to read.
 log4j simple message logging
LOG.debug("A log message");
vs
if (LOG.isDebugEnabled()) {
LOG.debug("A log message");
}

log4j_timing1.png




Now my next test case did a little more with the log message. It calculated a value using the loop's increment counter first, then logged the message. This is just an example, but the point I am making is that in some cases you need to do some work to generate a log message i.e. it is not a constant string.
 log4j calculated message logging
LOG.debug("A log message " + Integer.toString(i) + Math.pow(Double.valueOf(i + ""), 1.0));


The results in this case are significantly different. Not using a guard statement will severely impact performance.
log4j_timing2.png


I would call this an edge case because it is rare that it takes so much work to generate a log message or that so much calculation is performed simply for the purpose of logging, in my experience. I have seen a few cases where certain additional processing and logging was done for debug purposes, this spanned many lines of code and in this case a guard statement was completely warranted and encouraged. However, on the most part if you are logging simple messages, there is absolutely no need to check if you should log first, because the logging framework will do that check for you anyway!

Happy logging!

-i

A quick disclaimer...

Although I put in a great effort into researching all the topics I cover, mistakes can happen. Use of any information from my blog posts should be at own risk and I do not hold any liability towards any information misuse or damages caused by following any of my posts.

All content and opinions expressed on this Blog are my own and do not represent the opinions of my employer (Oracle). Use of any information contained in this blog post/article is subject to this disclaimer.
Hi! You can search my blog here ⤵
NOTE: (2022) This Blog is no longer maintained and I will not be answering any emails or comments.

I am now focusing on Atari Gamer.