Blog

Logging in Websphere Application Server using Apache commons-logging and Log4j

10 Apr, 2009
Xebia Background Header Wave

Logging should be simple and straightforward. It is an essential part of everyday administrative operations and it provides vital information for debugging production incidents. Adequate logging saves time and money.  When hosting a number of applications, say 10+, you will want to separate application logs from each other  and from platform logs and traces. Logging frameworks like the jdk logger and log4j, cooperating with the j2ee container provide the means to do this, using configuration files. So far, so good.

At some point (from 5.0 on I believe) IBM decided to include jakarta/apache commons-logging (JCL) in their Websphere Application Server product. This is a well known open source product that provides an abstraction below which any logging implementation can in theory be used. The inclusion in WAS implicated that applications using the same framework might see the logging behavior changed.  This is because the logging classes will by default be loaded by a different classloader. This classloader will have to be able to find the log4j.jar as well as its configuration file.
There´s another problem: JCL  needs to be told that it has to use log4j. By default the JDK logger is used and every line ends up in SystemOut.log.  The IBM documentation on this is clear: simply put a file called META-INF/services/org.apache.commons.logging.LogFactory on the classpath and you´re ready. The contents of this file turned out to be the puzzling part for me. I wrongly assumed that the file should be the same as the commons-logging.properties:
org.apache.commons.logging.LogFactory=org.apache.commons.logging.impl.Log4jFactory
I did what (I thought) the documentation  told me, redeployed my application and everything seemed fine. Until I changed classloading mode to PARENT_FIRST. Websphere applications can have this setting or APPLICATION_FIRST. In the latter mode jar files bundled with the application will be used first, before loading standard websphere libraries.
When you´re dealing  with an application you did not write and cannot change (say you´re the deployer),  PARENT_FIRST is your friend in the face of evil developers. I mean evil  as in: including  j2ee.jar in the earfile. It happens!! And not just this file, but anything you can find in a Maven repository today, containing lowlevel functionality (like xml processing, or j2ee api’s ). They should not be in the earfile!! Using PARENT_FIRST all correct versions of the platform classes will be loaded from the right location. Use this option and then nag the developers.
Actually the logging behavior in my case was very inconsistent. Sometimes APPLICATION_FIRST  didn´t work either. And sometimes a server restart changed the logging. It was a frustrating experience, and in those moments, you´re happy to fall back on java decompiling using good old JAD.
The source for org.apache.commons.LogFactory.class made it clear that the above configuration line is  wrong, and that you will NEVER get a warning if you fail to do it right. The class loads the file and the complete line is then interpreted as the classname for the LogFactoryImpl. So it´s not a properties file, and the correct contents for META-INF/services/ org.apache.commons.logging.LogFactory are:
org.apache.commons.logging.impl.Log4jFactory
And that´s all there is to it. Thanks Apache, for swallowing the  ClassNotFoundException !
Actually after some searching I came across a less well known part of the official SUN jarfile specification which states that service interfaces can have certain implementation classes, which are specified in a file that has the name of the interface. It´s a really rudimentary IOC implementation, that must have been fashionable back in the days of jdk 1.3.
I really didn´t know all this. It turned out to be a learning experience after all.

Questions?

Get in touch with us to learn more about the subject and related solutions

Explore related posts