Tuesday, January 12, 2010

Using your own Log4J with JBoss

If you use JBoss and Log4J, you've probably seen this error in JBoss' server.log file...

log4j:ERROR A "org.jboss.logging.appender.FileAppender" object is not assignable to a "org.apache.log4j.Appender" variable.
log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 
log4j:ERROR [BaseClassLoader@73f05c08{vfszip:/home/foo/work/tools/other/JEE_Servers/jboss-5.1.0.GA/server/default/deploy/smallapp.war/}] whereas object of type 
log4j:ERROR "org.jboss.logging.appender.FileAppender" was loaded by [org.jboss.bootstrap.NoAnnotationURLClassLoader@1cb1c5fa].
log4j:ERROR Could not instantiate appender named "FILE".

The InterGoogleWeb suggests "remove log4j.jar from your war and all is sweet". That's true and it will fix the immediate problem. The webapp class loader loads org.apache.log4j.Appender from your application's copy of Log4J, and loads the custom JBoss appender org.jboss.logging.appender.FileAppender from a different classloader. In these multi-classloader scenario's it is appropriate to get a ClassCastException if two classes are in different loaders, even if they are normally assignable (this is enforcing Class Namespace Isolation). Removing your log4j.jar removes Log4J in the webapp class loader, leaving JBoss's class loader to happily load these by itself and the problem appears to go away.

But, since when is Log4J part of the JavaEE spec? Remove Log4J at your own peril, otherwise you'll one day deploy to Tomcat, or Resin, or any number of app servers and get ClassNotFoundException's or NoClassDefFoundError's because you did not package Log4J!

So what's happening here. Consider this fairly typical scenario.
  • Your application uses Log4J and packages it up in WEB-INF/lib. 
  • You have a log4j.properties file which is on the classpath, but not in your application's WEB-INF/classes (or don't have a log4j.properties at all). 
  • You let Log4J auto-discover this properties file, rather than hard-code it or set a system property. 
This means when Log4J goes and executes Thread.currentThread().getContextClassLoader().loadResource("log4j.properties"), it will load your configuration, right?

Wrong.

In JBoss 5.1.0 GA (and possibly other versions), what you get is the log4j.properties bundled in jboss/bin/run.jar. That JAR is higher in the class loading hierarchy than your copy of the properties file, so it will always be picked up first. And you got it, the FileAppender that JBoss's log4j.properties declares is the special "org.jboss.logging.appender.FileAppender" class, the same one mentioned in the error message.

So what to do?
  • You can try using the XML format for the log4J configuration, because Log4J looks for log4j.xml before it looks for log4j.properties. This appears to work OK.
  • You can rename the log4j.properties inside the "run.jar" to something else, and give JBoss a system property to use the changed configuration file. Not sure if this would have other effects though
  • You can package up log4j.properties in WEB-INF/classes and that seems to work. But then you can't change your logging config without re-deploying your app 
  • Use Logback and ditch Log4J. Logback provides Log4J adapters, and it works really well. Thats a higher impact change to your app though
  • You can probably ignore the error if you don't care about logging, it relates to your application, not the server.
If I find a solution I'll update this post, but if you have one feel free to share!

1 comment:

  1. Hi,

    Thanks a lot for the great post ! Right now I'm facing the same problem
    My log4j.properties file is externalized. And I'm calling the ConfigAndWatch method in my servlet init (this is the first one to load).

    PropertyConfigurator.configureAndWatch(configFilename, delay);

    Seems like log4j is trying to initialize with the log4j.properties from run.jar..because after the error only this servlet code gets executed.
    I'm bit confused here since log4j tells we can use PropertyConfigurator to initialize it..

    my application has the following code for class loading




    myapp:loader=CardProcessingGateway.war
    java2ParentDelegation=false





    your feedback is highly appreciated !!

    ReplyDelete