Uploaded image for project: 'Infinispan'
  1. Infinispan
  2. ISPN-5356

Transactional, optimistic-locked caches do not honour Flag.FAIL_SILENTLY

    XMLWordPrintable

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Done
    • 6.0.2.Final
    • 7.2.0.Final
    • Core
    • None
    • Hide
      1. Configure Infinispan as the second-level cache for Hibernate
      2. Execute a Hibernate query

      (of course, it is not so easy - this is a concurrency problem, so the last step would have to be conducted repeatedly with the right timing)

      Show
      Configure Infinispan as the second-level cache for Hibernate Execute a Hibernate query (of course, it is not so easy - this is a concurrency problem, so the last step would have to be conducted repeatedly with the right timing)

    Description

      There is a related issue in the Hibernate JIRA, which can be found at:
      https://hibernate.atlassian.net/browse/HHH-7898
      However, I believe this to be an Infinispan issue, as per my analysis below.

      The following Exception is thrown when two threads are simultaneously committing a JTA transaction in which an entry has been written to Hibernate's "replicated-query" cache using the same key.

      10:55:02.238 ERROR saction.TransactionCoordinator  - ISPN000255: Error while processing prepare
      org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [0 milliseconds] on key [sql: select ...; parameters: ...; named parameters: {...}; transformer: org.hibernate.transform.CacheableResultTransformer@110f2] for requestor [GlobalTransaction:<null>:197882:local]! Lock held by [null]
      	at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:198)
      	at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:171)
      	at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:169)
      	at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:98)
      	at org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.lockAndRecord(OptimisticLockingInterceptor.java:211)
      	at org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitSingleKeyCommand(OptimisticLockingInterceptor.java:206)
      	at org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:199)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:70)
      	at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:270)
      	at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:75)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
      	at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:36)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:98)
      	at org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:114)
      	at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:101)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124)
      	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.visitPrepareCommand(AbstractVisitor.java:96)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124)
      	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.visitPrepareCommand(AbstractVisitor.java:96)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124)
      	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:333)
      	at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:119)
      	at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:101)
      	at org.infinispan.transaction.synchronization.SynchronizationAdapter.beforeCompletion(SynchronizationAdapter.java:44)
      	at com.metiom.core.transaction.TransactionImpl.lambda$commit$0(TransactionImpl.java:115)
      	at com.metiom.core.transaction.TransactionImpl$$Lambda$2/330107372.accept(Unknown Source)
      	at com.metiom.core.transaction.TransactionImpl.forEachSynchronisation(TransactionImpl.java:264)
      	at com.metiom.core.transaction.TransactionImpl.commit(TransactionImpl.java:114)
      	at com.metiom.core.transaction.TransactionManagerImpl.commit(TransactionManagerImpl.java:142)
      	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)
      	at org.springframework.transaction.interceptor.TransactionAspectSupport.commitTransactionAfterReturning(TransactionAspectSupport.java:497)
      	at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:277)
      	at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:96)
      	at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
      	...
      

      The configuration for Hibernate's "replicated-query" cache is as follows (from Hibernate's infinispan-configs.xml)

         <!-- An alternative configuration for entity/collection caching that uses replication instead of invalidation -->
         <namedCache name="replicated-entity">
            <clustering mode="replication">
               <stateTransfer fetchInMemoryState="false" timeout="20000"/>
               <sync replTimeout="20000"/>
            </clustering>
            <locking isolationLevel="READ_COMMITTED" concurrencyLevel="1000"
                     lockAcquisitionTimeout="15000" useLockStriping="false"/>
            <!-- Eviction configuration.  WakeupInterval defines how often the eviction thread runs, in milliseconds.  
                 0 means the eviction thread will never run.  A separate executor is used for eviction in each cache. -->
            <eviction maxEntries="10000" strategy="LRU"/>
            <expiration maxIdle="100000" wakeUpInterval="5000"/>
            <lazyDeserialization enabled="true"/>
            <transaction transactionMode="TRANSACTIONAL" autoCommit="false"
                         lockingMode="OPTIMISTIC"/>
         </namedCache>
      

      Additionally, the cache is configured programmatically with:

      • Flag.ZERO_LOCK_ACQUISITION_TIMEOUT; and
      • Flag.FAIL_SILENTLY

      The situation is that two threads are concurrently attempting to lock the same key on commit.

      • During a JTA transaction, a Hibernate query is executed, and Hibernate places a result in the query cache.
      • On commit, the SynchronizationAdaptor creates a PrepareCommand, which contains one or more "modifications", one of which is a PutKeyValueCommand. The SynchronizationAdapter invokes the PrepareCommand.
      • When visited, the OptimisticLockingInterceptor loops through the modifications held by the PrepareCommand and visits each one.
      • When the PutKeyValueCommand is visited, LockManagerImpl discovers that the key is locked, and throws TimeoutException.
      • The Exception is caught by InvocationContextInterceptor, and attempts to find out whether the command it was invoking is affected by Flag.FAIL_SILENTLY. PrepareCommand does not implement FlagAffectedCommand, so this test fails and the Exception is propagated.

      It is important to note here that the PutKeyValueCommand does implement FlagAffectedCommand, and does have the Flag.FAIL_SILENTLY flag set. So the problem seems to be that OptimisticLockingInterceptor is unaware that the modifications to the PrepareCommand could throw Exceptions which can be suppressed.

      Attachments

        Activity

          People

            gzamarre Galder ZamarreƱo
            itchimus Mitchell Archibald (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: