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

Possible loss of (pessimistic) lock if a transaction will reach timeout and/or is removed

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Critical
    • Resolution: Done
    • Affects Version/s: 10.0.0.Beta3, 9.4.15.Final
    • Fix Version/s: 10.1.0.Final
    • Component/s: Transactions
    • Labels:
      None
    • Sprint:
      DataGrid Sprint #33, DataGrid Sprint #34, DataGrid Sprint #35, DataGrid Sprint #36, DataGrid Sprint #37, DataGrid Sprint #38
    • Steps to Reproduce:
      Hide

      See attached reproducer and README

      Show
      See attached reproducer and README
    • Workaround Description:
      Hide

      completed-tx-timeout must be higher than the longest run of a transaction
      that means lockAcquisitionTimeout setting PLUS the longest possible delay which can be GC or application processing time

      Show
      completed-tx-timeout must be higher than the longest run of a transaction that means lockAcquisitionTimeout setting PLUS the longest possible delay which can be GC or application processing time

      Description

      If entries are locked, no matter whether it was done by FORCE_WRITE_LOCK flag or getAdvancedCache().lock(key), and the lock is hold longer than the current Tx timeout setting (.completedTxTimeout(...) ) the transacaction might be removed

      • if the node is blocked and expelled from the cluster (and join back later)
      • the thread processing the lock will take longer than the Tx-timeout setting

      This force to remove the Tx and free the lock.
      An indicator is the Exception below which will be shown if the Tx is timing out, it is not a (remote) access timout.
      If the originator is back after this this (ongoing) Tx is assumed new and it will continue by accident without lock.

      This can cause unexpected inconsistency!

      ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (EJB timer - 13) ISPN000136: Error executing command LockControlCommand, writing keys []: org.infinispan.util.concurrent.TimeoutException: Replication timeout for lt-33828
      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.checkRsp(JGroupsTransport.java:803)
      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.lambda$invokeRemotelyAsync$1(JGroupsTransport.java:641)
      at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602)
      at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577)
      at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)
      at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962)
      at org.infinispan.remoting.transport.jgroups.RspListFuture.call(RspListFuture.java:47)
      at org.infinispan.remoting.transport.jgroups.RspListFuture.call(RspListFuture.java:16)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)

      ERROR [org.jboss.as.ejb3.timer] (EJB timer - 13) WFLYEJB0020: Error invoking timeout for timer: [id=8a53d2c3-190d-4c74-9327-8e7554e1df2c timedObjectId=embeddedStressTest-ejb.embeddedStressTest-ejb.CacheAccessSingletonBean auto-timer?:false persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@72c41b07 initialExpiration=Fri Jun 28 10:56:16 CEST 2019 intervalDuration(in milli sec)=1 nextExpiration=Fri Jun 28 10:56:43 CEST 2019 timerState=IN_TIMEOUT info=org.infinispan.wfink.stress.TimerInfo@47ae2053]: javax.ejb.EJBException: org.infinispan.util.concurrent.TimeoutException: Replication timeout for lt-33828
      at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:246)
      at org.jboss.as.ejb3.tx.CMTTxInterceptor.requiresNew(CMTTxInterceptor.java:388)
      at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:146)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
      at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81)
      at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
      at org.jboss.as.ejb3.component.singleton.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:106)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
      at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
      at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
      at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:99)
      at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:109)
      at org.jboss.as.ejb3.timerservice.TimerTask.invokeBeanMethod(TimerTask.java:189)
      at org.jboss.as.ejb3.timerservice.TimerTask.callTimeout(TimerTask.java:185)
      at org.jboss.as.ejb3.timerservice.TimerTask.run(TimerTask.java:159)
      at org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1304)
      at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:494)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)
      at org.jboss.threads.JBossThread.run(JBossThread.java:485)
      Caused by: org.infinispan.util.concurrent.TimeoutException: Replication timeout for lt-33828
      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.checkRsp(JGroupsTransport.java:803)
      at org.infinispan.remoting.transport.jgroups.JGroupsTransport.lambda$invokeRemotelyAsync$1(JGroupsTransport.java:641)
      at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602)
      at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577)
      at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)
      at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962)
      at org.infinispan.remoting.transport.jgroups.RspListFuture.call(RspListFuture.java:47)
      at org.infinispan.remoting.transport.jgroups.RspListFuture.call(RspListFuture.java:16)
      at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
      at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)

        Gliffy Diagrams

          Attachments

            Issue Links

              Activity

                People

                • Assignee:
                  pruivo Pedro Ruivo
                  Reporter:
                  wdfink Wolf-Dieter Fink
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  4 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved: