large hql queries holding classloader lock for too long in weblogic
by Unmesh joshi
Hi,
We had an issue in our project where large hql expressions holding on lock to ChangeAwareClassloader in weblogic.
We had an hql query which was like
select * from ClassA a where a.identifier = 'id1' or a.identifier='id2' or ..... a.identifier='id1000'.
This was certainly bad to have this big or expression, but an issue this caused in weblogic is something interesting.
Hibernate query engine processes each identifier in a query to see if its a Java Class. So for each one of ClassA, a.identifier etc it calls Class.forName, if NoClassDefFound exception is thrown, ReflectHelper.getConstantValue returns null.
Now the problem is, if the expression is huge, recursive calls to /NodeTraverser.visitDepthFirst create huge stack trace. While building ClassNotFoundException, system class loader gets stuck to build all this stack trace. Because weblogic/utils/classloaders/ChangeAwareClassLoader.loadClass method is synchronized, any other thread trying to load any other class is blocked. If the stack trace is huge and taking consideratble amount of time to create Exception object, the lock is held for that much time, blocking every other thread trying to any the class. It brought down our servers in test environment.
Is this a known issue in weblogic and hibernate? I know that building such a large expression is bad(and we have already changed the code which was doing that), but the way its blocking the classloader in weblogic is an issue I think.
Following is the thread dump.
"[STUCK] ExecuteThread: '9' for queue: 'weblogic.kernel.Default (self-tuning)'" id=614 idx=0x3f8 tid=15385 prio=1 alive, in native, daemon
at pthread_cond_wait@@GLIBC_2.3.2+170(:0)@0x318c008a7a
at vmtWaitUntilNotSoftSuspended+66(:0)@0x2a955e35c2
at find_codeinfo+138(:0)@0x2a955b032e
at cmFindStackCodeInfoWithHint+44(:0)@0x2a955b040e
at frameIterFindCodeInfo+19(:0)@0x2a9571b11f
at frameIterGetCurrentAndStep+130(:0)@0x2a9571b489
at jniFillInStackTrace+368(:0)@0x2a95630d25
at JVM_FillInStackTrace+9(:0)@0x2a95647661
at RJNI_jrockit_vm_Reflect_fillInStackTrace0+9(:0)@0x2a956f5983
at jrockit/vm/Reflect.fillInStackTrace0(Ljava/lang/Throwable;)V(Native Method)
at java/lang/Throwable.fillInStackTrace()Ljava/lang/Throwable;(Native Method)[optimized]
at java/lang/Throwable.<init>(Throwable.java:218)[optimized]
at java/lang/Exception.<init>(Exception.java:59)[inlined]
at java/lang/ClassNotFoundException.<init>(ClassNotFoundException.java:65)[optimized]
at java/net/URLClassLoader$1.run(URLClassLoader.java:200)[inlined]
at jrockit/vm/AccessController.doPrivileged(AccessController.java:255)[inlined]
at java/net/URLClassLoader.findClass(URLClassLoader.java:188)[optimized]
at java/lang/ClassLoader.loadClass(ClassLoader.java:306)[optimized]
^-- Holding lock: java/net/URLClassLoader@0x4993580[thin lock]
at java/lang/ClassLoader.loadClass(ClassLoader.java:299)[optimized]
^-- Holding lock: weblogic/utils/classloaders/GenericClassLoader@0x469e900[thin lock]
at java/lang/ClassLoader.loadClass(ClassLoader.java:251)[inlined]
at weblogic/utils/classloaders/GenericClassLoader.loadClass(GenericClassLoader.java:158)[optimized]
at weblogic/utils/classloaders/FilteringClassLoader.findClass(FilteringClassLoader.java:83)[inlined]
at weblogic/utils/classloaders/FilteringClassLoader.loadClass(FilteringClassLoader.java:68)[optimized]
at java/lang/ClassLoader.loadClass(ClassLoader.java:299)[optimized]
^-- Holding lock: weblogic/utils/classloaders/GenericClassLoader@0x4969138[thin lock]
at java/lang/ClassLoader.loadClass(ClassLoader.java:299)[inlined]
at java/lang/ClassLoader.loadClass(ClassLoader.java:251)[inlined]
at weblogic/utils/classloaders/GenericClassLoader.loadClass(GenericClassLoader.java:158)[inlined]
at weblogic/utils/classloaders/ChangeAwareClassLoader.loadClass(ChangeAwareClassLoader.java:35)[optimized]
^-- Holding lock: weblogic/utils/classloaders/ChangeAwareClassLoader@0x4915178[recursive]
at jrockit/vm/Classes.loadClassInternal(Classes.java:75)[optimized]
^-- Holding lock: weblogic/utils/classloaders/ChangeAwareClassLoader@0x4915178[fat lock]
at jrockit/vm/RNI.c2java(JJJJJ)V(Native Method)
at jrockit/vm/Classes.forName0(Ljava/lang/String;ZLjava/lang/ClassLoader;)Ljava/lang/Class;(Native Method)
at jrockit/vm/Classes.forName(Classes.java:125)[inlined]
at java/lang/Class.forName(Class.java:164)[inlined]
at org/hibernate/util/ReflectHelper.classForName(ReflectHelper.java:100)[inlined]
at org/hibernate/util/ReflectHelper.getConstantValue(ReflectHelper.java:122)[inlined]
at org/hibernate/hql/ast/QueryTranslatorImpl$JavaConstantConverter.handleDotStructure(QueryTranslatorImpl.java:569)[inlined]
at org/hibernate/hql/ast/QueryTranslatorImpl$JavaConstantConverter.visit(QueryTranslatorImpl.java:564)[optimized]
at org/hibernate/hql/ast/util/NodeTraverser.visitDepthFirst(NodeTraverser.java:40)[optimized]
Following is part of thread dump which shows a thread waiting for Classloader lock.
"[ACTIVE] ExecuteThread: '51' for queue: 'weblogic.kernel.Default (self-tuning)'" id=7096 idx=0x6f8 tid=7459 prio=5 alive, in native, blocked, daemon
-- Blocked trying to get lock: weblogic/utils/classloaders/ChangeAwareClassLoader@0x4915178[fat lock]
at pthread_cond_wait@@GLIBC_2.3.2+170(:0)@0x318c008a7a
at tsiWaitForSignalForever+58(:0)@0x2a957035b5
at tsiWaitForSignal+39(:0)@0x2a95703610
at tsiWaitForLockSignal+39(:0)@0x2a957036f6
at tsWaitForJavaLockSignal+31(:0)@0x2a957037a5
at RJNI_jrockit_vm_Threads_waitForUnblockSignal+14(:0)@0x2a956f7620
at jrockit/vm/Threads.waitForUnblockSignal()V(Native Method)
at jrockit/vm/Locks.fatLockBlockOrSpin(Locks.java:1674)[optimized]
at jrockit/vm/Locks.lockFat(Locks.java:1775)[optimized]
at jrockit/vm/Locks.monitorEnterSecondStageHard(Locks.java:1311)[optimized]
at jrockit/vm/Locks.monitorEnterSecondStage(Locks.java:1258)[optimized]
at weblogic/utils/classloaders/ChangeAwareClassLoader.loadClass(ChangeAwareClassLoader.java:35)[optimized]
at com/sun/org/apache/xerces/internal/impl/dv/ObjectFactory.findProviderClass(ObjectFactory.java:403)[inlined]
at com/sun/org/apache/xerces/internal/impl/dv/ObjectFactory.newInstance(ObjectFactory.java:354)[inlined]
at com/sun/org/apache/xerces/internal/impl/dv/DTDDVFactory.getInstance(DTDDVFactory.java:98)[optimized]
^-- Holding lock: java/lang/Class@0x4fba6b8[recursive]
at com/sun/org/apache/xerces/internal/impl/dv/DTDDVFactory.getInstance(DTDDVFactory.java:83)[inlined]
at com/sun/org/apache/xerces/internal/parsers/XML11Configuration.<init>(XML11Configuration.java:565)[inlined]
Thanks,
Unmesh
_________________________________________________________________
Find a better job. We have plenty. Visit MSN Jobs
http://www.in.msn.com/jobs
15 years, 10 months