[jboss-user] [JBoss Cache: Core Edition] - Re: on child insert parent, child collection updated in DB b

dukehoops do-not-reply at jboss.com
Tue Mar 17 14:53:17 EDT 2009


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



More information about the jboss-user mailing list