[
https://issues.apache.org/jira/browse/QPID-6711?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Keith Wall updated QPID-6711:
-----------------------------
Attachment: repo.tar.bz2
> [0-8..0-9-1] Client may send a ChannelOpen before connection establishment
> is complete
> ---------------------------------------------------------------------------------------
>
> Key: QPID-6711
> URL: https://issues.apache.org/jira/browse/QPID-6711
> Project: Qpid
> Issue Type: Bug
> Components: Java Client
> Affects Versions: qpid-java-6.0
> Environment: MacBookAir 1.7 GHz Intel Core i7
> Maximum Memory : 1,908,932,608 bytes
> Platform : JVM : Oracle Corporation version: 1.7.0_45-b18 OS : Mac OS X
> version: 10.10.4 arch: x86_64 cores: 4
> Reporter: Keith Wall
> Attachments: repo.tar.bz2
>
>
> I am seeing a sporadic issue on the legacy Qpid Client when using the
> 0-8..0-91 protocol with SSL. Occasionally, the client is seen to emit a
> ChannelOpen before the ConnectionOpenOk has been received. The Java Broker
> detects that illegal state and closes the connection.
> I have not checked if this is a regression. I am reproducing this issue
> running the Perftest profile VaryingNumberOfParticipantsSSL.js using a Java
> Broker configured with SSL using the canned test certs.
> After augmenting the Broker to log a stack trace
> AMQPConnection_0_8#assertState)
> {noformat}
> 2015-08-26 09:26:47,977 ERROR [IO-/127.0.0.1:51674]
> (o.a.q.s.p.v.AMQPConnection_0_8) - Connection is in the wrong state
> AWAIT_START_OK , expecting OPEN
> java.lang.Exception: null
> at
> org.apache.qpid.server.protocol.v0_8.AMQPConnection_0_8.assertState(AMQPConnection_0_8.java:1061)
> [classes/:na]
> at
> org.apache.qpid.server.protocol.v0_8.AMQPConnection_0_8.receiveChannelOpen(AMQPConnection_0_8.java:1020)
> [classes/:na]
> at
> org.apache.qpid.framing.ChannelOpenBody.process(ChannelOpenBody.java:92)
> [classes/:na]
> at
> org.apache.qpid.codec.ServerDecoder.processMethod(ServerDecoder.java:122)
> [classes/:na]
> {noformat}
> And augmenting the Qpid Client to that IoSender and IoReceiver include the
> socket's localport:
> {noformat}
> 2015-08-26 09:26:47,972 DEBUG [Dispatcher-2-Conn-34]
> o.a.q.c.AMQProtocolHandler SEND: AMQP1109
> 2015-08-26 09:26:47,972 INFO [Dispatcher-2-Conn-34] o.a.q.c.AMQConnection
> Connection 82 now connected from /127.0.0.1:51674 to localhost/127.0.0.1:5671
> 2015-08-26 09:26:47,973 DEBUG [Dispatcher-2-Conn-34] o.a.q.c.AMQConnection
> Are we connected:true
> 2015-08-26 09:26:47,973 DEBUG [Dispatcher-2-Conn-34] o.a.q.c.AMQConnection
> Connected with ProtocolHandler Version:0-9
> 2015-08-26 09:26:47,974 DEBUG [Dispatcher-2-Conn-1]
> o.a.q.c.AMQProtocolHandler SEND: Frame channelId: 2, bodyFrame:
> [BasicAckBodyImpl: deliveryTag=81, multiple=false]
> 2015-08-26 09:26:47,974 DEBUG [Dispatcher-2-Conn-34]
> o.a.q.c.AMQProtocolHandler SEND:
> org.apache.qpid.framing.CompositeAMQDataBlock{ 0=[Frame channelId: 3,
> bodyFrame: [BasicPublishBodyImpl: ticket=0, exchange=amq.direct,
> routingKey=controllerqueue, mandatory=true, immediate=false]] 1=[Frame
> channelId: 3, bodyFrame: ContentHeaderBody{classId=60, weight=0, bodySize=0,
> properties=reply-to = null,propertyFlags = 47312,ApplicationID =
> null,ClusterID = null,UserId = guest,JMSMessageID =
> ID:448e77ea-0fde-3dd8-9133-1654cdb15fad,JMSCorrelationID =
> null,JMSDeliveryMode = 2,JMSExpiration = 0,JMSPriority = 4,JMSTimestamp =
> 1440577607974,JMSType = null}]}
> 2015-08-26 09:26:47,974 DEBUG [Dispatcher-2-Conn-34]
> o.a.q.c.AMQProtocolHandler SEND: Frame channelId: 2, bodyFrame:
> [BasicAckBodyImpl: deliveryTag=1, multiple=false]
> 2015-08-26 09:26:47,975 DEBUG [Dispatcher-2-Conn-34]
> o.a.q.c.AMQProtocolHandler SEND: Frame channelId: 1, bodyFrame:
> [ChannelOpenBody]
> 2015-08-26 09:26:47,976 DEBUG [IoRcvr-localhost/127.0.0.1:5671-51674]
> o.a.q.c.AMQProtocolHandler RECV: Frame channelId: 0, bodyFrame:
> [ConnectionStartBodyImpl: versionMajor=0, versionMinor=9,
> serverProperties={product=[LONG_STRING: qpid], version=[LONG_STRING:
> 6.0.0-SNAPSHOT], qpid.build=[LONG_STRING: Unversioned directory],
> qpid.instance_name=[LONG_STRING: Broker],
> qpid.close_when_no_route=[LONG_STRING: true],
> qpid.message_compression_supported=[LONG_STRING: true],
> qpid.confirmed_publish_supported=[LONG_STRING: true],
> qpid.virtualhost_properties_supported=[LONG_STRING: true]}, mechanisms=[80,
> 76, 65, 73, 78, 32, 67, 82, 65, 77, 45, 77, 68, 53], locales=[101, 110, 95,
> 85, 83]]
> 2015-08-26 09:26:47,977 DEBUG [IoRcvr-localhost/127.0.0.1:5671-51674]
> o.a.q.c.AMQProtocolHandler SEND: Frame channelId: 0, bodyFrame:
> [ConnectionStartOkBodyImpl: clientProperties={instance=[LONG_STRING:
> clientid], product=[LONG_STRING: qpid], version=[LONG_STRING:
> 6.0.0-SNAPSHOT], platform=[LONG_STRING: Java(TM) SE Runtime Environment,
> 1.7.0_79-b15, Oracle Corporation, x86_64, Mac OS X, 10.10.4, unknown],
> qpid.client_process=[LONG_STRING: Qpid Java Client], qpid.client_pid=[INT:
> 1142], qpid.message_compression_supported=[LONG_STRING: false]},
> mechanism=CRAM-MD5, response=null, locale=en_US]
> 2015-08-26 09:26:47,978 DEBUG [IoRcvr-localhost/127.0.0.1:5672-51588]
> o.a.q.c.AMQProtocolHandler RECV: Frame channelId: 2, bodyFrame:
> [BasicDeliverBodyImpl: consumerTag=1, deliveryTag=82, redelivered=false,
> exchange=amq.direct, routingKey=controllerqueue]
> 2015-08-26 09:26:47,978 DEBUG [IoRcvr-localhost/127.0.0.1:5672-51588]
> o.a.q.c.AMQProtocolHandler RECV: Frame channelId: 2, bodyFrame:
> ContentHeaderBody{classId=60, weight=0, bodySize=0, properties=reply-to =
> null,propertyFlags = 47312,ApplicationID = null,ClusterID = null,UserId =
> guest,JMSMessageID = ID:448e77ea-0fde-3dd8-9133-1654cdb15fad,JMSCorrelationID
> = null,JMSDeliveryMode = 2,JMSExpiration = 0,JMSPriority = 4,JMSTimestamp =
> 1440577607974,JMSType = null}
> 2015-08-26 09:26:47,980 DEBUG [Dispatcher-2-Conn-1]
> o.a.q.c.AMQProtocolHandler SEND: Frame channelId: 2, bodyFrame:
> [BasicAckBodyImpl: deliveryTag=82, multiple=false]
> 2015-08-26 09:26:47,981 DEBUG [IoRcvr-localhost/127.0.0.1:5671-51673]
> o.a.q.c.AMQProtocolHandler RECV: Frame channelId: 0, bodyFrame:
> [ConnectionCloseBodyImpl: replyCode=503, replyText=Command Invalid - not in
> required state OPEN current state AWAIT_START_OK, classId=20, methodId=10]
> 2015-08-26 09:26:47,981 DEBUG [IoRcvr-localhost/127.0.0.1:5671-51674]
> o.a.q.c.AMQProtocolHandler RECV: Frame channelId: 0, bodyFrame:
> [ConnectionCloseBodyImpl: replyCode=503, replyText=Command Invalid - not in
> required state OPEN current state AWAIT_START_OK, classId=20, methodId=10]
> {noformat}
> Notice that 51674 is reporting "Connection 82 now connected" before
> ConnectionOpenOk has been received. It suggests to me a defect in the
> StateWaiter mechanics.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org
