Leaving cluster member causes a lock to leak
anujshahwork Nov 18, 2013 11:45 AMHi,
I've encountered a problem when using replication, pessimistic locking, transactions and a having a node leave the cluster. This is on Infinispan 5.2.6.
If one node is in a transaction involving a put command and another node leaves we get the following stack:
2013-11-13 15:00:04,528 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (http-0.0.0.0-8080-26) ISPN000136: Execution error
org.infinispan.remoting.transport.jgroups.SuspectException: One or more nodes have left the cluster while replicating command TxCompletionNotificationCommand{ xid=null, internalId=0, topologyId=10, gtx=DldGlobalTransaction{coinToss=-5785
937396295240934, lockIntention=null, affectedKeys=[key1], locksAtOrigin=[]} GlobalTransaction:<member1>:256968:local, cacheName=cache}
at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:482)
at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:169)
at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:190)
at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:247)
at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:234)
at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:229)
at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.releaseLocksOnFailureBeforePrepare(PessimisticLockingInterceptor.java:299)
at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitPutKeyValueCommand(PessimisticLockingInterceptor.java:128)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:255)
at org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:191)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:211)
at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:194)
at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:136)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128)
at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92)
at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343)
at org.infinispan.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1186)
at org.infinispan.CacheImpl.putInternal(CacheImpl.java:783)
at org.infinispan.CacheImpl.put(CacheImpl.java:777)
Note the following to files:
at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.releaseLocksOnFailureBeforePrepare(PessimisticLockingInterceptor.java:299)
at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitPutKeyValueCommand(PessimisticLockingInterceptor.java:128)
This is actually hiding another exception that has occurred, probably for a similar reason, and the release lock command has not been sent
After this event whenever we try to interact with the same key we get a timeout.
2013-11-13 15:00:39,752 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (http-0.0.0.0-8080-16) ISPN000136: Execution error
org.infinispan.util.concurrent.TimeoutException: Replication timeout for member2
at org.infinispan.remoting.transport.AbstractTransport.parseResponseAndAddToResponseList(AbstractTransport.java:113)
at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:541)
at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:169)
at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:190)
at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:247)
at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:234)
at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:229)
at org.infinispan.remoting.rpc.RpcManagerImpl.broadcastRpcCommand(RpcManagerImpl.java:208)
at org.infinispan.interceptors.ReplicationInterceptor.visitLockControlCommand(ReplicationInterceptor.java:150)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.DeadlockDetectingInterceptor.handleDataCommand(DeadlockDetectingInterceptor.java:116)
at org.infinispan.interceptors.DeadlockDetectingInterceptor.visitLockControlCommand(DeadlockDetectingInterceptor.java:98)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:177)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:177)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:177)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.acquireRemoteIfNeeded(PessimisticLockingInterceptor.java:287)
at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitPutKeyValueCommand(PessimisticLockingInterceptor.java:118)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:255)
at org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:191)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:211)
at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:194)
at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:136)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128)
at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92)
at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:80)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343)
at org.infinispan.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1186)
at org.infinispan.CacheImpl.putInternal(CacheImpl.java:783)
at org.infinispan.CacheImpl.put(CacheImpl.java:777)
And on the remote side:
2013-11-13 15:00:44,774 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (OOB-59,member2) ISPN000136: Execution error
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [20 seconds] on key [key1] for requestor [DldGlobalTransaction{coinToss=-4953942596828894095, lockIntention=key1, affectedKeys=[], locksAtOrigin=[]} GlobalTransaction:<member1>:257722:remote]! Lock held by [DldGlobalTransaction{coinToss=-5785937396295240934, lockIntention=null, affectedKeys=[], locksAtOrigin=[]} GlobalTransaction:<member1>:256968:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:213)
at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:186)
at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:187)
at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:124)
at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitLockControlCommand(PessimisticLockingInterceptor.java:250)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:177)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:128)
at org.infinispan.interceptors.TxInterceptor.visitLockControlCommand(TxInterceptor.java:186)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:177)
at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitLockControlCommand(TransactionSynchronizerInterceptor.java:94)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:216)
at org.infinispan.statetransfer.StateTransferInterceptor.handleTxCommand(StateTransferInterceptor.java:189)
at org.infinispan.statetransfer.StateTransferInterceptor.visitLockControlCommand(StateTransferInterceptor.java:131)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128)
at org.infinispan.interceptors.InvocationContextInterceptor.visitLockControlCommand(InvocationContextInterceptor.java:97)
at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:131)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343)
at org.infinispan.commands.control.LockControlCommand.perform(LockControlCommand.java:150)
at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:101)
at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:122)
at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:86)
at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommandFromLocalCluster(CommandAwareRpcDispatcher.java:247)
at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:220)
This is an eerily similar situation to a thread from a few years ago:
Re: SuspectException handling.
Am I right in thinking this is related to [ISPN-2577] Silence SuspectExceptions - JBoss Issue Tracker ?
Any ideas on a work around?
Or failing that we can create our own patch. A simple idea is to have the transaction completion command (when releasing the locks) be in ignore leavers mode.