Log4j in Spring

Spring uses commons-logging for logging solution. However, most developers prefer Log4j. Here is a couple points I think need to be noted when use Log4j with Spring.

First, Spring 2.5.x uses commons-logging version 1.1 as dependency by default.  However, it has compatibility issues with Log4j 1.2. The easiest solution is simply change to commons-logging version 1.0.4.  You might notice, though, with the version change, commons-logging's trace log will become debug log.

Second, Spring actually has a few ways to configure Log4j settings.  One of my favorite is Log4jConfigurer.  It not only allows you to configure Log4j, but also give you an option to set a refresh interval to check Log4j configuration changes at runtime, which means there is no need to stop the application to make Log4j logging level, etc.

To set the refresh interval programmatically:

//initialize log4j with refresh every 5 min.
try {
    Log4jConfigurer.initLogging(getLocalLog4jConfig(), 5*60*1000);
} catch (Exception e) {
    System.out.println("Unable to initialize log4j configuration!");
}

Same configuration in Spring context:

<bean id="log4jInitialization"
    class="org.springframework.beans.factory.config.MethodInvokingFactoryBean">
    <property name="targetClass" value="org.springframework.util.Log4jConfigurer" />
    <property name="targetMethod" value="initLogging" />
    <property name="arguments">
        <list>
            <value>classpath:log4j.xml</value>
            <value>300000</value>
        </list>
    </property>
</bean>

A special note on Log4j:
There is a lot discussion on whether we should use log.isDebugEnabled() should be used.  I agree with the point that if the message doesn't need much computation, then it's not necessary to use log.isDebugEnabled() since it is checked within the log.debug(msg) call.

To verify, I also tried some testing code.  It seems to me that the initial log always takes longer than the rest logs.  So compare to running different settings in consequence, it's only fair to run them separately.

Other than that, with a 1000 loop of a simple string constant, it doesn't make much time difference (in milliseconds) whether to use log.isDebugEnabled() or not.  Same result with a message that requires simple computation.

Some people mentioned taking advantage of Java 5's new String feature and use something like String.format("some message %s", obj); where %s will be replaced by obj.  My test shows that this actually slows down logging speed instead of improving it.

Velocity Template in Web Application

I don't use Velocity a lot.  Initially, I was just using it for mail templates in a standalone application.  The setup is simple:

VelocityEngine velocity = new VelocityEngine();
velocity.setProperty(Velocity.RESOURCE_LOADER, "class");
velocity.setProperty("class.resource.loader.class",
        ClasspathResourceLoader.class.getName());
velocity.setProperty(Velocity.RUNTIME_LOG_LOGSYSTEM_CLASS,
        Log4JLogChute.class.getName());
velocity.setProperty("runtime.log.logsystem.log4j.logger", "mail");

Here I use ClasspathResourceLoader along with Log4j as logging method.

Then I decide to use Velocity again in a web application. To use Velocity in web application, however, you'll need a WebappResourceLoader.  WebappResourceLoader is available in VelocityTools.  However, you can always write your own.

Since I only needed this one class, I copied over the class from VelocityTools and made following configuration in my servlet:

VelocityEngine velocity = new VelocityEngine();
velocity.setProperty(Velocity.RESOURCE_LOADER, "webapp");
velocity.setProperty("webapp.resource.loader.class",
        WebappResourceLoader.class.getName());
velocity.setProperty("webapp.resource.loader.path", "/templates/");
velocity.setProperty(Velocity.RUNTIME_LOG_LOGSYSTEM_CLASS,
        ServletLogChute.class.getName());

I did try using Log4JLogChute, but somehow couldn't get it to log messages.