JBoss is slow with threads heavily blocked in BaseClassLoader.doLoadClass()
Environment
- JBoss Enterprise Application Platform (EAP) 5
- 5.2.0 and earlier
Issue
- We're migrating to EAP 5 and now see performance issues in classloading that were not present on earlier versions of EAP.
- Thread dumps show threads blocking heavily in BaseClassLoader.doLoadClass() like so:
"http-0.0.0.0-8080-1" prio=3 tid=0x025a3c00 nid=0x3a9 waiting for monitor entry [0x5de7d000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.jboss.classloader.spi.base.BaseClassLoader.doLoadClass(BaseClassLoader.java:495)
- waiting to lock <0x80e22960> (a org.jboss.classloader.spi.base.BaseClassLoader)
at org.jboss.classloader.spi.base.BaseClassLoader.loadClass(BaseClassLoader.java:447)
at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
at org.jboss.classloading.spi.DelegatingClassLoader.loadClass(DelegatingClassLoader.java:87)
at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
at org.jboss.util.loading.DelegatingClassLoader.loadClass(DelegatingClassLoader.java:97)
at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
- Thread dumps show the lock owning thread is changing so there is progression but it is unacceptably slow under load
Resolution
- Consume any available one-off fixes that address this caching/performance issue:
Root Cause
- Content from issues.jboss.org is not included.JBCL-185
- The BaseClassLoaderDomain is not properly storing found classes in its globalClassCache. The domain's globalClassCache is checked concurrently by BaseClassLoader.loadClass to return previously found entries quickly. If the cached value is not found, the thread proceeds to BaseClassLoader.doLoadClass() and synchronized calls to its classloader domain.
- With heavy load on the classloader, frequent cache failures and subsequent synchronized calls cause heavy thread contention on the classloader as seen above that didn't take place in prior EAP versions and classloader implementations.
Diagnostic Steps
- Troubleshoot using thread dumps and additional steps mentioned in Java application unresponsive
- Capture TRACE classloader logging to confirm the classloader behavior. This could be captured with the following logging amendements:
<appender name="BASECL" class="org.jboss.logging.appender.DailyRollingFileAppender">
<errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
<param name="File" value="${jboss.server.log.dir}/basecl.log"/>
<param name="Append" value="true"/>
<param name="DatePattern" value="'.'yyyy-MM-dd"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d %-5p [%c] (%t) %m%n"/>
</layout>
</appender>
<category name="org.jboss.classloader.spi.base" additivity="false">
<priority value="TRACE"/>
<appender-ref ref="BASECL"/>
</category>
-
A log message like the following indicates that a item was found in the domain's globalClassCache for this class:
TRACE [org.jboss.classloader.spi.base.BaseClassLoaderDomain] (http-0.0.0.0-8080-1) Found com.example.my.package.MyClass in global cacheThis can be misleading as the globalClassCache check still could have returned a null object found in the cache to still lead to the problematic synchronized calls.
-
A message like the following after the above cache message would indicate the class was not found from cache:
TRACE [org.jboss.classloader.spi.base.BaseClassLoader] (http-0.0.0.0-8080-1) BaseClassLoader@15e6d4a{vfszip:/jboss/server/default/deploy/myapp.ear/} load from domain com.example.my.package.MyClass domain=ClassLoaderDomain@1a5aa86{myapp:loader=myapp.loader}Repeated occurrences of such logging events for the same class(es) would confirm the classloader thread contention is due to a failure to properly cache
This solution is part of Red Hat’s fast-track publication program, providing a huge library of solutions that Red Hat engineers have created while supporting our customers. To give you the knowledge you need the instant it becomes available, these articles may be presented in a raw and unedited form.