JBoss and log4j

Problem statement

Some JBoss components rely on log4j for logging. For this reason, JBoss includes a customized copy of log4j in the application server class path. This version of the log4j classes are loaded first. This can cause a number of problems.

Side effect #1: stderr redirection

JBoss made the seemingly reasonable design decision to redirect stderr to the log4j error stream. So for example an e.printStackTrace() call would end up in the error log like this:

2009-03-23 16:36:54,107 ERROR [STDERR] ca.intelliware.sample.SomeException: text text
2009-03-23 16:36:54,108 ERROR [STDERR] 	at ca.intelliware.sample.SomeClass.method(SomeClass.java:63)
2009-03-23 16:36:54,108 ERROR [STDERR] 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
2009-03-23 16:36:54,108 ERROR [STDERR] 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)

This can make for verbose error logs if a lot of messages are written to stderr (more on this later).

Side effect #2: classloader problems

If your web application includes its own copy of log4j, you may find that JBoss appears to be ignoring the log4j configuration files (usually server/servername/conf/jboss-log4j.xml). What’s happening is that two different log4j instances are being used – one is loaded, configured and used by JBoss itself, and the other is the one that the application code uses. Since this second instance of log4j is not configured properly, by default it logs to stderr. And since JBoss itself redirects stderr to its own copy of JBoss, you end up with messages that are logged with a category of STDERR instead of the original logging class.

All of this can be avoided by not including the log4j jar in your packaged web app. Using maven, that’s as simple as adding a <scope>provided</scope> tag to the dependency:

<dependency>
	<groupId>log4j</groupId>
	<artifactId>log4j</artifactId>
	<version>1.2.15</version>
	<scope>provided</scope>
</dependency>

Side effect #3: dependent project logging

Some third-party software packages (CXF and Faces are two that come to mind) use java.util.logging for their logging. By default, java.util.logging logs all messages to stderr – even info messages. With a default setup in JBoss, this leads to log entries like this:

2009-03-23 16:36:13,981 ERROR [STDERR] 23-Mar-2009 4:36:13 PM com.sun.facelets.compiler.TagLibraryConfig loadImplicit
INFO: Added Library from: jar:file:/home/administrator/jboss-4.2.2.GA/server/default/tmp/deploy/myWar-exp.war/WEB-INF/lib/richfaces-ui-3.2.2.SR1.jar!/META-INF/richfaces.taglib.xml

Even though this message is an innocent INFO message logged via java.util.logging, by default it’s spit out to stderr – which, again, is intercepted by JBoss and sent to the ERROR log stream. So it’s impossible to filter out messages by severity since log4j is treating everything as an error.

Packages that don’t suck – let’s say CXF in this case – will allow you to override the logging implementation in some manner. In the CXF case, it’s as simple as setting up a file in META-INF named org.apache.cxf.Logger that looks like this:

org.apache.cxf.common.logging.Log4jLogger

This forces CXF to use a provided bridge between java.util.logging and log4j, with the net result that CXF logs to log4j.

Other packages such as Faces do not provide this option and you’re stuck with the stderr messages being sent to your error stream. This is really unfortunate. There are several workarounds that I’ve seen around the net, but they’re complicated and involve putting adapter classes right on the JBoss classpath.

Actual problem example #1

We wanted to log error messages to an SMTP appender. However, we were getting swamped with email since everything in the error stream was getting sent via email.

Our first approach was to clean up the logging – basically, tuning the logging of various packages so that we wouldn’t see it. But since JBoss was intercepting the INFO messages sent to stderr (for example) and sending them to ERROR, we were unable to control the flow of all messages.

What we ended up doing was logging only errors that our project produced to the SMTP appender:

<category name="ca.intelliware.sample">
   <priority value="ERROR"/>
   <appender-ref ref="EMAIL_ASYNC"/>
</category>

Whenever we think an error is important enough to get emailed to us, we make sure to log it with a category that matches ca.intelliware.sample, and we get the email as expected. Errors from other categories just end up in the log file.

It's only fair to share...
Share on FacebookGoogle+Tweet about this on TwitterShare on LinkedIn

2 thoughts on “JBoss and log4j

  1. Pingback: The State of Java Logging | i-proving.com

Leave a Reply