I think failure to acquire stems from failure to evict locks *after tx commit*. 
Here's a sample exception stack:

anonymous wrote : 
  | [11:03:29:881] main [ERROR] - 
org.hibernate.engine.ActionQueue.afterTransactionCompletion(line:207) - could 
not release a cache lock
  | org.hibernate.cache.CacheException: java.lang.IllegalStateException: 
Transaction a Bitronix Transaction with GTRID 
[737072696E672D62746D00000120159A386A00000033], status=COMMITTED, 1 resource(s) 
enlisted (started Tue Mar 17 11:03:29 PDT 2009) is not in a valid state to be 
invoking cache operations on.
  |     at 
org.hibernate.cache.jbc2.util.CacheHelper.removeAll(CacheHelper.java:380)
  |     at 
org.hibernate.cache.jbc2.util.CacheHelper.removeAll(CacheHelper.java:360)
  |     at 
org.hibernate.cache.jbc2.access.TransactionalAccessDelegate.evictOrRemoveAll(TransactionalAccessDelegate.java:146)
  |     at 
org.hibernate.cache.jbc2.access.TransactionalAccessDelegate.evictAll(TransactionalAccessDelegate.java:142)
  |     at 
org.hibernate.cache.jbc2.entity.TransactionalAccess.evictAll(TransactionalAccess.java:102)
  |     at 
org.hibernate.impl.SessionFactoryImpl.evictEntity(SessionFactoryImpl.java:870)
  |     at 
org.hibernate.action.BulkOperationCleanupAction.evictEntityRegions(BulkOperationCleanupAction.java:153)
  |     at 
org.hibernate.action.BulkOperationCleanupAction.afterTransactionCompletion(BulkOperationCleanupAction.java:132)
  |     at 
org.hibernate.engine.ActionQueue.afterTransactionCompletion(ActionQueue.java:198)
  |     at 
org.hibernate.impl.SessionImpl.afterTransactionCompletion(SessionImpl.java:451)
  |     at 
org.hibernate.jdbc.JDBCContext.afterTransactionCompletion(JDBCContext.java:252)
  |     at 
org.hibernate.transaction.CacheSynchronization.afterCompletion(CacheSynchronization.java:117)
  |     at 
bitronix.tm.BitronixTransaction.fireAfterCompletionEvent(BitronixTransaction.java:382)
  |     at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:188)
  |     at 
bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:96)
  |     at 
org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1028)
  |     at 
org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:732)
  |     at 
org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:701)
  |     at 
org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:321)
  |     at 
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:116)
  |     at 
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
  |     at 
org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:77)
  |     at 
com.doppelganger.service.tx.TxRetryAspect.doRetryIfNeeded(TxRetryAspect.java:114)
  |     at 
com.doppelganger.service.tx.TxRetryAspect.retryIfNeededForTxAnnotation(TxRetryAspect.java:90)
  |     at sun.reflect.GeneratedMethodAccessor81.invoke(Unknown Source)
  |     at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
  |     at java.lang.reflect.Method.invoke(Method.java:597)
  |     at 
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:627)
  |     at 
org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:616)
  |     at 
org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:64)
  |     at 
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:160)
  |     at 
org.springframework.aop.aspectj.AspectJAfterAdvice.invoke(AspectJAfterAdvice.java:42)
  |     at 
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
  |     at 
org.springframework.aop.framework.adapter.MethodBeforeAdviceInterceptor.invoke(MethodBeforeAdviceInterceptor.java:50)
  |     at 
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
  |     at 
org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
  |     at 
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
  |     at 
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
  |     at $Proxy96.leaveServer(Unknown Source)
  |     at com.doppelganger.test.TestServer.leave(TestServer.java:123)
  |     at 
com.doppelganger.service.userrelations.UserToUserSessionTest.testUserSessionLifecycle(UserToUserSessionTest.java:143)
  |     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
  |     at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
  |     at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
  |     at java.lang.reflect.Method.invoke(Method.java:597)
  |     at junit.framework.TestCase.runTest(TestCase.java:168)
  |     at junit.framework.TestCase.runBare(TestCase.java:134)
  |     at 
org.springframework.test.ConditionalTestCase.runBare(ConditionalTestCase.java:76)
  |     at junit.framework.TestResult$1.protect(TestResult.java:110)
  |     at junit.framework.TestResult.runProtected(TestResult.java:128)
  |     at junit.framework.TestResult.run(TestResult.java:113)
  |     at junit.framework.TestCase.run(TestCase.java:124)
  |     at junit.framework.TestSuite.runTest(TestSuite.java:232)
  |     at junit.framework.TestSuite.run(TestSuite.java:227)
  |     at 
org.junit.internal.runners.JUnit38ClassRunner.run(JUnit38ClassRunner.java:79)
  |     at junit.framework.JUnit4TestAdapter.run(JUnit4TestAdapter.java:39)
  |     at 
