Programmatically Configuring log4j - and the Future of Java Logging

log4j is probably the most common logging framework in use in the Java world. Even if a project/framework uses commons-logging most deployments configure log4j to be the underlying logger.

log4j is usually configured via a properties file (most common, in my experience) or an XML file (more powerful). There are a few situations, however, where I've found it useful to programmatically configure log4j, and since there is very little info on the web on how to do this I thought I'd write a short blog entry on the subject.

Why configure log4j programmatically?

Two situations I've found it useful to configure log4j in code are:

• During running of Unit Tests. Since unit tests are fine grained it helps to enable more verbose logging for just the area a particular test targets instead of for the whole suite. Also, if you are running single test inside your IDE you may want to output to the console, but if you run your whole suite from the command line you may want to output to a file.
  
• Changing logging dynamically via JMX. log4j has some basic JMX support, but if you want to do anything mildly complicated then you'll have to roll your own.

log4j initialization

Whenever a Logger is first used log4j goes through a default initialization procedure to find a log4j.properties or a log4j.xml configuration file. If the initialization procedure fails you typically get an error message like this:

log4j:WARN No appenders could be found for logger (net.sf.ehcache.CacheManager).
log4j:WARN Please initialize the log4j system properly.

when a Logger is used.

The simplest way to detect if log4j was initialized or not is to ask the root logger if it has any appenders attached to it:

import org.apache.log4j.Logger;

Logger root = Logger.getRootLogger();
if (!root.getAllAppenders().hasMoreElements()) {
// No appenders means log4j is not initialized!
}

A minimal default log4j configuration might be to add a single console appender to the root logger; this is in fact what the convenience method BasicConfigurator.configure() does:

import org.apache.log4j.ConsoleAppender;
import org.apache.log4j.Logger;
import org.apache.log4j.PatternLayout;

Logger root = Logger.getRootLogger();
root.addAppender(new ConsoleAppender(
    new PatternLayout(PatternLayout.TTCC_CONVERSION_PATTERN)));

If not explicitly set the default the log level will be DEBUG.

Example

So let's put these things together in a scenario: If I run my unit test suite from Ant then I add a log4j.properties to the classpath that directs log4j logging to a file. If I run a unit test from inside Eclipse then I deliberately want log4j initialization to fail, allowing me to initialize it programatically; log everything from the robertmaldon.moneymachine package to the console at DEBUG level, and log everything else to the console at INFO level.

package robertmaldon.moneymachine;

import org.junit.BeforeClass;

import org.apache.log4j.ConsoleAppender;
import org.apache.log4j.Logger;
import org.apache.log4j.PatternLayout;

public class OrderTest {

@BeforeClass
public static void classSetUp() {
  Logger rootLogger = Logger.getRootLogger();
  if (!rootLogger.getAllAppenders().hasMoreElements()) {
      rootLogger.setLevel(Level.INFO);
      rootLogger.addAppender(new ConsoleAppender(
             new PatternLayout("%-5p [%t]: %m%n")));

      // The TTCC_CONVERSION_PATTERN contains more info than
      // the pattern we used for the root logger
      Logger pkgLogger = rootLogger.getLoggerRepository().getLogger("robertmaldon.moneymachine");
      pkgLogger.setLevel(Level.DEBUG);
      pkgLogger.addAppender(new ConsoleAppender(
             new PatternLayout(PatternLayout.TTCC_CONVERSION_PATTERN)));
  }
}
}

The above code creates a new Logger and chains it to the root logger. Instances of Logger can not be instantiated directly, but have to be created from a LoggerRepository (a factory pattern).

The equivalent log4j.properties would look something like:

log4j.rootLogger=INFO, A

log4j.appender.A=org.apache.log4j.ConsoleAppender log4j.appender.A.layout=org.apache.log4j.PatternLayout
log4j.appender.A.layout.ConversionPattern=%-5p [%t]: %m%n

log4j.logger.robertmaldon.moneymachine=DEBUG, B

log4j.appender.B=org.apache.log4j.ConsoleAppender log4j.appender.B.layout=org.apache.log4j.PatternLayout
log4j.appender.B.layout.ConversionPattern=%r [%t] %p %c %x - %m%n

So not too difficult to do after all :)

The Future of Java Logging

In recent weeks I've noticed some discussion and dissension in the Java logging world.

Some implementation issues with commons-logging spurred a number of the Apache projects to switch to a replacement called SLF4j (Simple Logging Framework).

The original creator of log4j has been hard at work on a successor called LOGBack, which is an evolution of log4j rather than a revolution. e.g. smaller memory footprint, faster, better filtering and evaluation capabilities.

One feature of LOGBack that really caught my eye was that of parameterized logging. In log4j you might write logging code like:

if( logger.isDebugEnabled() ) {
  logger.debug( "User with account "
      + user.getAccount() + " failed authentication; "
      + "supplied crypted password " + user.crypt(password)
      + " does not match." );
}

The isDebugEnabled() check is usually a performance thing - there is no need to call expensive methods like the crypt() method above if the current logging level is higher than DEBUG. The equivalent code in LOGBack would be:

logger.debug( "User with account {} failed authentication; "
            + "supplied crypted password {} does not match.",
            user.getAccount(), user.crypt(password) );

which allows LOGBack to defer calling getAccount() and crypt() until it has determined that the log level will cause the logging to be generated. The less "if"s the better!

LOGBack natively implements the SLF4j APIs, but provides a bridge for applications currently using the log4j APIs. SLF4j provides a bridge for applications currently using the commons-logging APIs.