You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Keith Wall (JIRA)" <ji...@apache.org> on 2015/04/21 13:53:59 UTC
[jira] [Resolved] (QPID-6502) Close connection in response to a
CSRE condition rather than sending an execution exception
[ https://issues.apache.org/jira/browse/QPID-6502?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Keith Wall resolved QPID-6502.
------------------------------
Resolution: Fixed
> Close connection in response to a CSRE condition rather than sending an execution exception
> -------------------------------------------------------------------------------------------
>
> Key: QPID-6502
> URL: https://issues.apache.org/jira/browse/QPID-6502
> Project: Qpid
> Issue Type: Bug
> Components: Java Broker
> Reporter: Keith Wall
> Assignee: Keith Wall
> Fix For: 6.0 [Java]
>
>
> The Java Broker internally throws a ConnectionScopeRuntimeException in response to abnormal conditions encountered whilst processing commands from the wire. The intention is that this exception causes the Broker to close the messaging connection.
> This is currently not the case within the 0-10 implementation. A CSRE originating from beneath ServerSessionDelegate#command currently causes a execution exception to be sent down the wire, but the connection remains open.
> This problem is currently causing MultiNodeTest#testTransferMasterWhilstMessagesInFlight to fail consistently on the 0-10 BDB profile. Here the execution exception causes the client to close the JMS Session. The JE thread, in response to lost of mastership, then causes the connection to be closed, and the client then fails-over. However on reconnection to the new master the JMS connection no longer has a Session so the test fails.
> Broker side:
> {noformat}
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - org.apache.qpid.server.util.ConnectionScopedRuntimeException: Environment 'nodetestTransferMasterWhilstMessagesInFlight10001' cannot finish JE operation because master is unknown
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.handleDatabaseException(ReplicatedEnvironmentFacade.java:409)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.commit(ReplicatedEnvironmentFacade.java:288)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.commitTranImpl(AbstractBDBMessageStore.java:788)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore.access$1200(AbstractBDBMessageStore.java:74)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.store.berkeleydb.AbstractBDBMessageStore$BDBTransaction.commitTran(AbstractBDBMessageStore.java:1367)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.txn.LocalTransaction.commit(LocalTransaction.java:348)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.txn.LocalTransaction.commit(LocalTransaction.java:338)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ServerSession.commit(ServerSession.java:672)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.txCommit(ServerSessionDelegate.java:552)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.txCommit(ServerSessionDelegate.java:86)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.TxCommit.dispatch(TxCommit.java:82)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:55)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.command(ServerSessionDelegate.java:103)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ServerSessionDelegate.command(ServerSessionDelegate.java:86)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.Method.delegate(Method.java:159)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.Session.received(Session.java:596)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.Connection.dispatch(Connection.java:463)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:64)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:40)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.MethodDelegate.txCommit(MethodDelegate.java:152)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.TxCommit.dispatch(TxCommit.java:82)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:54)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:40)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.Method.delegate(Method.java:159)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.Connection.received(Connection.java:416)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ServerConnection.access$001(ServerConnection.java:70)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ServerConnection$2.run(ServerConnection.java:347)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ServerConnection$2.run(ServerConnection.java:343)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at java.security.AccessController.doPrivileged(Native Method)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at javax.security.auth.Subject.doAs(Subject.java:360)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ServerConnection.received(ServerConnection.java:342)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:98)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:199)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:132)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.network.Frame.delegate(Frame.java:128)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.network.Assembler.received(Assembler.java:103)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ServerAssembler.received(ServerAssembler.java:48)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:200)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:115)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.v0_10.ProtocolEngine_0_10.received(ProtocolEngine_0_10.java:218)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.protocol.MultiVersionProtocolEngine.received(MultiVersionProtocolEngine.java:159)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.transport.NonBlockingConnection.doRead(NonBlockingConnection.java:375)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.transport.NonBlockingConnection.doWork(NonBlockingConnection.java:276)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.transport.NetworkConnectionScheduler.processConnection(NetworkConnectionScheduler.java:94)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.transport.NetworkConnectionScheduler.access$000(NetworkConnectionScheduler.java:34)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.transport.NetworkConnectionScheduler$2.run(NetworkConnectionScheduler.java:75)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at java.lang.Thread.run(Thread.java:745)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - Caused by: com.sleepycat.je.rep.UnknownMasterException: (JE 5.0.104) Problem closing transaction -68. The current state is:UNKNOWN. The node transitioned to this state at:Fri Apr 17 22:49:01 BST 2015
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at com.sleepycat.je.rep.impl.RepImpl.checkIfMaster(RepImpl.java:872)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at com.sleepycat.je.rep.txn.MasterTxn.checkIfFrozen(MasterTxn.java:631)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at com.sleepycat.je.txn.Txn.commit(Txn.java:834)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at com.sleepycat.je.Transaction.doCommit(Transaction.java:609)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at com.sleepycat.je.Transaction.commit(Transaction.java:410)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - at org.apache.qpid.server.store.berkeleydb.replication.ReplicatedEnvironmentFacade.commit(ReplicatedEnvironmentFacade.java:284)
> 2015-04-17 22:49:01,624 INFO [STD] (BROKER-10000) - ... 47 more
> {noformat}
> Client side:
> {noformat}
> at org.apache.qpid.client.AMQSession_0_10.setCurrentException(AMQSession_0_10.java:1082)
> at org.apache.qpid.client.AMQSession_0_10.exception(AMQSession_0_10.java:936)
> at org.apache.qpid.transport.SessionDelegate.executionException(SessionDelegate.java:182)
> at org.apache.qpid.transport.SessionDelegate.executionException(SessionDelegate.java:32)
> at org.apache.qpid.transport.ExecutionException.dispatch(ExecutionException.java:103)
> at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:55)
> at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:50)
> at org.apache.qpid.transport.SessionDelegate.command(SessionDelegate.java:32)
> at org.apache.qpid.transport.Method.delegate(Method.java:159)
> at org.apache.qpid.transport.Session.received(Session.java:596)
> at org.apache.qpid.transport.Connection.dispatch(Connection.java:463)
> at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:64)
> at org.apache.qpid.transport.ConnectionDelegate.handle(ConnectionDelegate.java:40)
> at org.apache.qpid.transport.MethodDelegate.executionException(MethodDelegate.java:110)
> at org.apache.qpid.transport.ExecutionException.dispatch(ExecutionException.java:103)
> at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:54)
> at org.apache.qpid.transport.ConnectionDelegate.command(ConnectionDelegate.java:40)
> at org.apache.qpid.transport.Method.delegate(Method.java:159)
> at org.apache.qpid.transport.Connection.received(Connection.java:416)
> at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:98)
> at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:199)
> at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:132)
> at org.apache.qpid.transport.network.Frame.delegate(Frame.java:128)
> at org.apache.qpid.transport.network.Assembler.received(Assembler.java:103)
> at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:200)
> at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:115)
> at org.apache.qpid.transport.network.io.IoReceiver.run(
> {noformat}
>
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org