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

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Critical
    • 10.1.0.Final
    • 10.0.0.Beta3, 9.4.15.Final
    • Transactions
    • None
    • DataGrid Sprint #33, DataGrid Sprint #34, DataGrid Sprint #35, DataGrid Sprint #36, DataGrid Sprint #37, DataGrid Sprint #38
    • Hide

      See attached reproducer and README

      Show
      See attached reproducer and README
    • 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)

      Attachments

        Issue Links

          Activity

            People

              pruivo@redhat.com Pedro Ruivo
              rhn-support-wfink Wolf Fink
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: