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

Sander Hautvast

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.

Comments (6)

  1. Malena - Reply

    January 20, 2011 at 4:05 pm

    Hi Sander! I'm having the exact same problem you are describing here but i couldn't solve it by adding the META-INF/services/org.apache.commons.logging.LogFactory file. I still get the com.sshtools.j2ssh.* logs through the SystemOut.log and not the log4j logger. Any more ideas? Thanks!!

  2. Sander Hautvast - Reply

    January 26, 2011 at 12:39 pm

    You are right, this is not the complete story. There are other issues that I found out later. One of them is the fact that websphere 6.1 packages PART of the commons-logging-1.0.4. To solve all issues I created a little piece of software. See http://code.google.com/p/logbridge. Let me know if everything works for you.

  3. Dunand - Reply

    March 16, 2011 at 2:50 pm

    Hi, we upgraded our server form WebSphere 6.1.0.15 to 6.1.0.33 and our logging with JCL and log4j stopped working. We would like to do some testing with logbridge. I think IBM wrecked logging with version 6.1.0.17. Can you tell us on which version of WebSphere you tested logbridge ?

    thanks

  4. Sander Hautvast - Reply

    March 17, 2011 at 8:49 pm

    just tested it with 6.1.0.33 and working fine

  5. Andrey Alekseev - Reply

    February 29, 2012 at 1:24 pm

    just tested it with WebSphere Application Server 8.0.0.1 and working fine

  6. Arun Christopher - Reply

    October 29, 2013 at 4:20 pm

    This is working perfectly under windows (Websphere 7). But the same war deployed in Websephere 7 running in AIX, is not working. Any leads would be greatly helpful. Thanks!

Add a Comment