8 Replies Latest reply on Oct 19, 2015 12:45 PM by wedoc

    Infinispan as second level cache - Exception on commit & infinispan locks

    wedoc

      Hi all,

       

      Currently I'm working on a project where we are using infinispan (6.0.2) as a second level cache for Hibernate (4.3.4). Everything is working fine except one of the cases: if an exception is thrown at the time I'm calling the commit method (UnexpectedRollbackException generated by a database error - ORAXXXX) hibernate throws an exception saying that Infinispan could not release the cache locks. After this error if I try to access this cache entry I get a timeout when trying to get the lock... really a weird. I'm using JTA and JOTM to manage the transaction.

       

      This error is reproduced even in a local environment where there are not other nodes in the cluster.. Infinispan says that the transaction is not in a valid state to perform cache operations, so I guess that somehow Hibernate is completing the transaction before Infinispan can rollback changes?


      Any recommendation about how to solve the issue?

       

       

       

      Thanks in advance!!

        • 1. Re: Infinispan as second level cache - Exception on commit & infinispan locks
          rvansa

          Usually the stacktrace and logs (preferably on TRACE level) is helpful when investigating any issue like that. The locks should be released from afterCommit phase of the transaction (Infinispan is registered as synchronization in 2LC configurations), does JOTM call it after DB error?

          • 2. Re: Infinispan as second level cache - Exception on commit & infinispan locks
            wedoc

            Hi,

             

            Thanks for the fast response. This is the information I get from log files:

             

            [General Exception, see the log trace for resolution::org.hibernate.AssertionFailure: Exception releasing cache locks

              at org.hibernate.engine.spi.ActionQueue$AfterTransactionCompletionProcessQueue.afterTransactionCompletion(ActionQueue.java:743)

              at org.hibernate.engine.spi.ActionQueue.afterTransactionCompletion(ActionQueue.java:377)

              at org.hibernate.internal.SessionImpl.afterTransactionCompletion(SessionImpl.java:529)

              at org.hibernate.engine.transaction.internal.TransactionCoordinatorImpl.afterTransaction(TransactionCoordinatorImpl.java:150)

              at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorNonTrackingImpl.doAfterCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:140)

              at org.hibernate.engine.transaction.synchronization.internal.SynchronizationCallbackCoordinatorTrackingImpl.afterCompletion(SynchronizationCallbackCoordinatorTrackingImpl.java:87)

              at org.hibernate.engine.transaction.synchronization.internal.RegisteredSynchronization.afterCompletion(RegisteredSynchronization.java:56)

              at org.objectweb.jotm.SubCoordinator.doAfterCompletion(SubCoordinator.java:1634)

              at org.objectweb.jotm.SubCoordinator.doRollback(SubCoordinator.java:1423)

              at org.objectweb.jotm.SubCoordinator.commit_one_phase(SubCoordinator.java:475)

              at org.objectweb.jotm.TransactionImpl.commit(TransactionImpl.java:320)

              at org.objectweb.jotm.Current.commit(Current.java:471)

              at org.springframework.transaction.jta.JtaTransactionManager.doCommit(JtaTransactionManager.java:1021)

              at org.springframework.transaction.support.AbstractPlatformTransactionManager.processCommit(AbstractPlatformTransactionManager.java:757)

              at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:726)

            .....

            Caused by: java.lang.IllegalStateException: Transaction bb14:38:0:0138cc5c4ec23813db...6fcc26: is not in a valid state to be invoking cache operations on.

              at org.infinispan.interceptors.TxInterceptor.enlist(TxInterceptor.java:275)

              at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:240)

              at org.infinispan.interceptors.TxInterceptor.visitRemoveCommand(TxInterceptor.java:196)

              at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:57)

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)

              at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:112)

              at org.infinispan.commands.AbstractVisitor.visitRemoveCommand(AbstractVisitor.java:37)

              at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:57)

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)

              at org.infinispan.statetransfer.StateTransferInterceptor.handleNonTxWriteCommand(StateTransferInterceptor.java:206)

              at org.infinispan.statetransfer.StateTransferInterceptor.visitRemoveCommand(StateTransferInterceptor.java:156)

              at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:57)

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)

              at org.infinispan.interceptors.CacheMgmtInterceptor.visitRemoveCommand(CacheMgmtInterceptor.java:166)

              at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:57)

              at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)

              at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:110)

              at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:73)

              at org.infinispan.commands.AbstractVisitor.visitRemoveCommand(AbstractVisitor.java:37)

              at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:57)

              at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:333)

              at org.infinispan.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1306)

              at org.infinispan.CacheImpl.removeInternal(CacheImpl.java:407)

              at org.infinispan.CacheImpl.remove(CacheImpl.java:400)

              at org.infinispan.DecoratedCache.remove(DecoratedCache.java:406)

              at org.hibernate.cache.infinispan.access.TransactionalAccessDelegate.remove(TransactionalAccessDelegate.java:211)

              at org.hibernate.cache.infinispan.naturalid.TransactionalAccess.remove(TransactionalAccess.java:87)

              at org.hibernate.engine.internal.StatefulPersistenceContext$1$1.doAfterTransactionCompletion(StatefulPersistenceContext.java:1735)

              at org.hibernate.engine.spi.ActionQueue$AfterTransactionCompletionProcessQueue.afterTransactionCompletion(ActionQueue.java:736)

             

             

            I tried different lock and transaction configurations but I always get the same error.

             

            Btw, I have noticed that after this error I cannot see a rollback on the MBeans: commit:0, prepare: 1, rollback:0

             

            Thanks in advance.

            • 3. Re: Infinispan as second level cache - Exception on commit & infinispan locks
              rvansa

              Right, the cache.remove() is called from synchronization's afterTransaction (upon failure to commit that TX properly). IMO it's a bug in StatefulPersistenceContext, the remove there is not necessary when the cache behaves transactionally. However, since 4.x is at end of life, please upgrade to Hibernate ORM 5, where non-transactional caches should be used (and are default).

              • 4. Re: Infinispan as second level cache - Exception on commit & infinispan locks
                wedoc

                Hi Radim,

                 

                Thanks for your comments, really appreciated!

                 

                What do you mean with "non-transactional caches should be used"? Does it mean that using Hibernate 5 non-transactional caches provide the same level of consistency than transactional caches on Hibernate 4?

                 

                Thanks and regards,

                Juan

                • 5. Re: Infinispan as second level cache - Exception on commit & infinispan locks
                  rvansa

                  In Hibernate ORM 5, several bugs that caused stale reads etc. were fixed. The reworked mechanism does not rely on transactional behaviour of caches, it rather does the two-phase on its own. Transactional caches are still supported, but generally non-transactional caches are more performant. And yes, you get the same consistency.

                   

                  The consistency should not depend on your cache configuration, that's what you say by specifying CacheConcurrencyStrategy (that is transactional, read-write, read-only or nonstrict-read-write) - though, it's possible that you break something e.g. by having the caches async. In fact transactional and read-write should offer you the same guarantees - the 2LC should be absolutely transparent. Nonstrict-read-write has somewhat relaxed semantics, we interpret that as allowed stale read until the transaction fully completes, that means all synchronizations are called. With asynchronous caches, you can't know when some updates are applied to the cache and failure (e.g. to acquire a lock) can cause some updates not being applied in the cache at all.

                  • 6. Re: Infinispan as second level cache - Exception on commit & infinispan locks
                    wedoc

                    I have checked the latest recommendations on infinispan.org user guide:

                     

                    "It is highly recommended that Hibernate is configured with JTA transactions so that both Hibernate and Infinispan cooperate within the same transaction and the interaction works as expected.

                    ...

                    Risks here include failures to update the 2LC leaving it with stale data while the database committed data correctly. It has also been observed that under some circumstances where JTA was not used, commit/rollbacks are not propagated to Infinispan."

                     

                    Based on your previous post, it seems that this "transactional management" is done by Hibernate, Do you know if this new Hibernate upgrade prevents the scenario highlighted by Infinispan doc?

                     

                    Thanks a lot!

                    • 7. Re: Infinispan as second level cache - Exception on commit & infinispan locks
                      rvansa

                      Documentation would deserve some update, both on Infinispan and Hibernate side... If you're interested in the way how it works internally (reviews are welcome!), some less-outdated info can be found on Infinispan Hibernate Second Level Cache improvements · infinispan/infinispan Wiki · GitHub

                      • 8. Re: Infinispan as second level cache - Exception on commit & infinispan locks
                        wedoc

                        Hi I have discovered a post (btw written by you ) where I could fine more information about that new approach (Infinispan: Hibernate Second Level Cache improvements) I will review your last link as well.

                         

                        I will comment the solution adopted here once I have resolved the issue.


                        Thanks a lot for your support.