0-9-1 client attempts to reuse the connection after sending ConnectionCloseOk
-----------------------------------------------------------------------------
Key: QPID-3534
URL: https://issues.apache.org/jira/browse/QPID-3534
Project: Qpid
Issue Type: Bug
Components: Java Client
Affects Versions: 0.12, 0.11, 0.10, 0.9, 0.8, 0.7, 0.6, 0.5
Reporter: Alex Rudyy
Fix For: 0.13
With current implementation of 0-8/0-9/0-9-1 client, on receiving
ConnectionClose command from a broker, the client sends ConnectionCloseOk to
the server, and, than it sends another ConnectionClose commands to the broker.
First of all, such client behavior is not in the line with AMQP specs.
The sending of second command "ConnectionClose" from a client in the process of
closing socket by a broker might result in Exceptions being thrown in IoSender
which in turn might close the client connection and cause unexpected behaviour
in failover( The failover thread cannot be started when connection is closed).
The following logs demonstrates the issue
{noformat}
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,948 INFO
[qpid.protocol] RECV:
[org.apache.qpid.client.protocol.AMQProtocolHandler@19d142f] Frame channelId:
0, bodyFrame: [ConnectionCloseBodyImpl: replyCode=320, replyText=Broker is
shutting down, classId=0, methodId=0]
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,948 DEBUG
[qpid.client.protocol.AMQProtocolHandler] (27071535)Method frame received:
[ConnectionCloseBodyImpl: replyCode=320, replyText=Broker is shutting down,
classId=0, methodId=0]
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,948 INFO
[qpid.client.handler.ConnectionCloseMethodHandler] ConnectionClose frame
received
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,949 DEBUG
[qpid.protocol] SEND:
[org.apache.qpid.client.protocol.AMQProtocolHandler@19d142f] Frame channelId:
0, bodyFrame: [ConnectionCloseOkBodyImpl: ]
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,949 INFO
[qpid.client.handler.ConnectionCloseMethodHandler] Connection close received
with error code 320: connection forced
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,949 DEBUG
[qpid.client.state.AMQStateManager] State changing to AMQState: id = 5 name:
CONNECTION_CLOSING from old state AMQState: id = 4 name: CONNECTION_OPEN
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,949 DEBUG
[qpid.client.state.AMQStateManager] Notififying State change to 0 : []
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,949 ERROR
[qpid.client.state.AMQStateManager] No Waiters for error saving as last
error:Error: Broker is shutting down
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,949 INFO
[qpid.client.protocol.AMQProtocolHandler] Exception caught therefore going to
attempt failover: org.apache.qpid.AMQConnectionClosedException: Error: Broker
is shutting down [error code 320: connection forced]
org.apache.qpid.AMQConnectionClosedException: Error: Broker is shutting down
[error code 320: connection forced]
at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
at
sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
at
org.apache.qpid.AMQException.cloneForCurrentThread(AMQException.java:116)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.writeCommandFrameAndWaitForReply(AMQProtocolHandler.java:617)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.syncWrite(AMQProtocolHandler.java:653)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.closeConnection(AMQProtocolHandler.java:683)
at
org.apache.qpid.client.protocol.AMQProtocolSession.closeProtocolSession(AMQProtocolSession.java:365)
at
org.apache.qpid.client.handler.ConnectionCloseMethodHandler.methodReceived(ConnectionCloseMethodHandler.java:105)
at
org.apache.qpid.client.handler.ClientMethodDispatcherImpl.dispatchConnectionClose(ClientMethodDispatcherImpl.java:192)
at
org.apache.qpid.framing.amqp_0_91.ConnectionCloseBodyImpl.execute(ConnectionCloseBodyImpl.java:142)
at
org.apache.qpid.client.state.AMQStateManager.methodReceived(AMQStateManager.java:114)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.methodBodyReceived(AMQProtocolHandler.java:480)
at
org.apache.qpid.client.protocol.AMQProtocolSession.methodFrameReceived(AMQProtocolSession.java:445)
at
org.apache.qpid.framing.AMQMethodBodyImpl.handle(AMQMethodBodyImpl.java:96)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.received(AMQProtocolHandler.java:437)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.received(AMQProtocolHandler.java:121)
at
org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:151)
at java.lang.Thread.run(Thread.java:619)
Caused by: org.apache.qpid.AMQConnectionClosedException: Error: Broker is
shutting down [error code 320: connection forced]
at
org.apache.qpid.client.handler.ConnectionCloseMethodHandler.methodReceived(ConnectionCloseMethodHandler.java:92)
... 10 more
IoSender - localhost/127.0.0.1:25672 2011-10-08 08:39:49,950 ERROR
[transport.network.io.IoSender] error in write thread
java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at org.apache.qpid.transport.network.io.IoSender.run(IoSender.java:313)
at java.lang.Thread.run(Thread.java:619)
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,951 ERROR
[qpid.client.protocol.AMQProtocolHandler] Exception processing frame
org.apache.qpid.transport.SenderException: java.net.SocketException: Broken pipe
at
org.apache.qpid.transport.network.io.IoSender.close(IoSender.java:234)
at
org.apache.qpid.transport.network.io.IoSender.close(IoSender.java:194)
at
org.apache.qpid.transport.network.io.IoNetworkConnection.close(IoNetworkConnection.java:70)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.exception(AMQProtocolHandler.java:307)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.methodBodyReceived(AMQProtocolHandler.java:505)
at
org.apache.qpid.client.protocol.AMQProtocolSession.methodFrameReceived(AMQProtocolSession.java:445)
at
org.apache.qpid.framing.AMQMethodBodyImpl.handle(AMQMethodBodyImpl.java:96)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.received(AMQProtocolHandler.java:437)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.received(AMQProtocolHandler.java:121)
at
org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:151)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at org.apache.qpid.transport.network.io.IoSender.run(IoSender.java:313)
... 1 more
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,951 DEBUG
[apache.qpid.client.AMQConnection] exceptionReceived done by:IoReceiver -
localhost/127.0.0.1:25672
org.apache.qpid.transport.SenderException: java.net.SocketException: Broken pipe
at
org.apache.qpid.transport.network.io.IoSender.close(IoSender.java:234)
at
org.apache.qpid.transport.network.io.IoSender.close(IoSender.java:194)
at
org.apache.qpid.transport.network.io.IoNetworkConnection.close(IoNetworkConnection.java:70)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.exception(AMQProtocolHandler.java:307)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.methodBodyReceived(AMQProtocolHandler.java:505)
at
org.apache.qpid.client.protocol.AMQProtocolSession.methodFrameReceived(AMQProtocolSession.java:445)
at
org.apache.qpid.framing.AMQMethodBodyImpl.handle(AMQMethodBodyImpl.java:96)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.received(AMQProtocolHandler.java:437)
at
org.apache.qpid.client.protocol.AMQProtocolHandler.received(AMQProtocolHandler.java:121)
at
org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:151)
at java.lang.Thread.run(Thread.java:619)
Caused by: java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
at org.apache.qpid.transport.network.io.IoSender.run(IoSender.java:313)
... 1 more
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,951 INFO
[apache.qpid.client.AMQConnection] Closing AMQConnection due to
:org.apache.qpid.transport.SenderException: java.net.SocketException: Broken
pipe
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,952 DEBUG
[apache.qpid.client.BasicMessageConsumer] Passed exception to synchronous queue
for propagation to receive()
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,952 DEBUG
[qpid.client.protocol.AMQProtocolHandler] Session closed called by client
IoReceiver - localhost/127.0.0.1:25672 2011-10-08 08:39:49,952 DEBUG
[qpid.client.protocol.AMQProtocolHandler] Protocol Session
[org.apache.qpid.client.protocol.AMQProtocolHandler@19d142f] closed
{noformat}
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators:
https://issues.apache.org/jira/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project: http://qpid.apache.org
Use/Interact: mailto:[email protected]
