[Springframework-developer] Race condition with transaction synchronization?

[Dave B. <dba...@on...>]

Hello,

I posted this on the forums, but costin and Rod suggested that I post it 
here.

I'm using Spring Framework 1.1.5 with Hibernate on WebLogic Server 6.1. 
I'm testing timeout scenarios, and I've run into an issue I need some 
help with. I'm slowly eliminating EJB's from my application, but I do 
have some legacy EJB code to deal with. In my scenario, my servlet is 
calling a SLSB, which in turn calls spring-managed transactional 
services. These transaction service join the CMT transaction created by 
the EJB container. I have:

Code:

1) A servlet calls SLSB with CMT.
2) The SLSB calls SessionFactoryUtils.getSession(sessionFactory, true)
-- This binds the hibernate session to the current thread
3) The SLSB calls a spring-managed transactional service
-- This bean uses the bound session as expected
4) The SLSB calls another spring-managed transactional service
-- This bean uses the bound session as expected
5) The SLSB exits
-- The TransactionSynchronizationManager unbinds the bound session as 
expected


So the non-timeout scenario functions as expected. Now I introduce a 
timeout (by causing blocking in by database) prior to (3). With the 
timeout scenario, I encounter one of two results:

Code:

A) A spring HibernateJdbcException wrapping a weblogic TimedOutException 
as expected.
B) An IllegalStateException Already value 
[org.springframework.orm.hibernate.SessionHolder@6f2304] for key 
[net.sf.hibernate.impl.SessionFactoryImpl@655ad0] bound to thread 
[ExecuteThread: '29' for queue: 'default']


Whether I get (A) or (B) is seemingly random. I've created a diagnostic 
version of SessionFactoryUtils to see what is happening in more detail.
In scenario (B), it looks like WebLogic's transaction manager is 
grabbing another thread from the pool and is invoking spring's 
JtaSessionSynchronization.afterCompletion() which is resulting in 
doClose() being called. I've added a dumpStack() in doClose(), and here 
is what I see. The line numbers will be a little off because of my 
diagnostic code:

Code:

java.lang.Exception: Stack trace
        at java.lang.Thread.dumpStack(Thread.java:992)
        at 
org.springframework.orm.hibernate.SessionFactoryUtils.doClose(SessionFactoryUtils.java:738)
        at 
org.springframework.orm.hibernate.SessionFactoryUtils.closeSessionOrRegisterDeferredClose(SessionFactoryUtils.java:726)
        at 
org.springframework.orm.hibernate.SessionFactoryUtils.access$300(SessionFactoryUtils.java:89)
        at 
org.springframework.orm.hibernate.SessionFactoryUtils$SpringSessionSynchronization.beforeCompletion(SessionFactoryUtils.java:867)
        at 
org.springframework.orm.hibernate.SessionFactoryUtils$JtaSessionSynchronization.afterCompletion(SessionFactoryUtils.java:978)
        at 
weblogic.transaction.internal.ServerSCInfo.callAfterCompletions(ServerSCInfo.java:464)
        at 
weblogic.transaction.internal.ServerTransactionImpl.callAfterCompletions(ServerTransactionImpl.java:2139)
        at 
weblogic.transaction.internal.ServerTransactionImpl.setRolledBack(ServerTransactionImpl.java:2090)
        at 
weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:2188)DEBUG 
18:19:23,000 [ExecuteThread: '34' for queue: 'default'] [edemo_acme] 
(Transacti
        at 
weblogic.transaction.internal.ServerTransactionImpl.globalRollback(ServerTransactionImpl.java:2080)
        at 
weblogic.transaction.internal.TransactionImpl$1.execute(TransactionImpl.java:1617)
        at weblogic.kernel.ExecuteThread.execute(ExecuteThread.java:159)
        at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:140)


Meanwhile, the original timeout thread, who is in the middle of calling 
getSession(), and hasn't yet encountered the weblogic TimedOutException,
tries to bind the session holder to the thread, and fails:

Code:

ERROR 18:19:23,046 [ExecuteThread: '34' for queue: 'default'] 
[edemo_acme] (TransactionAspectSupport.java:264) - Application exception 
overridden by rollback exception
java.lang.IllegalStateException: Already value 
[org.springframework.orm.hibernate.SessionHolder@747db9] for key 
[net.sf.hibernate.impl.SessionFactoryImpl@606e55] bound to thread 
[ExecuteThread: '34' for queue: 'default']
        at 
org.springframework.transaction.support.TransactionSynchronizationManager.bindResource(TransactionSynchronizationManager.java:147)
        at 
org.springframework.orm.hibernate.SessionFactoryUtils.getSession(SessionFactoryUtils.java:346)
        at 
org.springframework.orm.hibernate.SessionFactoryUtils.getSession(SessionFactoryUtils.java:266)
        at 
org.springframework.orm.hibernate.SessionFactoryUtils.getSession(SessionFactoryUtils.java:223)
        at 
org.springframework.orm.hibernate.HibernateInterceptor.invoke(HibernateInterceptor.java:149)
        at 
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:144)
        at 
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:174)
        at $Proxy93.findContract(Unknown Source)
        at 
mycode.ContractServiceImpl.findContract(ContractServiceImpl.java:59)
        ...


It's not clear to me who the culprit is here, not being that familiar 
with JTA and Spring. Perhaps the beforeCompletion() called by the 
weblogic transaction manager is not cleaning up properly? Any ideas?

Thanks for your help,
Dave