[
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