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

Tue Dec 30 09:15:25 EST 2008

Umesh,

This is good information but it should be raised on the user forum or 
perhaps filed as a JIRA with a test case.  This list is for discussion 
of the development of Hibernate (not *using* Hibernate).

Cheers,

Chris

Unmesh joshi wrote:
> 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 at 0x4993580[thin lock]
>     at java/lang/ClassLoader.loadClass(ClassLoader.java:299)[optimized]
>     ^-- Holding lock: 
> weblogic/utils/classloaders/GenericClassLoader at 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 at 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 at 0x4915178[recursive]
>     at jrockit/vm/Classes.loadClassInternal(Classes.java:75)[optimized]
>     ^-- Holding lock: 
> weblogic/utils/classloaders/ChangeAwareClassLoader at 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 at 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 at 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! <http://lifestyle.in.msn.com/>
> ------------------------------------------------------------------------
> Get easy photo sharing with Windows Live™ Photos. Drag n’ drop 
> <http://www.microsoft.com/windows/windowslive/photos.aspx>
> 
> 
> ------------------------------------------------------------------------
> 
> _______________________________________________
> hibernate-dev mailing list
> hibernate-dev at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/hibernate-dev