Shlomo Yona's Blog -- יומן הרשת של שלמה יונה: Oct 7, 2010

Thursday, October 7, 2010

slf4j vs. log4j

Idioms for loggers in Java code:

An often used idiom for logger configuration in Java code uses log4j. Following is a code snippet that demonstrates the usage:

Import statement:

import org.apache.log4j.Logger;

Declaration and generation example within a class:

public class Foo {

private static final Logger logger = Logger.getLogger(Foo.class);

Usage example within that class:

if(logger.isDebugEnabled()) {

logger.debug("this will be logged with the following parameters x="+x+" y="+y+" z="+z);

}

This implementation causes evaluation and string concatenation of the argument to the various log levels of the Logger class instance (logger.debug in this case) regardless whether or not that logger is indeed configured for that log-level. Imagine a situation where the log level for this class' logger is set to an ERROR log level while the logger is reporting messages in a DEBUG log level. Obviously, the logging will not be manifested in the appender that is bound to that logger for this class (as DEBUG has a lower log level than ERROR log level) but nonetheless the String concatenation for the arguments to build up the string for logging will be executed and will yield a cost regardless of the actual logging. In order to avoid that, the code tests the log level for DEBUG and only if it is enabled then the invocation of the logger.debug method is being interpreted and executed. The cost is due to the concatenation operations and due to repetitive (possibly implicit) calls to toString().

A newer implementation provides an idiom that internally tests for the effective log level and thus builds up the string (with the required concatenations) only if the log message will actually eventually be streamed to the appender. As a result, the format of the method for logging changes to something that actually evaluates strings only if the suitable log level is used. For example, when logging is disabled at the DEBUG level, the logging framework does not need to evaluate the string representation of the values.

Import statement:

import org.slf4j.Logger;

import org.slf4j.LoggerFactory;

Declaration and generation example within a class:

public class Foo {

private static final Logger logger = LoggerFactory.getLogger(Foo.class);

Usage example within that class:

logger.debug("this will be logged with the following parameters x={} y={} z={}",new Object[] {x,y,z});

So, the slow and inefficient idiom

logger.debug("this will be logged with the following parameters x="+x+" y="+y+" z="+z);

which also took additional awkwardness with the attempt to reduce its performance costs by using this idiom

if(logger.isDebugEnabled()) {

logger.debug("this will be logged with the following parameters x="+x+" y="+y+" z="+z);

}

should now be replaced with the fast and more efficient

logger.debug("this will be logged with the following parameters x={} y={} z={}",new Object {x,y,z});

It is recommended to refactor log4j idioms to slf4j idioms when working on classes that use the inefficient idioms.

It is required to use te slf4j idiom in new implementations.

Some related links: