Invalid class loader hierarchy problem with commons-logging

[pcolagrosso]

Hi,

In the course of porting our app from JBOSS 3.2.3 (Tomat 4.x) to JBOSS 3.2.5 we have come across a problem with some interference between the commons-logging classes bundled within our app and the one which coimes bundled with the Tomcat SAR.

Our web app consists of an EAR file which is made up of a WAR file and a JAR file. The WAR fille contains a number of .jar files under WEB-INF/LIB (including commons-logging.jar) while the JAR file contains the EJB classes. We are also making use of scoped class loading with overriding, via the jboss-app.xml deployment descriptor which has the folllowing format

<jboss-app >
<loader-repository >app.classloader:loader=abox.ear </loader-repository>
 <loader-repository-config>
 java2ParentDelegation=false
 </loader-repository-config>
</jboss-app> >

However, the problem we are facing is that we obtain the following exception error message from commons-logging when the servlet attemps to access some commons-logging classes (see more complete trace at the end of this message):

org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed. (Caused by org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed.)

My understanding is that the class loader model we are using should ensure that the commons-logging classes used within our EAR should be loaded from the commons-logging.jar which is bundled as part of our EAR. However, from what I understand it seems that the commons-logging classes from the Tomcat SAR are conflicting so that our local commons-logging classes are not overriding the ones from the server.

Does anyone know what else I need to be doing from a class loading point of view so that our local version of commons-logging doesn't conflict with the ones from Tomcat SAR?

I have used the classloader troubleshooting tricks mentioned in the JBoss Wiki and the JBoss Admin guide (in particular turning on the class loader tracing and also using the JMX-console and the Loader Repository MBeans) but I am unable to really deduce which class loader hierarchy is corresponding to the which instances of the commons-logging classes (i.e., our APP's and Tomcat SAR's).

For example, here is the resulting class loading log file (filtered to include only the references to org.apache.commons.logging.Log):

[22604,LoadMgr3,main] Begin beginLoadTask, task=org.jboss.mx.loading.ClassLoadingTask@1ed2bbd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@45e228{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}, loadedClass: nullnull, loadOrder: 2147483647, loadException: null, threadTaskCount: 0, state: 0, #CCE: 0}
[22605,LoadMgr3,main] scheduleTask(1), created subtask: {t=Thread[main,5,jboss], ucl=org.jboss.mx.loading.UnifiedClassLoader3@45e228{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}, name=org.apache.commons.logging.Log, requestingThread=Thread[main,5,jboss], order=3, releaseInNextTask=false}
[22605,LoadMgr3,main] End beginLoadTask, task=org.jboss.mx.loading.ClassLoadingTask@1ed2bbd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@45e228{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}, loadedClass: nullnull, loadOrder: 2147483647, loadException: null, threadTaskCount: 1, state: 1, #CCE: 0}
[22605,LoadMgr3,main] Continue nextTask(1), task=org.jboss.mx.loading.ClassLoadingTask@1ed2bbd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@45e228{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}, loadedClass: nullnull, loadOrder: 2147483647, loadException: null, threadTaskCount: 1, state: 1, #CCE: 0}
[22605,LoadMgr3,main] Begin nextTask(0), loadTask=org.jboss.mx.loading.ClassLoadingTask@1ed2bbd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@45e228{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}, loadedClass: nullnull, loadOrder: 2147483647, loadException: null, threadTaskCount: 1, state: 1, #CCE: 0}
[22605,LoadMgr3,main] Running threadTask={t=Thread[main,5,jboss], ucl=org.jboss.mx.loading.UnifiedClassLoader3@45e228{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}, name=org.apache.commons.logging.Log, requestingThread=Thread[main,5,jboss], order=3, releaseInNextTask=false}
[22607,ClassLoadingTask,main] setLoadedClass, theClass=interface org.apache.commons.logging.Log, order=3
[22607,UnifiedLoaderRepository3,main] cacheLoadedClass, classname: org.apache.commons.logging.Log, class: interface org.apache.commons.logging.Log, ucl: org.jboss.mx.loading.UnifiedClassLoader3@45e228{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}, prevClass: null
[22607,LoadMgr3,main] Notifying task of thread completion, loadTask:org.jboss.mx.loading.ClassLoadingTask@1ed2bbd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@45e228{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}, loadedClass: interface org.apache.commons.logging.Logorg.apache.commons.logging.Log@1d2bb9f<CodeSource: (file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42639commons-logging.jar <no signer certificates>)>, loadOrder: 3, loadException: null, threadTaskCount: 0, state: 1, #CCE: 0}
[22607,LoadMgr3,main] End nextTask(0), loadTask=org.jboss.mx.loading.ClassLoadingTask@1ed2bbd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@45e228{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}, loadedClass: interface org.apache.commons.logging.Logorg.apache.commons.logging.Log@1d2bb9f<CodeSource: (file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42639commons-logging.jar <no signer certificates>)>, loadOrder: 3, loadException: null, threadTaskCount: 0, state: 4, #CCE: 0}
[45268,LoadMgr3,main] Begin beginLoadTask, task=org.jboss.mx.loading.ClassLoadingTask@b458fd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@194363b{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear ,addedOrder=36}, loadedClass: nullnull, loadOrder: 2147483647, loadException: null, threadTaskCount: 0, state: 0, #CCE: 0}
[45270,LoadMgr3,main] scheduleTask(1), created subtask: {t=Thread[main,5,jboss], ucl=org.jboss.mx.loading.UnifiedClassLoader3@194363b{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear ,addedOrder=36}, name=org.apache.commons.logging.Log, requestingThread=Thread[main,5,jboss], order=0, releaseInNextTask=false}
[45270,LoadMgr3,main] End beginLoadTask, task=org.jboss.mx.loading.ClassLoadingTask@b458fd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@194363b{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear ,addedOrder=36}, loadedClass: nullnull, loadOrder: 2147483647, loadException: null, threadTaskCount: 1, state: 1, #CCE: 0}
[45270,LoadMgr3,main] Continue nextTask(1), task=org.jboss.mx.loading.ClassLoadingTask@b458fd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@194363b{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear ,addedOrder=36}, loadedClass: nullnull, loadOrder: 2147483647, loadException: null, threadTaskCount: 1, state: 1, #CCE: 0}
[45270,LoadMgr3,main] Begin nextTask(0), loadTask=org.jboss.mx.loading.ClassLoadingTask@b458fd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@194363b{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear ,addedOrder=36}, loadedClass: nullnull, loadOrder: 2147483647, loadException: null, threadTaskCount: 1, state: 1, #CCE: 0}
[45270,LoadMgr3,main] Running threadTask={t=Thread[main,5,jboss], ucl=org.jboss.mx.loading.UnifiedClassLoader3@194363b{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear ,addedOrder=36}, name=org.apache.commons.logging.Log, requestingThread=Thread[main,5,jboss], order=0, releaseInNextTask=false}
[45271,ClassLoadingTask,main] setLoadedClass, theClass=interface org.apache.commons.logging.Log, order=0
[45272,UnifiedLoaderRepository3,main] cacheLoadedClass, classname: org.apache.commons.logging.Log, class: interface org.apache.commons.logging.Log, ucl: org.jboss.mx.loading.UnifiedClassLoader3@194363b{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear ,addedOrder=36}, prevClass: null
[45272,LoadMgr3,main] End nextTask(0), loadTask=org.jboss.mx.loading.ClassLoadingTask@b458fd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@194363b{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear ,addedOrder=36}, loadedClass: interface org.apache.commons.logging.Logorg.apache.commons.logging.Log@1ea34f3<CodeSource: (file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear-contents/abox.war/WEB-INF/lib/commons-logging.jar <no signer certificates>)>, loadOrder: 0, loadException: null, threadTaskCount: 0, state: 4, #CCE: 0}
[45272,LoadMgr3,main] Begin endLoadTask, task=org.jboss.mx.loading.ClassLoadingTask@b458fd{classname: org.apache.commons.logging.Log, requestingThread: Thread[main,5,jboss], requestingClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@194363b{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear ,addedOrder=36}, loadedClass: interface org.apache.commons.logging.Logorg.apache.commons.logging.Log@1ea34f3<CodeSource: (file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp42679abox.ear-contents/abox.war/WEB-INF/lib/commons-logging.jar <no signer certificates>)>, loadOrder: 0, loadException: null, threadTaskCount: 0, state: 4, #CCE: 0}

From this output, I can tell that there are two distinct instances of org.apache.commons.logging.Log instances which are being loaded (one from the Tomcat SAR's JAR and the other one from the WEB-INF/libs of our app). However, what is not clear is the context from which each of these instances is being loaded and exactly what the class loader hiearchy for each instance is.

Does anyone have any suggestions on how to proceed in order to obtain this type of info so as to be able to further diagnose the source of the problem?

Thanks,

Piero


More complete stack trace info for LogConfigurationException:

Caused by: org.apache.commons.logging.LogConfigurationException: org.apache.commons.logging.LogConfigurationException: org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed. (Caused by org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed.) (Caused by org.apache.commons.logging.LogConfigurationException: org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed. (Caused by org.apache.commons.logging.LogConfigurationException: Invalid class loader hierarchy. You have more than one version of 'org.apache.commons.logging.Log' visible, which is not allowed.))
at org.apache.commons.logging.impl.LogFactoryImpl.newInstance(LogFactoryImpl.java:543)
at org.apache.commons.logging.impl.LogFactoryImpl.getInstance(LogFactoryImpl.java:235)
at org.apache.commons.logging.impl.LogFactoryImpl.getInstance(LogFactoryImpl.java:209)
at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:351)
at org.apache.struts.action.ActionServlet.<clinit>(ActionServlet.java:375)
... 125 more

[pcolagrosso]

Here is some additional info which provides more insight into the problem. Based on this information I am begining to think that the problem we are observing is related the fact that the JBoss class loader
is actually loading some of the commons-logging classes from the Tomcat SAR's repository even though our class loader specification is stating that our ear should use an isolated class loader with overriding.


Could one of you experts on JBoss class loading please have a look at this and confirm whether I should report this as a bug on JBoss 3.2.5 class loading or whether I am understanding something incorrectly?

Using the JMX console I executed the method displayClassInfo on the MBean which corresponds to the loader repository for our application (i.e.. Domain=app.classloader, loader=abox.ear, class=org.jboss.mx.loading.HeirarchicalLoaderRepository3).

I specified org.apache.commons.logging.impl.Log4JLogger as the input parameter to this MBean method and obtained the results quoted below. Based on these results, what I understand is that the class org.apache.commons.logging.impl.Log4JLogger which is being loaded in the context of our EAR file is incorrectly being loaded from the Tomcat SAR's repository. If I understand correctly, it also seems that there are 2 different class loaders associated with this class.

Here is some additional information regarding our environment configuration:

OS: Linux Fedora Core 2
JBoss Version: 3.2.5
JDK: j2sdk1.4.2_03 or jdk1.5.0beta2 (problem occurs with either JDK)
commons-logging.jar version: 1.0.4

Please also note that this problem was not occuring under JBoss 3.2.5 with essentially the same web app.

Results obtained via JMX-console for method displayClassInfo with input string org.apache.commons.logging.impl.Log4JLogger:

org.apache.commons.logging.impl.Log4JLogger Information
Repository cache version:
org.apache.commons.logging.impl.Log4JLogger(88a970).ClassLoader=org.jboss.mx.loading.UnifiedClassLoader3@1e6e305{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}
..org.jboss.mx.loading.UnifiedClassLoader3@1e6e305{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53942servlet-api.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53943tomcat-http11.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53944servlets-common.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53945tomcat50-service.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53946tomcat-coyote.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53947jsp-api.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53948jasper-runtime.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53949tomcat-jk2.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53950naming-resources.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53951commons-el.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53952servlets-default.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53953servlets-invoker.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53954commons-digester.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53955catalina.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53956jasper-compiler.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53957commons-logging.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53958catalina-manager.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53959servlets-webdav.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53960commons-collections.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53961jakarta-regexp-1.3.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53962tomcat-util.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53963commons-beanutils.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53964catalina-optional.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53965naming-common.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53966commons-modeler.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53967ant.jar
....file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ROOT.war/
..org.jboss.system.server.NoAnnotationURLClassLoader@1de3f2d
..sun.misc.Launcher$AppClassLoader@181afa3
....file:/usr/local/jboss/jboss-3.2.5/bin/run.jar
....file:/usr/local/java/jdk1.5.0beta2/lib/tools.jar
..sun.misc.Launcher$ExtClassLoader@131f71a
....file:/usr/local/java/jdk1.5.0beta2/jre/lib/ext/sunpkcs11.jar
....file:/usr/local/java/jdk1.5.0beta2/jre/lib/ext/dnsns.jar
....file:/usr/local/java/jdk1.5.0beta2/jre/lib/ext/localedata.jar
....file:/usr/local/java/jdk1.5.0beta2/jre/lib/ext/sunjce_provider.jar
....file:/usr/local/java/jdk1.5.0beta2/jre/lib/ext/pg74.213.jdbc3.jar
++++CodeSource: (file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53957commons-logging.jar )
Implemented Interfaces:
++interface org.apache.commons.logging.Log(a7bd7a)
++++ClassLoader: org.jboss.mx.loading.UnifiedClassLoader3@1e6e305{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/deploy/jbossweb-tomcat50.sar/ ,addedOrder=3}
++++CodeSource: (file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53957commons-logging.jar )

### Instance0 found in UCL: org.jboss.mx.loading.UnifiedClassLoader3@1bd8993{ url=file:/usr/local/jboss/jboss-3.2.5/server/PCOL/tmp/deploy/tmp53997abox.ear ,addedOrder=36}

[starksm64]

Its an issue with tomcat5 integration. See the following bug:

http://sourceforge.net/tracker/index.php?func=detail&aid=983462&group_id=22866&atid=376685

You will have to remove the commons-logging.jar from the wars to avoid the problem. Standalone tomcat avoids this issue by ignoring the deployment level classes that are included in the system classpath, the commons-logging is one of them.