Search This Blog

Clean code, clean logs: use appropriate tools (1/10)

Many programmers seem to forget how logging application behavior and its current activity is important. When somebody puts:

log.info("!@#$%");

happily somewhere in the code, he probably don't realize the importance of application logs during maintenance, tuning and failure identification. Underestimating the value of good logs is a terrible mistake. I have collected few random advices that I find especially useful when it comes to writing logging routines and I will present them in a series of short articles. First tip (out of ten) is about logging libraries and tools.

In my opinion, SLF4J is the best logging API available, mostly because of a great pattern substitution support:

This is not only longer and less readable, but also inefficient because of extensive use of string concatenation. SLF4J adds nice {} substitution feature. Also, because string concatenation is avoided and toString() is not called if the logging statement is filtered, there is no need for isDebugEnabled() anymore. BTW, have you noticed single quotes around filter string parameter?

SLF4J is just a façade, as an implementation I would recommend Logback framework, already advertised on my blog, instead of well established Log4J. It has many interesting features (some of them will be discussed in future tips) and, in contrary to Log4J, is actively developed.

Perf4J is to System.currentTimeMillis() as log4j is to System.out.println()

I've added Perf4J to one existing application under heavy load and seen it in action in few other. Both administrators and business users were impressed by the nice graphs produced by this simple utility. Also we were able to discover performance flaws in no time. Perf4J itself deserves its own article, but for now just check their Developer Guide.

As you can see, no matter which logging framework is used (we don't even have Log4J and Commons-Logging on our CLASSPATH, see 99.0-does-not-exist version!), every logging statement is printed using Logback (see how it works). So even if your favorite libraries stick to Commons-Logging (very bad thing! [1], [2]) or even worse to Log4J, you don't need to include them in your project.

Thanks Tomasz.Recently I've wrote some tests whether should we use if (logger.isDebugEnabled()or skip it and always log debug info because the overhead is little.I regret the article is in Polish.http://zdanek.ostrejezyki.pl/2010/04/16/develop/w-koncu-logowac-z-if-isdebugenabled-czy-nie/

Thank you Bartek for the reference to Your article. I will try to find some time and perform similar benchmark for SLF4J and Logback duo. Thanks to "{}" pattern substitution feature and faster is*Enabled() implementation, the difference would probably be unnoticeable.

great post man, indeed quite useful logging tips in java. In my opinion using correct logging level for different message is most important thing to learn and logging has important performance impact (ever found process running in DEBUG mode in production ) and has to be handled efficiently. I have also blogged my tips as 10 tips on logging in Java , let me know how do you find it.

@Henry Ho: maybe it does, maybe not (see below). The point is you don't have to perform these nasty and verbose string concatenations yourself. Also isDebugEnabled() is no longer needed since the concatenation happens only when the logging statement is actually printed.

@Steven: True, but the official API states: SLF4J's implementation is 10 times faster than that of MessageFormat.

@Javin Paul: Thanks, I had quick look at your article. I don't agree with everything, but it's a nice resource.

Well, there's wasn't much activity in 2.x branch of log4j, and 1.2.x was only bugfixed without new features. I see this version is now in alpha and it will probably take a while until it's production ready. But it would be great to see two good logging frameworks around.

"which does lose logging events when it is under reconfiguration" - you probably meant: "doesn't"?