org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:420)
  |     at 
org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.launch(JUnitTestRunner.java:911)
  |     at 
org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.main(JUnitTestRunner.java:768)
  | Caused by: java.lang.IllegalStateException: Transaction a Bitronix 
Transaction with GTRID [737072696E672D62746D00000120159A386A00000033], 
status=COMMITTED, 1 resource(s) enlisted (started Tue Mar 17 11:03:29 PDT 2009) 
is not in a valid state to be invoking cache operations on.
  |     at 
org.jboss.cache.interceptors.TxInterceptor.registerTransaction(TxInterceptor.java:604)
  |     at 
org.jboss.cache.interceptors.TxInterceptor.attachGlobalTransaction(TxInterceptor.java:405)
  |     at 
org.jboss.cache.interceptors.TxInterceptor.attachGtxAndPassUpChain(TxInterceptor.java:260)
  |     at 
org.jboss.cache.interceptors.TxInterceptor.handleDefault(TxInterceptor.java:250)
  |     at 
org.jboss.cache.commands.AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75)
  |     at 
org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
  |     at 
org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
  |     at 
org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:131)
  |     at 
org.jboss.cache.commands.AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75)
  |     at 
org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
  |     at 
org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
  |     at 
org.jboss.cache.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:178)
  |     at 
org.jboss.cache.interceptors.InvocationContextInterceptor.visitRemoveNodeCommand(InvocationContextInterceptor.java:88)
  |     at 
org.jboss.cache.commands.write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125)
  |     at 
org.jboss.cache.interceptors.InterceptorChain.invoke(InterceptorChain.java:287)
  |     at 
org.jboss.cache.invocation.CacheInvocationDelegate.removeNode(CacheInvocationDelegate.java:409)
  |     at 
org.hibernate.cache.jbc2.util.CacheHelper.removeAll(CacheHelper.java:378)
  |     ... 58 more
  | 

and this happens because JBC makes an assumption about state of JTA Transaction 
to which it keeps a pointer:
-in InvocationContextInterceptor.handleAll:
Transaction tx = getTransaction(); //does not check TX Status
-later in TxInterceptor.attachGtxAndPassUpChain:
if (tx != null) attachGlobalTransaction(ctx, tx, command); //does not check TX 
Status
-finally in TxInterceptor.registerTransaction we fail because tx isn't active:

  |       boolean txValid = TransactionTable.isValid(tx);
  |       if (!txValid) {
  |          throw new IllegalStateException("Transaction " + tx + " is not in 
a valid state to be invoking cache operations on.");
  |       }
  | 

The problem is that:
-Hibernate Core calls into cache in Synchronization's afterCompletion, when TX 
is already in committed state.
-in InvocationContextInterceptor JBC assumes that if txManager.getTransaction() 
returns a non-null then TX is still active. Reading JTA Spec 1.1 that's not 
guaranteed:

In section 3.2.2:
anonymous wrote : 
  | The TransactionManager.commit method completes the transaction currently
  | associated with the calling thread. After the commit method returns, the 
calling thread
  | is not associated with a transaction.
  | 

However, tx Synchronization may be notified from within commit() method - at 
which point TX is already Status=COMMITTED but is still on the thread (because 
commit() hasn't returned yet). i.e:


  | TransactionManager's commit(){
  | 
  | //do commit
  | finally{
  |     fireSynchronizationsAfterTxCompletion(); //still in commit()
  | }
  | }
  | 

What is the intent of InvocationContextInterceptor.getTransaction()? Is it to 
return any Transaction or an active/valid one? From what txInterceptor does 
subsequently the answer seems to be "a valid one". If so, IMO the method should 
be changed to test validity of tx and return null if this test fails. How about 
this (renamed from ICI.getTransaction()):

  |    /**
  |     *
  |     * @return a valid, usable Transaction if one exists, null otherwise
  |     * @throws javax.transaction.SystemException
  |     */
  |    private Transaction getValidTransaction() throws SystemException
  |    {
  |       // this creates a context if one did not exist.
  |       if (txManager == null)
  |       {
  |          if (trace) log.trace("no transaction manager configured, setting 
tx as null.");
  |          return null;
  |       }
  |       else
  |       {
  |          Transaction tx = txManager.getTransaction();
  |          //is this TX still usable?
  |          if(tx != null && tx.getStatus() == Status.ACTIVE) //or 'if (tx != 
null && TransactionTable.isValid(tx))'  - not sure
  |          {
  |              return tx;
  |          }
  |          else{
  |              return null;
  |          }
  |       }
  |    }
  | 








View the original post : 
http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4218796#4218796

Reply to the post : 
http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&p=4218796
_______________________________________________
jboss-user mailing list
jboss-user@lists.jboss.org
https://lists.jboss.org/mailman/listinfo/jboss-user

Reply via email to