About one week ago I was struggling at work with a really strange scalability issue on the back-end system I'm responsible of.
Once a system looks like frozen and does not react it could be possible it has been somehow somewhere deadlocked.
Thus I asked the JVM about the presence of any deadlocked threads, and the answer has been:
Found one Java-level deadlock:
=============================
"Thread-11":
waiting to lock monitor 0x08078ac4 (object 0xa5c85f98, a oracle.jdbc.driver.LogicalConnection),
which is held by "RMICallHandler-29"
"RMICallHandler-29":
waiting to lock monitor 0x08078e04 (object 0x67154b48, a oracle.jdbc.pool.OracleImplicitConnectionCache),
which is held by "Thread-11"
Java stack information for the threads listed above:
===================================================
"Thread-11":
at oracle.jdbc.driver.LogicalConnection.close(LogicalConnection.java:194)
- waiting to lock <0xa5c85f98> (a oracle.jdbc.driver.LogicalConnection)
at oracle.jdbc.pool.OracleImplicitConnectionCache.closeCheckedOutConnection(OracleImplicitConnectionCache.java:1148)
at oracle.jdbc.pool.OracleImplicitConnectionCacheThread.runTimeToLiveTimeout(OracleImplicitConnectionCacheThread.java:153)
- locked <0x67154b48> (a oracle.jdbc.pool.OracleImplicitConnectionCache)
at oracle.jdbc.pool.OracleImplicitConnectionCacheThread.run(OracleImplicitConnectionCacheThread.java:67)
"RMICallHandler-29":
at oracle.jdbc.pool.OracleImplicitConnectionCache.reusePooledConnection(OracleImplicitConnectionCache.java:1422)
- waiting to lock <0x67154b48> (a oracle.jdbc.pool.OracleImplicitConnectionCache)
at oracle.jdbc.pool.OracleConnectionCacheEventListener.connectionClosed(OracleConnectionCacheEventListener.java:61)
- locked <0x673947e8> (a oracle.jdbc.pool.OracleConnectionCacheEventListener)
at oracle.jdbc.pool.OraclePooledConnection.callImplicitCacheListener(OraclePooledConnection.java:519)
at oracle.jdbc.pool.OraclePooledConnection.logicalCloseForImplicitConnectionCache(OraclePooledConnection.java:440)
at oracle.jdbc.pool.OraclePooledConnection.logicalClose(OraclePooledConnection.java:456)
at oracle.jdbc.driver.LogicalConnection.closeInternal(LogicalConnection.java:221)
at oracle.jdbc.driver.LogicalConnection.close(LogicalConnection.java:194)
- locked <0xa5c85f98> (a oracle.jdbc.driver.LogicalConnection)
at oracle.oc4j.sql.spi.ManagedConnectionImpl._cleanup(ManagedConnectionImpl.java:371)
at oracle.oc4j.sql.spi.ManagedConnectionImpl.cleanup(ManagedConnectionImpl.java:339)
at com.evermind.server.connector.ConnectionContext.cleanup(ConnectionContext.java:893)
- locked <0xa5d4ee08> (a com.evermind.server.connector.ConnectionContext)
at com.evermind.server.connector.ConnectionContext.cleanupIfUnreferenced(ConnectionContext.java:836)
- locked <0xa5d4ee08> (a com.evermind.server.connector.ConnectionContext)
at com.evermind.server.connector.ConnectionContext.jtaTransactionEnded(ConnectionContext.java:733)
- locked <0xa5d4ee08> (a com.evermind.server.connector.ConnectionContext)
at com.evermind.server.connector.ConnectionContext.afterCompletion(ConnectionContext.java:542)
at com.evermind.server.ApplicationServerTransaction.callSynchronizationAfterCompletion(ApplicationServerTransaction.java:1184)
at com.evermind.server.ApplicationServerTransactionManager.freeResources(ApplicationServerTransactionManager.java:394)
at com.evermind.server.ApplicationServerTransaction.doCommit(ApplicationServerTransaction.java:282)
- locked <0xa5d5bab8> (a com.evermind.server.ApplicationServerTransaction)
at com.evermind.server.ApplicationServerTransaction.commit(ApplicationServerTransaction.java:162)
at com.evermind.server.ApplicationServerTransactionManager.commit(ApplicationServerTransactionManager.java:472)
at com.evermind.server.ejb.EJBTransactionManager.end(EJBTransactionManager.java:132)
at com.evermind.server.ejb.interceptor.system.TxRequiredInterceptor.invoke(TxRequiredInterceptor.java:57)
at com.evermind.server.ejb.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:119)
at com.evermind.server.ejb.interceptor.system.DMSInterceptor.invoke(DMSInterceptor.java:52)
at com.evermind.server.ejb.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:119)
at com.evermind.server.ejb.InvocationContextPool.invoke(InvocationContextPool.java:55)
at com.evermind.server.ejb.StatelessSessionEJBObject.OC4J_invokeMethod(StatelessSessionEJBObject.java:87)
at DgComponentSession_RemoteProxy_k3k2ci.create(Unknown Source)
at sun.reflect.GeneratedMethodAccessor126.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at com.evermind.server.rmi.RmiMethodCall.run(RmiMethodCall.java:53)
at com.evermind.util.ReleasableResourcePooledExecutor$MyWorker.run(ReleasableResourcePooledExecutor.java:303)
at java.lang.Thread.run(Thread.java:595)
Found 1 deadlock.
Once I saw this output message I could not belive to my own two eyes, I had finally found a deadlock in a third-party piece of code! I still belive it is a quite rare thing to see so clearly, so I felt quite happy and excited when I saw the mesage above for the first time.
Just a silly post to share this rare little-thing with others.
F.
Subscribe to:
Post Comments (Atom)
3 comments:
Hi
I'm fighting with similar Orace JDBC driver deadlocks :(
Did you find any solution or workaround for Oracle JDBC driver deadlocks?
Smiles!
Adam
PS.
Here you have my problem description:
http://forum.hibernate.org/viewtopic.php?p=2386237
I have taken a look at the URL you have posted. I actually see something different than the deadlock I've faced some months ago, but it still seems a deadlock.
The rightest way to see whether there's a deadlock or not while your application is running you should use one of the standard tools provided with your JVM (jconsole if you like using graphical tools). If your application freezes you can run the deadlock-detection tool a see if there's really a deadlock.
Should you have faced the same problem I did, you better contact your support and ask for a patch.
F.
Post a Comment