6:14 a.m.
Bad usage of ClassLoader.loadClass() for Java6 in
SerializationHelper$CustomObjectInputStream - deserialization bottleneck for arrays
-------------------------------------------------------------------------------------------------------------------------------------
Key: HHH-2990
URL: http://opensource.atlassian.com/projects/hibernate/browse/HHH-2990
Project: Hibernate3
Issue Type: Bug
Affects Versions: 3.2.5
Environment: Hibernate 3.2.5, Java 6 Sun (any), any platform (tested Linux x64,
Mac x64 (J6dp1))
Reporter: Tom Eicher
Sun has "clarified" (others say modified) the API of
"ClassLoader.loadClass()" and no longer allows this to be called for arrays,
e.g. String[].
( see: http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6500212 and duplicates )
and states that this has always been very unstable to use/do in the first place.
So trying to load an array of something using this method results in
ClassNotFoundException.
The correct thing to do is call Class.forName(className,false,myClassLoader); instead of
myClassLoader.loadClass(className);
In SerializationHelper$CustomObjectInputStream.resolveClass() we do
ClassLoader loader = Thread.currentThread().getContextClassLoader();
try {
resolvedClass = loader.loadClass(className);
log.trace("Class resolved through context class loader");
}
catch(ClassNotFoundException e) {
log.trace("Asking super to resolve");
resolvedClass = super.resolveClass(v);
}
which results in the deserialization process for a String[] always searching String[] in
all the application's jars/wars/etc before really loading it.
The bad thing is, loadClass() is synchronized.
In our case, we have multiple threads loading database rows containing String[]s, which
results in one Thread doing
INFO | jvm 1 | 2007/11/30 16:56:44 | java.lang.Thread.State: RUNNABLE
INFO | jvm 1 | 2007/11/30 16:56:44 | at java.util.zip.ZipFile.getEntry(Native
Method)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.util.zip.ZipFile.getEntry(ZipFile.java:149)
INFO | jvm 1 | 2007/11/30 16:56:44 | - locked <0x00002aaab4047c20> (a
java.util.jar.JarFile)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.util.jar.JarFile.getEntry(JarFile.java:206)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.util.jar.JarFile.getJarEntry(JarFile.java:189)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
sun.misc.URLClassPath$JarLoader.getResource(URLClassPath.java:754)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
sun.misc.URLClassPath.getResource(URLClassPath.java:168)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.net.URLClassLoader$1.run(URLClassLoader.java:192)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.security.AccessController.doPrivileged(Native Method)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.net.URLClassLoader.findClass(URLClassLoader.java:188)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.lang.ClassLoader.loadClass(ClassLoader.java:306)
INFO | jvm 1 | 2007/11/30 16:56:44 | - locked <0x00002aaab4025998> (a
org.apache.catalina.loader.StandardClassLoader)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.lang.ClassLoader.loadClass(ClassLoader.java:299)
INFO | jvm 1 | 2007/11/30 16:56:44 | - locked <0x00002aaab4095a68> (a
org.apache.catalina.loader.StandardClassLoader)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.lang.ClassLoader.loadClass(ClassLoader.java:251)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1346)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1205)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
org.hibernate.util.SerializationHelper$CustomObjectInputStream.resolveClass(SerializationHelper.java:263)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1575)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.io.ObjectInputStream.readClassDesc(ObjectInputStream.java:1496)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.io.ObjectInputStream.readArray(ObjectInputStream.java:1624)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1323)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.io.ObjectInputStream.readObject(ObjectInputStream.java:351)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
org.hibernate.util.SerializationHelper.deserialize(SerializationHelper.java:210)
and all other threads doing nothing
INFO | jvm 1 | 2007/11/30 16:56:44 | java.lang.Thread.State: BLOCKED (on object
monitor)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.lang.ClassLoader.loadClass(ClassLoader.java:295)
INFO | jvm 1 | 2007/11/30 16:56:44 | - waiting to lock
<0x00002aaab4095a68> (a org.apache.catalina.loader.StandardClassLoader)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.lang.ClassLoader.loadClass(ClassLoader.java:251)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1346)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1205)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
org.hibernate.util.SerializationHelper$CustomObjectInputStream.resolveClass(SerializationHelper.java:263)
INFO | jvm 1 | 2007/11/30 16:56:44 | at
java.io.ObjectInputStream.readNonProxyDesc(ObjectInputStream.java:1575)
(rest of stack trace identical to above)
This can easily be worked around by setting the compatibility property
-Dsun.lang.ClassLoader.allowArraySyntax=true
however a) this workaround might not be around for long and b) most people will never find
this bottleneck, therefore will not apply the workaround.
For our case, we got a 35% performance increase just be setting this property (and not a
single loadClass() or ZipFile.getEntry() in any thread dump any more).
Cheers, Tom.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://opensource.atlassian.com/projects/hibernate/secure/Administrators....
-
For more information on JIRA, see: http://www.atlassian.com/software/jira