[jboss-jira] [JBoss JIRA] (AS7-4724) Sessions lost on server crash when using DIST SYNC mode (Lock is being held by null)
Jason Greene (JIRA)
jira-events at lists.jboss.org
Wed May 9 23:57:21 EDT 2012
[ https://issues.jboss.org/browse/AS7-4724?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jason Greene updated AS7-4724:
------------------------------
Fix Version/s: 7.1.3.Final (EAP)
(was: 7.1.2.Final (EAP))
> Sessions lost on server crash when using DIST SYNC mode (Lock is being held by null)
> ------------------------------------------------------------------------------------
>
> Key: AS7-4724
> URL: https://issues.jboss.org/browse/AS7-4724
> Project: Application Server 7
> Issue Type: Bug
> Components: Clustering
> Affects Versions: 7.1.1.Final
> Reporter: Radoslav Husar
> Assignee: Paul Ferraro
> Priority: Critical
> Labels: failover_testing
> Fix For: 7.1.3.Final (EAP)
>
>
> It seems that the current failover tests have few failed requests when using DIST SYNC.
> The client logging indicates that
> {noformat}2012/05/06 17:04:20:041 EDT [WARN ][Runner - 123] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error sampling data: <org.jboss.smartfrog.loaddriver.RequestProcessingException: Stale session data received. Expected 100, received 0, Runner: 123>{noformat}
> that the session was not found and created a new session instead.
> The exceptions sorroundthing the errors
> {noformat}
> [JBossINF] 16:55:52,535 INFO [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (ajp-perf21-10.16.90.60-8009-44) New session created: -gjLvzZ7CdxcPVSlMbL1A1bK.perf21
> 2012/05/06 16:56:22:030 EDT [DEBUG][Thread-28] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - JBossStartup, server started!
> [JBossINF] 16:57:49,978 INFO [org.jboss.as.clustering] (Incoming-10,null) JBAS010226: New cluster view for partition ejb: 4 (org.jboss.as.clustering.impl.CoreGroupCommunicationService$GroupView at 6232c7b5 delta: -1, merge: false)
> [JBossINF] 16:57:49,980 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-10,null) ISPN000094: Received new cluster view: [perf19/ejb|4] [perf19/ejb, perf21/ejb, perf20/ejb]
> [JBossINF] 16:57:49,980 INFO [org.jboss.as.clustering] (Incoming-2,null) JBAS010226: New cluster view for partition web: 4 (org.jboss.as.clustering.impl.CoreGroupCommunicationService$GroupView at 27782e36 delta: -1, merge: false)
> [JBossINF] 16:57:49,981 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-2,null) ISPN000094: Received new cluster view: [perf19/web|4] [perf19/web, perf21/web, perf20/web]
> [JBossINF] 16:58:52,192 INFO [org.jboss.as.clustering] (Incoming-19,null) JBAS010226: New cluster view for partition web: 5 (org.jboss.as.clustering.impl.CoreGroupCommunicationService$GroupView at 2d942191 delta: 1, merge: false)
> [JBossINF] 16:58:52,192 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-19,null) ISPN000094: Received new cluster view: [perf19/web|5] [perf19/web, perf21/web, perf20/web, perf18/web]
> [JBossINF] 16:58:52,256 INFO [org.jboss.as.clustering] (Incoming-18,null) JBAS010226: New cluster view for partition ejb: 5 (org.jboss.as.clustering.impl.CoreGroupCommunicationService$GroupView at 2f94ac91 delta: 1, merge: false)
> [JBossINF] 16:58:52,257 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-18,null) ISPN000094: Received new cluster view: [perf19/ejb|5] [perf19/ejb, perf21/ejb, perf20/ejb, perf18/ejb]
> [JBossINF] 16:59:56,589 INFO [org.jboss.as.clustering] (VERIFY_SUSPECT.TimerThread,web,perf21/web) JBAS010232: Suspected member: perf19/web
> [JBossINF] 16:59:56,589 INFO [org.jboss.as.clustering] (VERIFY_SUSPECT.TimerThread,ejb,perf21/ejb) JBAS010232: Suspected member: perf19/ejb
> [JBossINF] 16:59:56,694 INFO [org.jboss.as.clustering] (Incoming-11,null) JBAS010225: New cluster view for partition ejb (id: 6, delta: -1, merge: false) : [perf21/ejb, perf20/ejb, perf18/ejb]
> [JBossINF] 16:59:56,694 INFO [org.jboss.as.clustering] (Incoming-1,null) JBAS010225: New cluster view for partition web (id: 6, delta: -1, merge: false) : [perf21/web, perf20/web, perf18/web]
> [JBossINF] 16:59:56,695 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-11,null) ISPN000094: Received new cluster view: [perf21/ejb|6] [perf21/ejb, perf20/ejb, perf18/ejb]
> [JBossINF] 16:59:56,695 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-1,null) ISPN000094: Received new cluster view: [perf21/web|6] [perf21/web, perf20/web, perf18/web]
> [JBossINF] 17:00:58,915 INFO [org.jboss.as.clustering] (Incoming-7,null) JBAS010225: New cluster view for partition web (id: 7, delta: 1, merge: false) : [perf21/web, perf20/web, perf18/web, perf19/web]
> [JBossINF] 17:00:58,916 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-7,null) ISPN000094: Received new cluster view: [perf21/web|7] [perf21/web, perf20/web, perf18/web, perf19/web]
> [JBossINF] 17:00:58,974 INFO [org.jboss.as.clustering] (Incoming-4,null) JBAS010225: New cluster view for partition ejb (id: 7, delta: 1, merge: false) : [perf21/ejb, perf20/ejb, perf18/ejb, perf19/ejb]
> [JBossINF] 17:00:58,974 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-4,null) ISPN000094: Received new cluster view: [perf21/ejb|7] [perf21/ejb, perf20/ejb, perf18/ejb, perf19/ejb]
> [JBossINF] 17:02:02,386 INFO [org.jboss.as.clustering] (VERIFY_SUSPECT.TimerThread,ejb,perf21/ejb) JBAS010232: Suspected member: perf20/ejb
> [JBossINF] 17:02:02,387 INFO [org.jboss.as.clustering] (VERIFY_SUSPECT.TimerThread,web,perf21/web) JBAS010232: Suspected member: perf20/web
> [JBossINF] 17:02:02,445 INFO [org.jboss.as.clustering] (Incoming-5,null) JBAS010225: New cluster view for partition web (id: 8, delta: -1, merge: false) : [perf21/web, perf18/web, perf19/web]
> [JBossINF] 17:02:02,450 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-5,null) ISPN000094: Received new cluster view: [perf21/web|8] [perf21/web, perf18/web, perf19/web]
> [JBossINF] 17:02:02,463 INFO [org.jboss.as.clustering] (Incoming-4,null) JBAS010225: New cluster view for partition ejb (id: 8, delta: -1, merge: false) : [perf21/ejb, perf18/ejb, perf19/ejb]
> [JBossINF] 17:02:02,463 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-4,null) ISPN000094: Received new cluster view: [perf21/ejb|8] [perf21/ejb, perf18/ejb, perf19/ejb]
> [JBossINF] 17:02:21,486 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (ajp-perf21-10.16.90.60-8009-104) ISPN000136: Execution error: org.infinispan.util.concurrent.TimeoutException: Could not acquire lock on x2pULjT0wz2pS0AC1l0Osck6 on behalf of transaction GlobalTransaction:<perf21/web>:5824:remote. Lock is being held by null
> [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.newTimeoutException(AbstractTxLockingInterceptor.java:214)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:195)
> [JBossINF] at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:136)
> [JBossINF] at org.infinispan.interceptors.locking.OptimisticLockingInterceptor$LockAcquisitionVisitor.visitPutKeyValueCommand(OptimisticLockingInterceptor.java:243)
> [JBossINF] at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
> [JBossINF] at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.acquireLocksVisitingCommands(OptimisticLockingInterceptor.java:318)
> [JBossINF] at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:119)
> [JBossINF] at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
> [JBossINF] at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
> [JBossINF] at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
> [JBossINF] at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
> [JBossINF] at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
> [JBossINF] at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
> [JBossINF] at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
> [JBossINF] at org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
> [JBossINF] at org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
> [JBossINF] at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
> [JBossINF] at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
> [JBossINF] at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
> [JBossINF] at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
> [JBossINF] at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
> [JBossINF] at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
> [JBossINF] at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
> [JBossINF] at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
> [JBossINF] at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
> [JBossINF] at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
> [JBossINF] at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
> [JBossINF] at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
> [JBossINF] at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
> [JBossINF] at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
> [JBossINF] at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
> [JBossINF] at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
> [JBossINF] at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
> [JBossINF] at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
> [JBossINF] at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
> [JBossINF] at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
> [JBossINF] at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
> [JBossINF] at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
> [JBossINF] at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
> [JBossINF] at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
> [JBossINF] at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
> [JBossINF] at org.jgroups.JChannel.up(JChannel.java:716)
> [JBossINF] at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
> [JBossINF] at org.jgroups.protocols.RSVP.up(RSVP.java:192)
> [JBossINF] at org.jgroups.protocols.FRAG2.up(FRAG2.java:181)
> [JBossINF] at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
> [JBossINF] at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
> [JBossINF] at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
> [JBossINF] at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
> [JBossINF] at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:759)
> [JBossINF] at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:365)
> [JBossINF] at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:602)
> [JBossINF] at org.jgroups.protocols.BARRIER.up(BARRIER.java:102)
> [JBossINF] at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
> [JBossINF] at org.jgroups.protocols.FD.up(FD.java:273)
> [JBossINF] at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
> [JBossINF] at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
> [JBossINF] at org.jgroups.protocols.Discovery.up(Discovery.java:359)
> [JBossINF] at org.jgroups.stack.Protocol.up(Protocol.java:363)
> [JBossINF] at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
> [JBossINF] at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
> [JBossINF] at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_30]
> [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_30]
> [JBossINF] at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
> [JBossINF]
> {noformat}
> ...
> {noformat}
> [JBossINF] 17:02:40,549 ERROR [org.infinispan.transaction.tm.DummyTransaction] (ajp-perf21-10.16.90.60-8009-104) ISPN000109: beforeCompletion() failed for SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=6307}, status=1}, lockedKeys=null, backupKeyLocks=null, viewId=8} org.infinispan.transaction.synchronization.SyncLocalTransaction at 189b} org.infinispan.transaction.synchronization.SynchronizationAdapter at 18ba: org.infinispan.CacheException: Could not prepare.
> [JBossINF] at org.infinispan.transaction.synchronization.SynchronizationAdapter.beforeCompletion(SynchronizationAdapter.java:70)
> [JBossINF] at org.infinispan.transaction.tm.DummyTransaction.notifyBeforeCompletion(DummyTransaction.java:230)
> [JBossINF] at org.infinispan.transaction.tm.DummyTransaction.runPrepare(DummyTransaction.java:241)
> [JBossINF] at org.infinispan.transaction.tm.DummyTransaction.commit(DummyTransaction.java:86)
> [JBossINF] at org.infinispan.transaction.tm.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:102)
> [JBossINF] at org.jboss.as.clustering.web.impl.TransactionBatchingManager.endBatch(TransactionBatchingManager.java:75)
> [JBossINF] at org.jboss.as.web.session.DistributableSessionManager.processSessionRepl(DistributableSessionManager.java:1512) [jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
> [JBossINF] at org.jboss.as.web.session.DistributableSessionManager.storeSession(DistributableSessionManager.java:854) [jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
> [JBossINF] at org.jboss.as.web.session.InstantSnapshotManager.snapshot(InstantSnapshotManager.java:47) [jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
> [JBossINF] at org.jboss.as.web.session.ClusteredSessionValve.handleRequest(ClusteredSessionValve.java:133) [jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
> [JBossINF] at org.jboss.as.web.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:91) [jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
> [JBossINF] at org.jboss.as.web.session.JvmRouteValve.invoke(JvmRouteValve.java:88) [jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
> [JBossINF] at org.jboss.as.web.session.LockingValve.invoke(LockingValve.java:56) [jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
> [JBossINF] at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:153) [jboss-as-web-7.1.2.Final-SNAPSHOT.jar:7.1.2.Final-SNAPSHOT]
> [JBossINF] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:155) [jbossweb-7.0.15.Final.jar:]
> [JBossINF] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [jbossweb-7.0.15.Final.jar:]
> [JBossINF] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [jbossweb-7.0.15.Final.jar:]
> [JBossINF] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:368) [jbossweb-7.0.15.Final.jar:]
> [JBossINF] at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:505) [jbossweb-7.0.15.Final.jar:]
> [JBossINF] at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:445) [jbossweb-7.0.15.Final.jar:]
> [JBossINF] at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:931) [jbossweb-7.0.15.Final.jar:]
> [JBossINF] at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
> [JBossINF] Caused by: javax.transaction.xa.XAException
> [JBossINF] at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:160)
> [JBossINF] at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:122)
> [JBossINF] at org.infinispan.transaction.synchronization.SynchronizationAdapter.beforeCompletion(SynchronizationAdapter.java:68)
> [JBossINF] ... 21 more
> {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
More information about the jboss-jira
mailing list