Re: [hibernate-dev] large hql queries holding classloader lock for too long in weblogic

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 ______________________________________________________________________ Make sure your wardrobe reflects the latest trends and styles in the world of fashion. Try it! ______________________________________________________________________ Get easy photo sharing with Windows Live™ Photos. Drag n’ drop _______________________________________________ hibernate-dev mailing list hibernate-dev(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/hibernate-dev