Possible loss of (pessimistic) lock if a transaction will reach timeout and/or is removed ----------------------------------------------------------------------------------------- Key: ISPN-10367 URL: https://issues.jboss.org/browse/ISPN-10367 Project: Infinispan Issue Type: Bug Components: Transactions Affects Versions: 10.0.0.Beta3, 9.4.15.Final Environment: Infinispan with pessimistic locking enabled Reporter: Wolf-Dieter Fink Assignee: Pedro Ruivo Priority: Critical Attachments: StressApp.zip 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)