0 Replies Latest reply on Nov 18, 2013 11:45 AM by anujshahwork

    Leaving cluster member causes a lock to leak

    anujshahwork

      Hi,

       

      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.