Most Java developers
are familiar with the infamous and very common java.lang.ClassNotFoundException.
While the sources of this problem are generally well understood (missing classes/libraries
in classpath, class loader delegation problems etc.), the impact to the overall
JVM and performance is often unknown. This situation can lead to significant
impacts to your application response time and scalability.
Large Java
EE enterprise systems with multiple applications deployed are the most exposed
to this type of problem due to the large number of different application
classloaders active at runtime. This increases the risk of facing “undetected”
ClassNotFoundException unless a clear business impact is identified and close
log monitoring is implemented, results: on-going performance impact along with possible
JVM class loading IO and Thread lock contention.
The
following article and sample programs will demonstrate that any occurrence of
ClassNotFoundException found from your client production systems should be
taken very seriously and addressed promptly.
Java class loading: the missing link for
optimal performance
Proper
understanding of this performance problem starts with proper knowledge of the
Java class loading model. ClassNotFoundException essentially means a failure of
the JVM to locate and/or load a particular Java class such as:
- The Class.forName() method
- The ClassLoader.findSystemClass() method
- The ClassLoader.loadClass() method
While
class loading of your application Java classes should occur only once in the
JVM life-cycle (or through dynamic re-deploy functions), some applications also
rely on dynamic class loading operations.
Regardless,
repetitive valid and “failing” class loading operations can be quite intrusive,
especially when the loading process is attempted by the default JDK
java.lang.ClassLoader itself. Indeed, the default JDK 1.7+ behaviour, due to backward
compatibility, will allow only one class to be loaded at the time, unless the
class loader is tagged as “parallel capable”. Please keep in mind the even if
the synchronization is done at the Class level only, a repetitive class loading
failure against the same class name is still going to trigger thread lock
contention depending of the Java thread concurrency level you are dealing with.
The situation was much worst back with JDK 1.6 with synchronization done systematically
at the class loader instance level.
For this
reason, Java EE containers such as JBoss WildFly 8
are using their own internal concurrent
class loaders for the loading of your application classes. These class loaders implements
locking at a finer level of granularity, thus allowing loading different
classes from the same instance of the class loader concurrently. This is also
aligned with the latest JDK 1.7+ improvement introducing the support for Multithreaded
Custom Class Loaders which also help prevent certain class loader deadlock
scenarios.
That being
said, class loading of system level classes such as java.* and Java EE
container modules still fall back on the default JDK ClassLoader. This means
that repetitive class loading failure for the same class name e.g.
ClassNotFoundException can still trigger severe thread lock contention. This is
precisely what we will replicate and demonstrate for the rest of the article.
Thread lock contention - problem replication
In order
to recreate and simulate this problem, we created a simple application as per
below specifications:
- A JAX-RS (REST) Web
Service executing Class.forName() against a dummy Class name “located”
from the system package level:
String
className = "java.lang.WrongClassName";
Class.forName(className);
The simulation
essentially executes concurrently with 20
threads the JAX-RS Web service. Each invocation generates a ClassNotFoundException.
The logging was fully disabled in order to reduce impact on IO and focus on the
class loading contention only.
Now let’s look at the results from JVisualVM
from our 30-60 seconds run. We can clearly see a lot of BLOCKED threads waiting
to acquire a lock on an Object monitor.
Analysis of
the JVM thread dump is clearly exposing the problem: Thread lock contention. We
can see from the execution stack trace that JBoss delegates the loading of the
class to the JDK ClassLoader…why? This is because our wrong Java class name is
detected to be part of the system class path e.g. java.*. In this situation,
JBoss will delegate the loading to the system class loader, triggering
systematic synchronization for that particular class name and waiters from the
other threads waiting to acquire a lock to load the same Class name.
Many threads waiting to acquire LOCK 0x00000000ab84c0c8…
"default
task-15" prio=6 tid=0x0000000014849800 nid=0x2050 waiting for monitor
entry [0x000000001009d000]
java.lang.Thread.State: BLOCKED (on object
monitor)
at
java.lang.ClassLoader.loadClass(ClassLoader.java:403)
- waiting to lock
<0x00000000ab84c0c8> (a java.lang.Object)
// Waiting to acquire a LOCK held by Thread “default
task-20”
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)
at
java.lang.ClassLoader.loadClass(ClassLoader.java:356) // JBoss now delegates to system ClassLoader..
at org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:371)
at
org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:119)
at
java.lang.Class.forName0(Native Method)
at
java.lang.Class.forName(Class.java:186)
at
org.jboss.tools.examples.rest.MemberResourceRESTService.SystemCLFailure(MemberResourceRESTService.java:176)
at
org.jboss.tools.examples.rest.MemberResourceRESTService$Proxy$_$$_WeldClientProxy.SystemCLFailure(Unknown
Source)
at
sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at
java.lang.reflect.Method.invoke(Method.java:601)
……………………..
Culprit thread - default task-20
"default
task-20" prio=6 tid=0x000000000e3a3000 nid=0x21d8 runnable
[0x0000000010e7d000]
java.lang.Thread.State: RUNNABLE
at
java.lang.Throwable.fillInStackTrace(Native Method)
at
java.lang.Throwable.fillInStackTrace(Throwable.java:782)
- locked
<0x00000000a09585c8> (a java.lang.ClassNotFoundException)
at
java.lang.Throwable.<init>(Throwable.java:287)
at
java.lang.Exception.<init>(Exception.java:84)
at
java.lang.ReflectiveOperationException.<init>(ReflectiveOperationException.java:75)
at java.lang.ClassNotFoundException.<init>(ClassNotFoundException.java:82) // ClassNotFoundException! at
java.net.URLClassLoader$1.run(URLClassLoader.java:366)
at
java.net.URLClassLoader$1.run(URLClassLoader.java:355)
at
java.security.AccessController.doPrivileged(Native Method)
at
java.net.URLClassLoader.findClass(URLClassLoader.java:354)
at
java.lang.ClassLoader.loadClass(ClassLoader.java:423)
- locked
<0x00000000ab84c0e0> (a java.lang.Object)
at
java.lang.ClassLoader.loadClass(ClassLoader.java:410)
- locked
<0x00000000ab84c0c8> (a java.lang.Object) // java.lang.ClassLoader:
LOCK acquired at
sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:308)
at
java.lang.ClassLoader.loadClass(ClassLoader.java:356)
at
org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:371)
at
org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:119)
at java.lang.Class.forName0(Native
Method)
at
java.lang.Class.forName(Class.java:186)
at
org.jboss.tools.examples.rest.MemberResourceRESTService.SystemCLFailure(MemberResourceRESTService.java:176)
at
org.jboss.tools.examples.rest.MemberResourceRESTService$Proxy$_$$_WeldClientProxy.SystemCLFailure(Unknown
Source)
…………………………………
Now let’s replace
our Class name by a Java class tagged as part of the “application” package and re-run
the test under the same load conditions.
String className = "org.ph.WrongClassName";
Class.forName(className);
As we can
see, we are no longer dealing with BLOCKED threads…why is that? Let’s have a
look at the JVM thread dump to better understand this change of behaviour.
"default
task-51" prio=6 tid=0x000000000dd33000 nid=0x200c runnable
[0x000000001d76d000]
java.lang.Thread.State: RUNNABLE
at java.io.WinNTFileSystem.getBooleanAttributes(Native
Method) //
IO overhead due to JAR file search operation
at
java.io.File.exists(File.java:772)
at org.jboss.vfs.spi.RootFileSystem.exists(RootFileSystem.java:99)
at
org.jboss.vfs.VirtualFile.exists(VirtualFile.java:192)
at
org.jboss.as.server.deployment.module.VFSResourceLoader$2.run(VFSResourceLoader.java:127)
at
org.jboss.as.server.deployment.module.VFSResourceLoader$2.run(VFSResourceLoader.java:124)
at
java.security.AccessController.doPrivileged(Native Method)
at
org.jboss.as.server.deployment.module.VFSResourceLoader.getClassSpec(VFSResourceLoader.java:124)
at
org.jboss.modules.ModuleClassLoader.loadClassLocal(ModuleClassLoader.java:252)
at
org.jboss.modules.ModuleClassLoader$1.loadClassLocal(ModuleClassLoader.java:76)
at org.jboss.modules.Module.loadModuleClass(Module.java:526)
at
org.jboss.modules.ModuleClassLoader.findClass(ModuleClassLoader.java:189) // JBoss now
fully responsible to load the class
at org.jboss.modules.ConcurrentClassLoader.performLoadClassUnchecked(ConcurrentClassLoader.java:444)
// Unchecked since using JDK 1.7 e.g. tagged as “safe”
JDK
at
org.jboss.modules.ConcurrentClassLoader.performLoadClassChecked(ConcurrentClassLoader.java:432)
at
org.jboss.modules.ConcurrentClassLoader.performLoadClass(ConcurrentClassLoader.java:374)
at
org.jboss.modules.ConcurrentClassLoader.loadClass(ConcurrentClassLoader.java:119)
at
java.lang.Class.forName0(Native Method)
at
java.lang.Class.forName(Class.java:186)
at
org.jboss.tools.examples.rest.MemberResourceRESTService.AppCLFailure(MemberResourceRESTService.java:196)
at
org.jboss.tools.examples.rest.MemberResourceRESTService$Proxy$_$$_WeldClientProxy.AppCLFailure(Unknown
Source)
at
sun.reflect.GeneratedMethodAccessor60.invoke(Unknown Source)
……………….
The above
execution stack trace is quite revealing:
- Since the Java class name was not detected to be
part of the Java system package, no ClassLoader delegation was performed,
thus no synchronization.
- Since JBoss considers JDK 1.7+ as a “safe” JDK, the ConcurrentClassLoader
.performLoadClassUnchecked() method was used, not triggering any
Object monitor lock.
- No synchronization means no Thread lock contention
triggered as a result of the non-stop ClassNotFoundException error.
It is
still important to note that while JBoss is doing a great job at preventing
Thread lock contention in this scenario, the repetitive class
loading attempt will still degrade the performance to a certain degree due to
IO overhead associated with excessive JAR file search operations, again
re-enforcing the need to take immediate corrective actions.
Final words
I hope
that you enjoyed this article and have now a better understanding of potential
performance impacts due to excessive class loading operations. While JDK 1.7 and
modern Java EE containers brought great improvements on class loader related issues
such as deadlocks and thread lock contention, potential problematic scenarios
still remain. For this reason, I highly recommend that you closely monitor your
application behaviour, logs and ensure that class loader related errors such as java.lang.ClassNotFoundException and java.lang.NoClassDefFoundError are aggressively corrected.
I’m
looking forward for your comments and please share your troubleshooting
experience with Java class loaders.
