Created attachment 1198123 [details] testing deployment Description of problem: Configure an EAP cluster with an invalidation cache + a shared cache store (e.g. a remote JDG cluster or a shared file store). Deploy a distributable web app and enable web session passivation in jboss-web.xml. Then send an HTTP request to a non-coordinator node of the cluster. The node will log a bunch of remote exceptions during invalidation processing. The remote exceptions are "TimeoutException: Unable to acquire lock". Version-Release number of selected component (if applicable): EAP 6.4.8 How reproducible: Always Steps to Reproduce: 1. unzip jboss-eap-6.4.0.zip 2. ./jboss-eap-6.4/bin/jboss-cli.sh --command="patch apply jboss-eap-6.4.8-patch.zip" 3. ./jboss-eap-6.4/bin/standalone.sh -c standalone-ha.xml 4. ./jboss-eap-6.4/bin/jboss-cli.sh -c /subsystem=infinispan/cache-container=web/invalidation-cache=offload:add(mode=SYNC, batching=true) /subsystem=infinispan/cache-container=web/invalidation-cache=offload/file-store=FILE_STORE:add(path=/tmp/eap-shared-cache-store, shared=true, preload=false, purge=false, passivation=false) shutdown 5. cp tinyClusteredWebapp.war jboss-eap-6.4/standalone/deployments/ # attached 6. mv jboss-eap-6.4/ jboss-eap-6.4-node1 7. cp -a jboss-eap-6.4-node1 jboss-eap-6.4-node2 8. ./jboss-eap-6.4-node1/bin/standalone.sh -c standalone-ha.xml -Djboss.node.name=node1 9. ./jboss-eap-6.4-node2/bin/standalone.sh -c standalone-ha.xml -Djboss.node.name=node2 -Djboss.socket.binding.port-offset=100 10. curl -v http://localhost:8180/tinyClusteredWebapp/ Actual results: Exceptions logged on both cluster nodes. The request takes a lot of time to process, waiting for timeout. Expected results: No exceptions logged. No timeouts. Additional info: This is specific to EAP 6. Upstream / EAP 7 has a completely different web session clustering implementation.
I was asked to provide a stack trace. Here are the relevant parts of the logs: ----- on the coordinator ----- 15:41:22,899 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (OOB-19,shared=udp) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [ahHlOUxiY79VGB0ND2cisa6x] for requestor [Thread[OOB-19,shared=udp,5,ServerService ThreadGroup]]! Lock held by [GlobalTransaction:<node2/web>:1:remote] at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213) at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitInvalidateCommand(AbstractLockingInterceptor.java:66) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:255) at org.infinispan.interceptors.TxInterceptor.visitInvalidateCommand(TxInterceptor.java:221) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61) at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:70) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:100) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:121) at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:85) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220) at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484) at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391) at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249) at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:600) at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) at org.jgroups.JChannel.up(JChannel.java:707) at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1025) at org.jgroups.protocols.RSVP.up(RSVP.java:188) at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) at org.jgroups.protocols.FlowControl.up(FlowControl.java:400) at org.jgroups.protocols.pbcast.GMS.up(GMS.java:896) at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245) at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:766) at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420) at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:645) at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:147) at org.jgroups.protocols.FD.up(FD.java:253) at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) at org.jgroups.protocols.MERGE3.up(MERGE3.java:290) at org.jgroups.protocols.Discovery.up(Discovery.java:359) at org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2607) at org.jgroups.protocols.TP.passMessageUp(TP.java:1260) at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1822) at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1795) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_101] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_101] at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_101] 15:41:22,904 ERROR [org.infinispan.remoting.InboundInvocationHandlerImpl] (OOB-19,shared=udp) Exception executing command: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [ahHlOUxiY79VGB0ND2cisa6x] for requestor [Thread[OOB-19,shared=udp,5,ServerService ThreadGroup]]! Lock held by [GlobalTransaction:<node2/web>:1:remote] at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213) at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitInvalidateCommand(AbstractLockingInterceptor.java:66) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:255) at org.infinispan.interceptors.TxInterceptor.visitInvalidateCommand(TxInterceptor.java:221) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61) at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:70) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:100) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:121) at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:85) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220) at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484) at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391) at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249) at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:600) at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) at org.jgroups.JChannel.up(JChannel.java:707) at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1025) at org.jgroups.protocols.RSVP.up(RSVP.java:188) at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) at org.jgroups.protocols.FlowControl.up(FlowControl.java:400) at org.jgroups.protocols.pbcast.GMS.up(GMS.java:896) at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245) at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:766) at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420) at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:645) at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:147) at org.jgroups.protocols.FD.up(FD.java:253) at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) at org.jgroups.protocols.MERGE3.up(MERGE3.java:290) at org.jgroups.protocols.Discovery.up(Discovery.java:359) at org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2607) at org.jgroups.protocols.TP.passMessageUp(TP.java:1260) at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1822) at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1795) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_101] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_101] at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_101] ----- on the non-coordinator node that received the request ----- 15:41:22,918 WARN [org.infinispan.interceptors.InvalidationInterceptor] (http-127.0.0.1:8180-1) Unable to broadcast evicts as a part of the prepare phase. Rolling back.: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from node1/web, see cause for remote stack trace at org.infinispan.remoting.transport.AbstractTransport.checkResponse(AbstractTransport.java:60) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.processSingleCall(CommandAwareRpcDispatcher.java:310) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommand(CommandAwareRpcDispatcher.java:179) at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:515) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:173) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:194) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:251) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:238) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:233) at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:212) at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:204) at org.infinispan.interceptors.InvalidationInterceptor.invalidateAcrossCluster(InvalidationInterceptor.java:283) at org.infinispan.interceptors.InvalidationInterceptor.broadcastInvalidateForPrepare(InvalidationInterceptor.java:211) at org.infinispan.interceptors.InvalidationInterceptor.visitPrepareCommand(InvalidationInterceptor.java:145) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.CacheStoreInterceptor.visitPrepareCommand(CacheStoreInterceptor.java:208) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.EntryWrappingInterceptor.visitPrepareCommand(EntryWrappingInterceptor.java:111) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.invokeNextAndCommitIf1Pc(AbstractTxLockingInterceptor.java:109) at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitPrepareCommand(PessimisticLockingInterceptor.java:106) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:128) at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:115) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.transaction.TransactionCoordinator.commit(TransactionCoordinator.java:175) at org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:81) at org.infinispan.transaction.tm.DummyTransaction.notifyAfterCompletion(DummyTransaction.java:285) at org.infinispan.transaction.tm.DummyTransaction.runCommitTx(DummyTransaction.java:334) at org.infinispan.transaction.tm.DummyTransaction.commit(DummyTransaction.java:91) at org.infinispan.transaction.tm.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:102) at org.jboss.as.clustering.web.impl.TransactionBatchingManager.endBatch(TransactionBatchingManager.java:75) at org.jboss.as.web.session.DistributableSessionManager.processSessionRepl(DistributableSessionManager.java:1574) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.DistributableSessionManager.storeSession(DistributableSessionManager.java:872) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.InstantSnapshotManager.snapshot(InstantSnapshotManager.java:47) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.ClusteredSessionValve.handleRequest(ClusteredSessionValve.java:142) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:99) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.JvmRouteValve.invoke(JvmRouteValve.java:92) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.LockingValve.invoke(LockingValve.java:64) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:654) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_101] Caused by: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [ahHlOUxiY79VGB0ND2cisa6x] for requestor [Thread[OOB-19,shared=udp,5,ServerService ThreadGroup]]! Lock held by [GlobalTransaction:<node2/web>:1:remote] at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213) at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitInvalidateCommand(AbstractLockingInterceptor.java:66) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:255) at org.infinispan.interceptors.TxInterceptor.visitInvalidateCommand(TxInterceptor.java:221) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61) at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:70) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:100) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:121) at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:85) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220) at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484) at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391) at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249) at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:600) at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) at org.jgroups.JChannel.up(JChannel.java:707) at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1025) at org.jgroups.protocols.RSVP.up(RSVP.java:188) at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) at org.jgroups.protocols.FlowControl.up(FlowControl.java:400) at org.jgroups.protocols.pbcast.GMS.up(GMS.java:896) at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245) at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:766) at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420) at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:645) at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:147) at org.jgroups.protocols.FD.up(FD.java:253) at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) at org.jgroups.protocols.MERGE3.up(MERGE3.java:290) at org.jgroups.protocols.Discovery.up(Discovery.java:359) at org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2607) at org.jgroups.protocols.TP.passMessageUp(TP.java:1260) at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1822) at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1795) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_101] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_101] ... 1 more 15:41:22,927 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (http-127.0.0.1:8180-1) ISPN000136: Execution error: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from node1/web, see cause for remote stack trace at org.infinispan.remoting.transport.AbstractTransport.checkResponse(AbstractTransport.java:60) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.processSingleCall(CommandAwareRpcDispatcher.java:310) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommand(CommandAwareRpcDispatcher.java:179) at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:515) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:173) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:194) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:251) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:238) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:233) at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:212) at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:204) at org.infinispan.interceptors.InvalidationInterceptor.invalidateAcrossCluster(InvalidationInterceptor.java:283) at org.infinispan.interceptors.InvalidationInterceptor.broadcastInvalidateForPrepare(InvalidationInterceptor.java:211) at org.infinispan.interceptors.InvalidationInterceptor.visitPrepareCommand(InvalidationInterceptor.java:145) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.CacheStoreInterceptor.visitPrepareCommand(CacheStoreInterceptor.java:208) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.EntryWrappingInterceptor.visitPrepareCommand(EntryWrappingInterceptor.java:111) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.invokeNextAndCommitIf1Pc(AbstractTxLockingInterceptor.java:109) at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitPrepareCommand(PessimisticLockingInterceptor.java:106) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:128) at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:115) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.transaction.TransactionCoordinator.commit(TransactionCoordinator.java:175) at org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:81) at org.infinispan.transaction.tm.DummyTransaction.notifyAfterCompletion(DummyTransaction.java:285) at org.infinispan.transaction.tm.DummyTransaction.runCommitTx(DummyTransaction.java:334) at org.infinispan.transaction.tm.DummyTransaction.commit(DummyTransaction.java:91) at org.infinispan.transaction.tm.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:102) at org.jboss.as.clustering.web.impl.TransactionBatchingManager.endBatch(TransactionBatchingManager.java:75) at org.jboss.as.web.session.DistributableSessionManager.processSessionRepl(DistributableSessionManager.java:1574) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.DistributableSessionManager.storeSession(DistributableSessionManager.java:872) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.InstantSnapshotManager.snapshot(InstantSnapshotManager.java:47) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.ClusteredSessionValve.handleRequest(ClusteredSessionValve.java:142) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:99) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.JvmRouteValve.invoke(JvmRouteValve.java:92) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.LockingValve.invoke(LockingValve.java:64) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:654) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_101] Caused by: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [ahHlOUxiY79VGB0ND2cisa6x] for requestor [Thread[OOB-19,shared=udp,5,ServerService ThreadGroup]]! Lock held by [GlobalTransaction:<node2/web>:1:remote] at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213) at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitInvalidateCommand(AbstractLockingInterceptor.java:66) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:255) at org.infinispan.interceptors.TxInterceptor.visitInvalidateCommand(TxInterceptor.java:221) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61) at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:70) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:100) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:121) at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:85) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220) at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484) at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391) at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249) at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:600) at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) at org.jgroups.JChannel.up(JChannel.java:707) at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1025) at org.jgroups.protocols.RSVP.up(RSVP.java:188) at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) at org.jgroups.protocols.FlowControl.up(FlowControl.java:400) at org.jgroups.protocols.pbcast.GMS.up(GMS.java:896) at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245) at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:766) at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420) at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:645) at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:147) at org.jgroups.protocols.FD.up(FD.java:253) at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) at org.jgroups.protocols.MERGE3.up(MERGE3.java:290) at org.jgroups.protocols.Discovery.up(Discovery.java:359) at org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2607) at org.jgroups.protocols.TP.passMessageUp(TP.java:1260) at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1822) at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1795) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_101] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_101] ... 1 more 15:41:22,934 ERROR [org.infinispan.transaction.TransactionCoordinator] (http-127.0.0.1:8180-1) ISPN000097: Error while processing a prepare in a single-phase transaction: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from node1/web, see cause for remote stack trace at org.infinispan.remoting.transport.AbstractTransport.checkResponse(AbstractTransport.java:60) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.processSingleCall(CommandAwareRpcDispatcher.java:310) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommand(CommandAwareRpcDispatcher.java:179) at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:515) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:173) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:194) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:251) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:238) at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:233) at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:212) at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:204) at org.infinispan.interceptors.InvalidationInterceptor.invalidateAcrossCluster(InvalidationInterceptor.java:283) at org.infinispan.interceptors.InvalidationInterceptor.broadcastInvalidateForPrepare(InvalidationInterceptor.java:211) at org.infinispan.interceptors.InvalidationInterceptor.visitPrepareCommand(InvalidationInterceptor.java:145) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.CacheStoreInterceptor.visitPrepareCommand(CacheStoreInterceptor.java:208) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.EntryWrappingInterceptor.visitPrepareCommand(EntryWrappingInterceptor.java:111) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.invokeNextAndCommitIf1Pc(AbstractTxLockingInterceptor.java:109) at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitPrepareCommand(PessimisticLockingInterceptor.java:106) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:128) at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:115) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126) at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:124) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.transaction.TransactionCoordinator.commit(TransactionCoordinator.java:175) at org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:81) at org.infinispan.transaction.tm.DummyTransaction.notifyAfterCompletion(DummyTransaction.java:285) at org.infinispan.transaction.tm.DummyTransaction.runCommitTx(DummyTransaction.java:334) at org.infinispan.transaction.tm.DummyTransaction.commit(DummyTransaction.java:91) at org.infinispan.transaction.tm.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:102) at org.jboss.as.clustering.web.impl.TransactionBatchingManager.endBatch(TransactionBatchingManager.java:75) at org.jboss.as.web.session.DistributableSessionManager.processSessionRepl(DistributableSessionManager.java:1574) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.DistributableSessionManager.storeSession(DistributableSessionManager.java:872) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.InstantSnapshotManager.snapshot(InstantSnapshotManager.java:47) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.ClusteredSessionValve.handleRequest(ClusteredSessionValve.java:142) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:99) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.JvmRouteValve.invoke(JvmRouteValve.java:92) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.LockingValve.invoke(LockingValve.java:64) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:654) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_101] Caused by: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds] on key [ahHlOUxiY79VGB0ND2cisa6x] for requestor [Thread[OOB-19,shared=udp,5,ServerService ThreadGroup]]! Lock held by [GlobalTransaction:<node2/web>:1:remote] at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213) at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitInvalidateCommand(AbstractLockingInterceptor.java:66) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:255) at org.infinispan.interceptors.TxInterceptor.visitInvalidateCommand(TxInterceptor.java:221) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76) at org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) at org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61) at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:70) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:100) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:121) at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:85) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247) at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220) at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484) at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391) at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249) at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:600) at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) at org.jgroups.JChannel.up(JChannel.java:707) at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1025) at org.jgroups.protocols.RSVP.up(RSVP.java:188) at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) at org.jgroups.protocols.FlowControl.up(FlowControl.java:400) at org.jgroups.protocols.pbcast.GMS.up(GMS.java:896) at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245) at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:766) at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420) at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:645) at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:147) at org.jgroups.protocols.FD.up(FD.java:253) at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) at org.jgroups.protocols.MERGE3.up(MERGE3.java:290) at org.jgroups.protocols.Discovery.up(Discovery.java:359) at org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2607) at org.jgroups.protocols.TP.passMessageUp(TP.java:1260) at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1822) at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1795) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_101] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_101] ... 1 more 15:41:22,940 ERROR [org.infinispan.transaction.tm.DummyTransaction] (http-127.0.0.1:8180-1) ISPN000111: afterCompletion() failed for SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=[node1/web, node2/web], isMarkedForRollback=false, lockedKeys=null, backupKeyLocks=[ahHlOUxiY79VGB0ND2cisa6x], topologyId=2, isFromStateTransfer=false} org.infinispan.transaction.synchronization.SyncLocalTransaction@1} org.infinispan.transaction.synchronization.SynchronizationAdapter@20: org.infinispan.CacheException: Could not commit. at org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:83) at org.infinispan.transaction.tm.DummyTransaction.notifyAfterCompletion(DummyTransaction.java:285) at org.infinispan.transaction.tm.DummyTransaction.runCommitTx(DummyTransaction.java:334) at org.infinispan.transaction.tm.DummyTransaction.commit(DummyTransaction.java:91) at org.infinispan.transaction.tm.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:102) at org.jboss.as.clustering.web.impl.TransactionBatchingManager.endBatch(TransactionBatchingManager.java:75) at org.jboss.as.web.session.DistributableSessionManager.processSessionRepl(DistributableSessionManager.java:1574) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.DistributableSessionManager.storeSession(DistributableSessionManager.java:872) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.InstantSnapshotManager.snapshot(InstantSnapshotManager.java:47) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.ClusteredSessionValve.handleRequest(ClusteredSessionValve.java:142) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:99) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.JvmRouteValve.invoke(JvmRouteValve.java:92) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.session.LockingValve.invoke(LockingValve.java:64) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169) [jboss-as-web-7.5.8.Final-redhat-2.jar:7.5.8.Final-redhat-2] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:654) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926) [jbossweb-7.5.16.Final-redhat-1.jar:7.5.16.Final-redhat-1] at java.lang.Thread.run(Thread.java:745) [rt.jar:1.8.0_101] Caused by: javax.transaction.xa.XAException at org.infinispan.transaction.TransactionCoordinator.handleCommitFailure(TransactionCoordinator.java:224) at org.infinispan.transaction.TransactionCoordinator.commit(TransactionCoordinator.java:177) at org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:81) ... 21 more
https://github.com/jbossas/jboss-eap/pull/2837
Amended commit: https://github.com/jbossas/jboss-eap/pull/2838
I built EAP 6.4.8 with the patch from PR 2838 and it didn't help, the stack traces are still the same. Looking at the proposed fix, it looks like it prevents the request-handling node from locking the key during session eviction. However, the problem here happens during session creation. I used these Byteman rules: RULE Infinispan acquiring lock CLASS org.infinispan.util.concurrent.locks.LockManagerImpl METHOD lock AT ENTRY IF true DO traceStack("!!!!!!!!!!!!!!!!!!! acquiring lock for key " + $2 + "\n", 100) ENDRULE RULE Infinispan acquired lock CLASS org.infinispan.util.concurrent.locks.LockManagerImpl METHOD lock AT EXIT IF true DO traceln("!!!!!!!!!!!!!!!!!!! acquired lock for key " + $2) ENDRULE RULE Infinispan failed to acquire lock CLASS org.infinispan.util.concurrent.locks.LockManagerImpl METHOD lock AT EXCEPTION EXIT IF true DO traceln("!!!!!!!!!!!!!!!!!!! failed to acquired lock for key " + $2) ENDRULE Here are the logs from these Byteman rules: ----- on the coordinator ----- 10:23:27,708 INFO [stdout] (OOB-20,shared=udp) Rule.execute called for Infinispan acquiring lock_0 10:23:27,710 INFO [stdout] (OOB-20,shared=udp) HelperManager.install for helper class org.jboss.byteman.rule.helper.Helper 10:23:27,711 INFO [stdout] (OOB-20,shared=udp) calling activated() for helper class org.jboss.byteman.rule.helper.Helper 10:23:27,711 INFO [stdout] (OOB-20,shared=udp) Default helper activated 10:23:27,711 INFO [stdout] (OOB-20,shared=udp) calling installed(Infinispan acquiring lock) for helper classorg.jboss.byteman.rule.helper.Helper 10:23:27,711 INFO [stdout] (OOB-20,shared=udp) Installed rule using default helper : Infinispan acquiring lock 10:23:27,711 INFO [stdout] (OOB-20,shared=udp) Infinispan acquiring lock execute() 10:23:27,712 INFO [stdout] (OOB-20,shared=udp) !!!!!!!!!!!!!!!!!!! acquiring lock for key B5Daw4KVa+smEQ-vOqOuioI8 10:23:27,712 INFO [stdout] (OOB-20,shared=udp) org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:-1) 10:23:27,712 INFO [stdout] (OOB-20,shared=udp) org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:186) 10:23:27,712 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:192) 10:23:27,712 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:129) 10:23:27,712 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitLockControlCommand(PessimisticLockingInterceptor.java:253) 10:23:27,712 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131) 10:23:27,712 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:177) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:128) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.TxInterceptor.visitLockControlCommand(TxInterceptor.java:186) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.InvocationContextInterceptor.visitLockControlCommand(InvocationContextInterceptor.java:97) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:177) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.control.LockControlCommand.perform(LockControlCommand.java:150) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:100) 10:23:27,713 INFO [stdout] (OOB-20,shared=udp) org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:121) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:85) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:600) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.JChannel.up(JChannel.java:707) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1025) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.RSVP.up(RSVP.java:188) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.FRAG2.up(FRAG2.java:181) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.FlowControl.up(FlowControl.java:418) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.FlowControl.up(FlowControl.java:400) 10:23:27,714 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.pbcast.GMS.up(GMS.java:896) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:766) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:645) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:147) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.FD.up(FD.java:253) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.MERGE3.up(MERGE3.java:290) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.Discovery.up(Discovery.java:359) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2607) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.TP.passMessageUp(TP.java:1260) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1822) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1795) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 10:23:27,715 INFO [stdout] (OOB-20,shared=udp) java.lang.Thread.run(Thread.java:745) 10:23:27,717 INFO [stdout] (OOB-20,shared=udp) Rule.execute called for Infinispan acquired lock_2 10:23:27,717 INFO [stdout] (OOB-20,shared=udp) HelperManager.install for helper class org.jboss.byteman.rule.helper.Helper 10:23:27,717 INFO [stdout] (OOB-20,shared=udp) calling installed(Infinispan acquired lock) for helper classorg.jboss.byteman.rule.helper.Helper 10:23:27,717 INFO [stdout] (OOB-20,shared=udp) Installed rule using default helper : Infinispan acquired lock 10:23:27,718 INFO [stdout] (OOB-20,shared=udp) Infinispan acquired lock execute() 10:23:27,718 INFO [stdout] (OOB-20,shared=udp) !!!!!!!!!!!!!!!!!!! acquired lock for key B5Daw4KVa+smEQ-vOqOuioI8 10:23:27,764 INFO [stdout] (OOB-20,shared=udp) Rule.execute called for Infinispan acquiring lock_0 10:23:27,764 INFO [stdout] (OOB-20,shared=udp) Infinispan acquiring lock execute() 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) !!!!!!!!!!!!!!!!!!! acquiring lock for key B5Daw4KVa+smEQ-vOqOuioI8 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:-1) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLockNoCheck(LockManagerImpl.java:196) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockKey(AbstractLockingInterceptor.java:114) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitInvalidateCommand(AbstractLockingInterceptor.java:66) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:255) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.TxInterceptor.visitInvalidateCommand(TxInterceptor.java:221) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,765 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.AbstractVisitor.visitInvalidateCommand(AbstractVisitor.java:141) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.write.InvalidateCommand.acceptVisitor(InvalidateCommand.java:136) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:70) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:100) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:121) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:85) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247) 10:23:27,766 INFO [stdout] (OOB-20,shared=udp) org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:484) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:391) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:249) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:600) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.JChannel.up(JChannel.java:707) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1025) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.RSVP.up(RSVP.java:188) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.FRAG2.up(FRAG2.java:181) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.FlowControl.up(FlowControl.java:418) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.FlowControl.up(FlowControl.java:400) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.pbcast.GMS.up(GMS.java:896) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:245) 10:23:27,767 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:766) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.UNICAST2.up(UNICAST2.java:420) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:645) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:147) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.FD.up(FD.java:253) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.MERGE3.up(MERGE3.java:290) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.Discovery.up(Discovery.java:359) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2607) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.TP.passMessageUp(TP.java:1260) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1822) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1795) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 10:23:27,768 INFO [stdout] (OOB-20,shared=udp) java.lang.Thread.run(Thread.java:745) 10:23:42,771 INFO [stdout] (OOB-20,shared=udp) Rule.execute called for Infinispan failed to acquire lock_4 10:23:42,774 INFO [stdout] (OOB-20,shared=udp) HelperManager.install for helper class org.jboss.byteman.rule.helper.Helper 10:23:42,774 INFO [stdout] (OOB-20,shared=udp) calling installed(Infinispan failed to acquire lock) for helper classorg.jboss.byteman.rule.helper.Helper 10:23:42,775 INFO [stdout] (OOB-20,shared=udp) Installed rule using default helper : Infinispan failed to acquire lock 10:23:42,776 INFO [stdout] (OOB-20,shared=udp) Infinispan failed to acquire lock execute() 10:23:42,776 INFO [stdout] (OOB-20,shared=udp) !!!!!!!!!!!!!!!!!!! failed to acquired lock for key B5Daw4KVa+smEQ-vOqOuioI8 ----- on the non-coordinator node that received the request ----- 10:23:27,721 INFO [stdout] (http-127.0.0.1:8180-1) Rule.execute called for Infinispan acquiring lock_0 10:23:27,724 INFO [stdout] (http-127.0.0.1:8180-1) HelperManager.install for helper class org.jboss.byteman.rule.helper.Helper 10:23:27,724 INFO [stdout] (http-127.0.0.1:8180-1) calling activated() for helper class org.jboss.byteman.rule.helper.Helper 10:23:27,724 INFO [stdout] (http-127.0.0.1:8180-1) Default helper activated 10:23:27,724 INFO [stdout] (http-127.0.0.1:8180-1) calling installed(Infinispan acquiring lock) for helper classorg.jboss.byteman.rule.helper.Helper 10:23:27,725 INFO [stdout] (http-127.0.0.1:8180-1) Installed rule using default helper : Infinispan acquiring lock 10:23:27,725 INFO [stdout] (http-127.0.0.1:8180-1) Infinispan acquiring lock execute() 10:23:27,725 INFO [stdout] (http-127.0.0.1:8180-1) !!!!!!!!!!!!!!!!!!! acquiring lock for key B5Daw4KVa+smEQ-vOqOuioI8 10:23:27,725 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:-1) 10:23:27,725 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:186) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:192) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitGetKeyValueCommand(PessimisticLockingInterceptor.java:93) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:104) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:231) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:226) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) 10:23:27,726 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:104) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:92) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:104) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.CacheImpl.get(CacheImpl.java:289) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.DecoratedCache.get(DecoratedCache.java:315) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.AbstractDelegatingCache.get(AbstractDelegatingCache.java:303) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.atomic.AtomicHashMapProxy.getDeltaMapForWrite(AtomicHashMapProxy.java:133) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.infinispan.atomic.AtomicHashMapProxy.put(AtomicHashMapProxy.java:207) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.clustering.web.infinispan.SessionMapEntry.put(SessionMapEntry.java:70) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.clustering.web.infinispan.DistributedCacheManager$1.invoke(DistributedCacheManager.java:173) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.clustering.web.infinispan.DistributedCacheManager$1.invoke(DistributedCacheManager.java:168) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.clustering.infinispan.invoker.SimpleCacheInvoker.invoke(SimpleCacheInvoker.java:34) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.clustering.infinispan.invoker.BatchCacheInvoker.invoke(BatchCacheInvoker.java:48) 10:23:27,727 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.clustering.infinispan.invoker.RetryingCacheInvoker.invoke(RetryingCacheInvoker.java:85) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.clustering.web.infinispan.DistributedCacheManager$ForceSynchronousCacheInvoker.invoke(DistributedCacheManager.java:552) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.clustering.web.infinispan.DistributedCacheManager.storeSessionData(DistributedCacheManager.java:185) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.web.session.ClusteredSession.processSessionReplication(ClusteredSession.java:1064) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.web.session.DistributableSessionManager.processSessionRepl(DistributableSessionManager.java:1556) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.web.session.DistributableSessionManager.storeSession(DistributableSessionManager.java:872) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.web.session.InstantSnapshotManager.snapshot(InstantSnapshotManager.java:47) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.web.session.ClusteredSessionValve.handleRequest(ClusteredSessionValve.java:142) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.web.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:99) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.web.session.JvmRouteValve.invoke(JvmRouteValve.java:92) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.web.session.LockingValve.invoke(LockingValve.java:64) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:150) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:854) 10:23:27,728 INFO [stdout] (http-127.0.0.1:8180-1) org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:654) 10:23:27,729 INFO [stdout] (http-127.0.0.1:8180-1) org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926) 10:23:27,729 INFO [stdout] (http-127.0.0.1:8180-1) java.lang.Thread.run(Thread.java:745) 10:23:27,730 INFO [stdout] (http-127.0.0.1:8180-1) Rule.execute called for Infinispan acquired lock_2 10:23:27,731 INFO [stdout] (http-127.0.0.1:8180-1) HelperManager.install for helper class org.jboss.byteman.rule.helper.Helper 10:23:27,731 INFO [stdout] (http-127.0.0.1:8180-1) calling installed(Infinispan acquired lock) for helper classorg.jboss.byteman.rule.helper.Helper 10:23:27,731 INFO [stdout] (http-127.0.0.1:8180-1) Installed rule using default helper : Infinispan acquired lock 10:23:27,732 INFO [stdout] (http-127.0.0.1:8180-1) Infinispan acquired lock execute() 10:23:27,732 INFO [stdout] (http-127.0.0.1:8180-1) !!!!!!!!!!!!!!!!!!! acquired lock for key B5Daw4KVa+smEQ-vOqOuioI8 I know I should probably add some rules to print unlocks as well, but even from this, it looks like 1. the coordinator locks the key successfully (LockControlCommand) 2. the request-handling node locks the key successfully (DistributableSessionManager.storeSession > DistributedCacheManager.storeSessionData > SessionMapEntry.put > GetKeyValueCommand) 3. the coordinator tries to lock the key again (InvalidateCommand), but fails
@lthon Question - the attached config does not appear to set a value for <max-active-sessions/>. Session creation only triggers pre-emptive passivation if there is a max-active-session value specified. Are we absolutely sure this isn't the case? In EAP6, you would never need to set a max-active-sessions if you have passivation enabled.
Paul, I'm using the exact application that is attached to this BZ. So yes, max-active-sessions is not set. I don't think that the problem is caused by pre-emptive passivation -- see the stack traces in comment 5. Looking at ClusteredSessionValve.handleRequest:142, I was obviously wrong about the problem happening during session creation, it's after the request was processed, when the session is stored to the cache.
Many thanks for detailed "Steps to Reproduce". Reopened because reproducer gets exception as well in 6.4.11.CP.CR1. From comment #5 was not provided new fix so it still does not work.
Verified with EAP 6.4.19.CP.CR1