[JBoss JIRA] (AS7-4813) Shutdown in REPL SYNC results in TimeoutException: Unable to acquire lock after
9:06 a.m.
Radoslav Husar created AS7-4813:
-----------------------------------
Summary: Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.1.3.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
9:10 a.m.
[
https://issues.jboss.org/browse/AS7-4813?page=com.atlassian.jira.plugin.s...
]
Radoslav Husar commented on AS7-4813:
-------------------------------------
Grepped out runner log
{noformat}./lastSuccessful/perf17.log:2012/05/14 11:40:37:421 EDT [DEBUG][Runner - 229]
HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Session assigned:
sgalNLPm8jvqZzLyQjwt4oZ3
./lastSuccessful/perf17.log:2012/05/14 11:40:37:421 EDT [DEBUG][Runner - 229] HOST
perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - JvmRoute assigned: perf19
./lastSuccessful/perf17.log:2012/05/14 11:45:31:021 EDT [INFO ][Runner - 229] HOST
perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Failover detected, JvmRoute changed.
perf19 -> perf18
./lastSuccessful/perf17.log:2012/05/14 11:49:22:377 EDT [INFO ][Runner - 229] HOST
perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Client state is reset.
./lastSuccessful/perf17.log:2012/05/14 11:49:22:377 EDT [WARN ][Runner - 229] HOST
perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error sampling data:
<org.jboss.smartfrog.loaddriver.RequestProcessingException: IO error:
java.net.SocketTimeoutException: Read timed out>
./lastSuccessful/perf17.log:2012/05/14 11:49:22:380 EDT [WARN ][Runner - 229] SFCORE_LOG -
Error sampling data: <org.jboss.smartfrog.loaddriver.RequestProcessingException: IO
error: java.net.SocketTimeoutException: Read timed out>
./lastSuccessful/perf17.log:2012/05/14 11:49:26:386 EDT [DEBUG][Runner - 229] HOST
perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Session changed:
MtMtLCc5A8QqZw1-dUeDLeYa
./lastSuccessful/perf17.log:2012/05/14 11:49:26:386 EDT [INFO ][Runner - 229] HOST
perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Failover detected, JvmRoute changed.
perf18 -> perf19
{noformat}
Session grepped on the servers:
{noformat}
./lastSuccessful/perf17.log:2012/05/14 11:40:37:421 EDT [DEBUG][Runner - 229] HOST
perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Session assigned:
sgalNLPm8jvqZzLyQjwt4oZ3
./lastSuccessful/perf21.log:[JBossINF] 11:46:54,106 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-1720,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf21.log:[JBossINF] 11:47:13,142 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-1878,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:4891:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf21.log:[JBossINF] 11:47:32,175 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-1953,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:5951:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf21.log:[JBossINF] 11:47:51,211 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-2090,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:7018:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf21.log:[JBossINF] 11:48:10,246 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-2182,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:8062:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf21.log:[JBossINF] 11:48:29,278 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-2252,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:9113:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf21.log:[JBossINF] 11:48:48,311 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-2333,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:10184:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf21.log:[JBossINF] 11:49:07,343 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-2375,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:11241:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf21.log:[JBossINF] 11:49:22,426 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-2447,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:11241:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,112 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-97) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,123 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-97) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,132 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-97)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=3842}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@f00}
org.infinispan.transaction.synchronization.SynchronizationAdapter@f1f:
org.infinispan.CacheException: Could not prepare.
./lastSuccessful/perf18.log:[JBossINF] 11:47:13,147 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-18) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:4891:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:47:13,157 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-18) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:4891:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:47:13,165 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-18)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=4893}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@131b}
org.infinispan.transaction.synchronization.SynchronizationAdapter@133a:
org.infinispan.CacheException: Could not prepare.
./lastSuccessful/perf18.log:[JBossINF] 11:47:32,183 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (ajp-perf18/10.16.90.54:8009-5)
ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:5951:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:47:32,193 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-5) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:5951:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:47:32,201 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-5)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=5953}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@173f}
org.infinispan.transaction.synchronization.SynchronizationAdapter@175e:
org.infinispan.CacheException: Could not prepare.
./lastSuccessful/perf18.log:[JBossINF] 11:47:51,218 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-69) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:7018:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:47:51,228 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-69) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:7018:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:47:51,236 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-69)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=7020}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@1b6a}
org.infinispan.transaction.synchronization.SynchronizationAdapter@1b89:
org.infinispan.CacheException: Could not prepare.
./lastSuccessful/perf18.log:[JBossINF] 11:48:10,250 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-13) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:8062:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:48:10,259 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-13) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:8062:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:48:10,268 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-13)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=8064}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@1f7e}
org.infinispan.transaction.synchronization.SynchronizationAdapter@1f9d:
org.infinispan.CacheException: Could not prepare.
./lastSuccessful/perf18.log:[JBossINF] 11:48:29,282 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-53) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:9113:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:48:29,292 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-53) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:9113:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:48:29,301 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-53)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=9115}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@2399}
org.infinispan.transaction.synchronization.SynchronizationAdapter@23b8:
org.infinispan.CacheException: Could not prepare.
./lastSuccessful/perf18.log:[JBossINF] 11:48:48,315 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-36) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:10184:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:48:48,325 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-36) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:10184:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:48:48,333 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-36)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=10186}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@27c8}
org.infinispan.transaction.synchronization.SynchronizationAdapter@27e7:
org.infinispan.CacheException: Could not prepare.
./lastSuccessful/perf18.log:[JBossINF] 11:49:22,448 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-76) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:11241:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:49:22,458 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-76) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:11241:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:49:22,467 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-76)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=11243}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@2be9}
org.infinispan.transaction.synchronization.SynchronizationAdapter@2c08:
org.infinispan.CacheException: Could not prepare.
./lastSuccessful/perf19.log:[JBossINF] 11:40:37,414 INFO
[org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet]
(ajp-perf19/10.16.90.56:8009-6) New session created: sgalNLPm8jvqZzLyQjwt4oZ3.perf19
{noformat}
Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
-------------------------------------------------------------------------------
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.1.3.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
1:45 p.m.
[
https://issues.jboss.org/browse/AS7-4813?page=com.atlassian.jira.plugin.s...
]
Richard Achmatowicz commented on AS7-4813:
------------------------------------------
A request is initiated by Runner 229 on perf17 which generates a session
sgalNLPm8jvqZzLyQjwt4oZ3 which gets assigned jvmRoute perf19. It uses perf19 to process
requests until perf19 fails and the jvmRoute is changed to perf18. The server logs show
activity at perf18 and perf21: the perf18 exceptions come in groups of three
{noformat}
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,112 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-97) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,123 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-97) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,132 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-97)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=3842}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@f00}
org.infinispan.transaction.synchronization.SynchronizationAdapter@f1f:
org.infinispan.CacheException: Could not prepare.
{noformat}
representing an incoming prepare request to the assigned slave; the perf21 exceptions
{noformat}
./lastSuccessful/perf21.log:[JBossINF] 11:46:54,106 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-1720,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
{noformat}
are the corresponding remote prepare commands which are sent to all hosts participating in
the prepare and which fail only on perf21. Those exceptions are then returned to perf18
and show up there.
These coupled pairs of exceptions occur every 19 (= 4 + 15) seconds where the client sends
out requests every 4 seconds regularly, and the timeout on waiting for the locks is 15
seconds. Each coupled pair of exceptions represents a different incoming retry request by
the client to do complete the HTTP request. These exceptions only arise after perf19 fails
and they disappear when perf19 comes back.
Is it possible that perf21 was a remote participant in a transaction initiated on perf19
(before failure) and perf19 (the coordinator for the prepare) was shutdown during the
prepare phase for a transaction involving the session in question. So perf21 ended up with
locks on the session which let's assume were never released, in a different cache
view. Then perf18 becomes the new jvmRoute for the session, and tries to prepare a
transaction using the same session id. When it coordinates its prepare phase, the remote
command goes out to perf21 which tries to take locks for that session locally and it times
out waiting for the locks.
The way locks are taken on remote nodes as in
AbstractLockingTxInterceptor.lockKeyAndCheckOwnership() is to:
- check if there any pending locks for that session id (i.e. locks on transactions from
previous cache views which are pending - have not completed)
- if there are pending locks, wait for them to complete
The exceptions in this issue are occurring when we try to wait for locks for pending
transactions (in earlier cache views) and we never get them time (in 15 seconds). So it
may be that there are stale entries in the transaction tables.
Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
-------------------------------------------------------------------------------
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.1.3.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
1:47 p.m.
[
https://issues.jboss.org/browse/AS7-4813?page=com.atlassian.jira.plugin.s...
]
Richard Achmatowicz edited comment on AS7-4813 at 5/15/12 2:45 PM:
-------------------------------------------------------------------
A request is initiated by Runner 229 on perf17 which generates a session
sgalNLPm8jvqZzLyQjwt4oZ3 which gets assigned jvmRoute perf19. It uses perf19 to process
requests until perf19 fails and the jvmRoute is changed to perf18. The server logs show
activity at perf18 and perf21: the perf18 exceptions come in groups of three
{noformat}
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,112 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-97) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,123 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-97) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,132 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-97)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=3842}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@f00}
org.infinispan.transaction.synchronization.SynchronizationAdapter@f1f:
org.infinispan.CacheException: Could not prepare.
{noformat}
representing an incoming prepare request to the assigned slave; the perf21 exceptions
{noformat}
./lastSuccessful/perf21.log:[JBossINF] 11:46:54,106 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-1720,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
{noformat}
are the corresponding remote prepare commands which are sent to all hosts participating in
the prepare and which fail only on perf21. Those exceptions are then returned to perf18
and show up there.
These coupled pairs of exceptions occur every 19 (= 4 + 15) seconds where the client sends
out requests every 4 seconds regularly, and the timeout on waiting for the locks is 15
seconds. Each coupled pair of exceptions represents a different incoming retry request by
the client to do complete the HTTP request. These exceptions only arise after perf19 fails
and they disappear when perf19 comes back.
Is it possible that perf21 was a remote participant in a transaction initiated on perf19
(before failure) and perf19 (the coordinator for the prepare) was shutdown during the
prepare phase for a transaction involving the session in question. So perf21 ended up with
locks on the session which let's assume were never released, in a different cache
view. Then perf18 becomes the new jvmRoute for the session, and, in a new cache view,
tries to prepare a transaction using the same session id. When it coordinates its prepare
phase, the remote command goes out to perf21 which tries to take locks for that session
locally and it times out waiting for the locks.
The way locks are taken on remote nodes as in
AbstractLockingTxInterceptor.lockKeyAndCheckOwnership() is to:
- check if there any pending locks for that session id (i.e. locks on transactions from
previous cache views which are pending - have not completed)
- if there are pending locks, wait for them to complete
The exceptions in this issue are occurring when we try to wait for locks for pending
transactions (in earlier cache views) and we never get them time (in 15 seconds). So it
may be that there are stale entries in the transaction tables.
was (Author: rachmato):
A request is initiated by Runner 229 on perf17 which generates a session
sgalNLPm8jvqZzLyQjwt4oZ3 which gets assigned jvmRoute perf19. It uses perf19 to process
requests until perf19 fails and the jvmRoute is changed to perf18. The server logs show
activity at perf18 and perf21: the perf18 exceptions come in groups of three
{noformat}
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,112 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-97) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,123 ERROR
[org.infinispan.transaction.TransactionCoordinator] (ajp-perf18/10.16.90.54:8009-97) Error
while processing prepare: org.infinispan.util.concurrent.TimeoutException: Unable to
acquire lock after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
./lastSuccessful/perf18.log:[JBossINF] 11:46:54,132 ERROR
[org.infinispan.transaction.tm.DummyTransaction] (ajp-perf18/10.16.90.54:8009-97)
ISPN000109: beforeCompletion() failed for
SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null,
isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=3842}, status=1},
lockedKeys=null, backupKeyLocks=[sgalNLPm8jvqZzLyQjwt4oZ3], viewId=7}
org.infinispan.transaction.synchronization.SyncLocalTransaction@f00}
org.infinispan.transaction.synchronization.SynchronizationAdapter@f1f:
org.infinispan.CacheException: Could not prepare.
{noformat}
representing an incoming prepare request to the assigned slave; the perf21 exceptions
{noformat}
./lastSuccessful/perf21.log:[JBossINF] 11:46:54,106 ERROR
[org.infinispan.interceptors.InvocationContextInterceptor] (OOB-1720,null) ISPN000136:
Execution error: org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock
after [15 seconds] on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
{noformat}
are the corresponding remote prepare commands which are sent to all hosts participating in
the prepare and which fail only on perf21. Those exceptions are then returned to perf18
and show up there.
These coupled pairs of exceptions occur every 19 (= 4 + 15) seconds where the client sends
out requests every 4 seconds regularly, and the timeout on waiting for the locks is 15
seconds. Each coupled pair of exceptions represents a different incoming retry request by
the client to do complete the HTTP request. These exceptions only arise after perf19 fails
and they disappear when perf19 comes back.
Is it possible that perf21 was a remote participant in a transaction initiated on perf19
(before failure) and perf19 (the coordinator for the prepare) was shutdown during the
prepare phase for a transaction involving the session in question. So perf21 ended up with
locks on the session which let's assume were never released, in a different cache
view. Then perf18 becomes the new jvmRoute for the session, and tries to prepare a
transaction using the same session id. When it coordinates its prepare phase, the remote
command goes out to perf21 which tries to take locks for that session locally and it times
out waiting for the locks.
The way locks are taken on remote nodes as in
AbstractLockingTxInterceptor.lockKeyAndCheckOwnership() is to:
- check if there any pending locks for that session id (i.e. locks on transactions from
previous cache views which are pending - have not completed)
- if there are pending locks, wait for them to complete
The exceptions in this issue are occurring when we try to wait for locks for pending
transactions (in earlier cache views) and we never get them time (in 15 seconds). So it
may be that there are stale entries in the transaction tables.
Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
-------------------------------------------------------------------------------
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.1.3.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
11:43 a.m.
[
https://issues.jboss.org/browse/AS7-4813?page=com.atlassian.jira.plugin.s...
]
Dan Berindei commented on AS7-4813:
-----------------------------------
Richard, I might be wrong, but I think the errors only start appearing AFTER perf19
re-joined the cluster. This is what I've seen in the server logs:
{noformat}
11:45:29,369 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport]
(Incoming-14,null) ISPN000094: Received new cluster view: [perf21/web|6] [perf21/web,
perf20/web, perf18/web]
11:46:34,639 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport]
(Incoming-10,null) ISPN000094: Received new cluster view: [perf21/ejb|7] [perf21/ejb,
perf20/ejb, perf18/ejb, perf19/ejb]
11:46:54,112 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(ajp-perf18/10.16.90.54:8009-97) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
{noformat}
Richard, could it be that the client is only reporting the jvm route change if the request
was successful? That may explain why the client logs show the jvm route change so long
after the node re-joined... (Assuming I got the right logs.)
A possible reason may be that we only remove the tx from the TransactionTable in
XaTransactionAdapter.commit, after we have already released the shared StateTransferLock.
So it's possible for state transfer to acquire the exclusive StateTransferLock and
start sending the tx information to the new owner before all the already-committed txs
have been removed from the table. The tx being committed already, the joiner won't
receive any other commit command and will keep the key locked until it loses ownership of
the key.
Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
-------------------------------------------------------------------------------
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.1.3.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
3:34 p.m.
[
https://issues.jboss.org/browse/AS7-4813?page=com.atlassian.jira.plugin.s...
]
Richard Achmatowicz commented on AS7-4813:
------------------------------------------
I've had a look at the JvmRouteValve code and it appears that the jvmRoute processing
is done as the request comes in: both the sessionid.jvmRoute in the cached session is
modified, as well as any sessionid.jvmRoute information in the Cookie in the response. So
I would expect that if an exception was thrown in a later valve, it would have the updated
information included which would go back to the client. Is that what you were asking
about?
Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
-------------------------------------------------------------------------------
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.1.3.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
6:18 a.m.
[
https://issues.jboss.org/browse/AS7-4813?page=com.atlassian.jira.plugin.s...
]
Mircea Markus commented on AS7-4813:
------------------------------------
@Dan
When syncCommitPhase=false both the lock release and removal of the transaction from the
tx table happen during the commit phase(no lock release command being send). So it's
not possible to have the transaction committed and still holding locks/be present in the
tx table.
In this situation seems like the commit command doesn't make it on the node which
still has the lock held. Unless recovery is enabled( Paul?), the fact that the commit is
sent async shouldn't really matter as the lock would be released by the async view
change thread. I guess some trace logs can tell us more?
Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
-------------------------------------------------------------------------------
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.1.3.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
9:32 a.m.
[
https://issues.jboss.org/browse/AS7-4813?page=com.atlassian.jira.plugin.s...
]
Paul Ferraro commented on AS7-4813:
-----------------------------------
We don't have recovery enabled.
Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
-------------------------------------------------------------------------------
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.1.3.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
9:37 a.m.
[
https://issues.jboss.org/browse/AS7-4813?page=com.atlassian.jira.plugin.s...
]
Dan Berindei commented on AS7-4813:
-----------------------------------
@Mircea, because the commit is async, I would imagine that the transaction can be
committed on the originator yet still present in the transaction table on the primary or
backup owner - the ones that send the list of pending transactions to the joiner.
Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
-------------------------------------------------------------------------------
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.1.3.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
4:34 p.m.
[
https://issues.jboss.org/browse/AS7-4813?page=com.atlassian.jira.plugin.s...
]
Brian Stansberry updated AS7-4813:
----------------------------------
Fix Version/s: 7.2.0.CR1
7.1.4.Final (EAP)
(was: 7.1.3.Final (EAP))
Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
-------------------------------------------------------------------------------
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.2.0.CR1, 7.1.4.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
11:57 a.m.
[
https://issues.jboss.org/browse/AS7-4813?page=com.atlassian.jira.plugin.s...
]
Paul Ferraro closed AS7-4813.
-----------------------------
Fix Version/s: 7.1.3.Final (EAP)
(was: 7.2.0.CR1)
(was: 7.1.4.Final (EAP))
Resolution: Out of Date
This was already addressed by AS7-5379.
Shutdown in REPL SYNC results in TimeoutException: Unable to acquire
lock after
-------------------------------------------------------------------------------
Key: AS7-4813
URL: https://issues.jboss.org/browse/AS7-4813
Project: Application Server 7
Issue Type: Bug
Components: Clustering
Affects Versions: 7.1.2.Final (EAP)
Reporter: Radoslav Husar
Assignee: Paul Ferraro
Fix For: 7.1.3.Final (EAP)
Similar to what we had before, but this time in failover tests.
Whole logs
http://hudson.qa.jboss.com/hudson/view/EAP6/view/EAP6-Failover/job/eap-6x...
{noformat}
11:46:54,106 ERROR [org.infinispan.interceptors.InvocationContextInterceptor]
(OOB-1720,null) ISPN000136: Execution error:
org.infinispan.util.concurrent.TimeoutException: Unable to acquire lock after [15 seconds]
on key [sgalNLPm8jvqZzLyQjwt4oZ3] for requestor
[GlobalTransaction:<perf18/web>:3840:remote]! Lock held by
[GlobalTransaction:<perf18/web>:3617:remote]
at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:216)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:189)
at
org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:179)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:209)
at
org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
at
org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
at
org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
at
org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
at
org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at
org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
at
org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
at
org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
at
org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
at
org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:706)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:566)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.BARRIER.up(BARRIER.java:126)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.Discovery.up(Discovery.java:359)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.stack.Protocol.up(Protocol.java:363)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
[jgroups-3.0.9.Final.jar:3.0.9.Final]
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
[rt.jar:1.6.0_30]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
[rt.jar:1.6.0_30]
at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
4460
days inactive
4628
days old
10 comments
6 participants
participants (6)
-
Brian Stansberry (JIRA) -
Dan Berindei (JIRA)
-
Mircea Markus (JIRA)
-
Paul Ferraro (JIRA)
-
Radoslav Husar (JIRA)
-
Richard Achmatowicz (JIRA)