On Ter, 2013-05-21 at 12:08 +0100, Gordon Sim wrote:
> On 05/21/2013 11:14 AM, Bruno Matos wrote:
> > It needs the username and password properties set on domain creation, I
> > thought they were parsed from url.
> >
> > Now, with SASL it doesn't create the queue for the outgoing link. This
> > is because when qpid::broker::amqp::Sasl::canEncode() is called the
> > state is NONE so it doesn't call the Connection::canEncode which would
> > create the queue as when there is no SASL layer and Wrapper::canEncode
> > is called.
> >
> > If at this point I stop the source broker, the destination broker gives
> > 'Connection closed prior to authentication completing' twice, which
> > makes me think that authentication or the handshake were never finished.
>
> Can you post the protocol trace for the handshaking?
They are in attachment from both source and destination brokers.
>
> > Could you please help me understand if something is wrong with my
> > configuration or clarify this authentication/handshake process and what
> > may be wrong?
>
> I suspect a bug (or two) in the code (obviously there is at least one,
> that which you fixed already) where SASL and interlinks combine. I'm
> sorry I haven't responded more positively, I've been trying to finish
> off another piece of work. I will get on to this as soon as that is
> done. (And thanks very much for all your help and insight on the issue
> so far).
>
I'm glad I could help, as little as my contribution has been.
Regards.
--
Bruno Matos
2013-05-21 13:44:26 [Protocol] debug qpid.192.168.102.7:5672-192.168.102.146:33443 Sent SASL-MECHANISMS(PLAIN) 27
2013-05-21 13:44:26 [Protocol] debug qpid.192.168.102.7:5672-192.168.102.146:33443 writing protocol header: 1-0
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: INIT(0-10)
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ConnectionStartBody: server-properties={qpid.federation_tag:V2:36:str16(616dacd8-63e0-4f19-801b-bba718aa5a3a)}; mechanisms=str16{V2:5:str16(PLAIN)}; locales=str16{V2:5:str16(en_US)}; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ConnectionStartOkBody: client-properties={platform:V2:5:str16(posix),product:V2:18:str16(qpid python client),qpid.client_pid:F8:int64(20376),qpid.client_ppid:F8:int64(20009),qpid.client_process:V2:9:str16(qpid-ctrl),version:V2:11:str16(development)}; mechanism=PLAIN; response=xxxxxx; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ConnectionTuneBody: channel-max=32767; max-frame-size=65535; heartbeat-min=0; heartbeat-max=120; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ConnectionTuneOkBody: channel-max=32767; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ConnectionOpenBody: }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ConnectionOpenOkBody: known-hosts=str16{}; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionAttachBody: name=d12fcc51-d697-4385-88f4-37d152ec87b2:0; }]
2013-05-21 13:44:07 [Protocol] debug Attached channel 0 to someuser@QPID.d12fcc51-d697-4385-88f4-37d152ec87b2:0
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionCommandPointBody: command-id=0; command-offset=0; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ExchangeQueryBody: name=qmf.default.direct; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {QueueQueryBody: queue=qmf.default.direct; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionAttachedBody: name=d12fcc51-d697-4385-88f4-37d152ec87b2:0; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionCommandPointBody: command-id=0; command-offset=0; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ExecutionResultBody: command-id=0; value=\x07\x01 \x00\x11management-direct\x00\x00\x00\x1A\x00\x00\x00\x01\x0Eqpid.replicate\x95\x00\x04none; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,0] }; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ExecutionResultBody: command-id=1; value=\x08\x01\x00\x00; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,1] }; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {QueueDeclareBody: queue=d12fcc51-d697-4385-88f4-37d152ec87b2:0.0; exclusive=1; auto-delete=1; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ExchangeBindBody: queue=d12fcc51-d697-4385-88f4-37d152ec87b2:0.0; exchange=qmf.default.direct; binding-key=68c9524a-c7ce-41b0-b7a8-1f16c2e18407; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {MessageSubscribeBody: queue=d12fcc51-d697-4385-88f4-37d152ec87b2:0.0; destination=0; accept-mode=1; acquire-mode=0; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {MessageSetFlowModeBody: destination=0; flow-mode=0; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,5] }; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[Bbe; channel=0; {MessageTransferBody: destination=qmf.default.direct; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[be; channel=0; header (183 bytes); properties={{MessageProperties: reply-to={ReplyTo: exchange=qmf.default.direct; routing-key=68c9524a-c7ce-41b0-b7a8-1f16c2e18407; }; content-type=amqp/map; app-id=qmf2; application-headers={qmf.opcode:V2:15:str16(_method_request),qpid.subject:V2:6:str16(broker),x-amqp-0-10.app-id:V2:4:str16(qmf2)}; }{DeliveryProperties: routing-key=broker; }}]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[Ebe; channel=0; content (267 bytes) \x00\x00\x01\x07\x00\x00\x00\x03
_object_id\xA8\x00\x00\x00=\x00\x00\x00\x01 _ob...]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,6] }; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {MessageFlowBody: destination=0; unit=1; value=4294967295; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {MessageFlowBody: destination=0; unit=0; value=1; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[Bbe; channel=0; {MessageTransferBody: destination=0; accept-mode=1; acquire-mode=0; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[be; channel=0; header (151 bytes); properties={{MessageProperties: content-length=28; content-type=amqp/map; app-id=qmf2; application-headers={method:V2:8:str16(response),qmf.agent:V2:6:str16(broker),qmf.opcode:V2:16:str16(_method_response)}; }{DeliveryProperties: routing-key=68c9524a-c7ce-41b0-b7a8-1f16c2e18407; }}]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[Ebe; channel=0; content (28 bytes) \x00\x00\x00\x18\x00\x00\x00\x01
_arguments\xA8\x00\x00\x00\x04\x00\x00\x00\x00]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ExecutionSyncBody: }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,9] }; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {MessageCancelBody: destination=0; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {QueueDeleteBody: queue=d12fcc51-d697-4385-88f4-37d152ec87b2:0.0; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,11] }; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionDetachBody: name=d12fcc51-d697-4385-88f4-37d152ec87b2:0; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {SessionDetachedBody: name=d12fcc51-d697-4385-88f4-37d152ec87b2:0; code=0; }]
2013-05-21 13:44:07 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ConnectionCloseBody: reply-code=200; }]
2013-05-21 13:44:07 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39410]: Frame[BEbe; channel=0; {ConnectionCloseOkBody: }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: INIT(0-10)
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ConnectionStartBody: server-properties={qpid.federation_tag:V2:36:str16(616dacd8-63e0-4f19-801b-bba718aa5a3a)}; mechanisms=str16{V2:5:str16(PLAIN)}; locales=str16{V2:5:str16(en_US)}; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ConnectionStartOkBody: client-properties={platform:V2:5:str16(posix),product:V2:18:str16(qpid python client),qpid.client_pid:F8:int64(20382),qpid.client_ppid:F8:int64(20009),qpid.client_process:V2:9:str16(qpid-ctrl),version:V2:11:str16(development)}; mechanism=PLAIN; response=xxxxxx; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ConnectionTuneBody: channel-max=32767; max-frame-size=65535; heartbeat-min=0; heartbeat-max=120; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ConnectionTuneOkBody: channel-max=32767; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ConnectionOpenBody: }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ConnectionOpenOkBody: known-hosts=str16{}; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionAttachBody: name=8780b5d4-1f23-473a-b040-db82cefa69a0:0; }]
2013-05-21 13:44:26 [Protocol] debug Attached channel 0 to someuser@QPID.8780b5d4-1f23-473a-b040-db82cefa69a0:0
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionCommandPointBody: command-id=0; command-offset=0; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ExchangeQueryBody: name=qmf.default.direct; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {QueueQueryBody: queue=qmf.default.direct; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionAttachedBody: name=8780b5d4-1f23-473a-b040-db82cefa69a0:0; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionCommandPointBody: command-id=0; command-offset=0; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ExecutionResultBody: command-id=0; value=\x07\x01 \x00\x11management-direct\x00\x00\x00\x1A\x00\x00\x00\x01\x0Eqpid.replicate\x95\x00\x04none; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,0] }; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ExecutionResultBody: command-id=1; value=\x08\x01\x00\x00; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,1] }; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {QueueDeclareBody: queue=8780b5d4-1f23-473a-b040-db82cefa69a0:0.0; exclusive=1; auto-delete=1; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ExchangeBindBody: queue=8780b5d4-1f23-473a-b040-db82cefa69a0:0.0; exchange=qmf.default.direct; binding-key=6e74cb0f-3114-46fd-a904-2f8d68778cba; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {MessageSubscribeBody: queue=8780b5d4-1f23-473a-b040-db82cefa69a0:0.0; destination=0; accept-mode=1; acquire-mode=0; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {MessageSetFlowModeBody: destination=0; flow-mode=0; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,5] }; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[Bbe; channel=0; {MessageTransferBody: destination=qmf.default.direct; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[be; channel=0; header (183 bytes); properties={{MessageProperties: reply-to={ReplyTo: exchange=qmf.default.direct; routing-key=6e74cb0f-3114-46fd-a904-2f8d68778cba; }; content-type=amqp/map; app-id=qmf2; application-headers={qmf.opcode:V2:15:str16(_method_request),qpid.subject:V2:6:str16(broker),x-amqp-0-10.app-id:V2:4:str16(qmf2)}; }{DeliveryProperties: routing-key=broker; }}]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[Ebe; channel=0; content (244 bytes) \x00\x00\x00\xF0\x00\x00\x00\x03
_object_id\xA8\x00\x00\x00=\x00\x00\x00\x01 _ob...]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,6] }; }]
2013-05-21 13:44:26 [Protocol] debug my-outgoing-link writing protocol header: 1-0
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {MessageFlowBody: destination=0; unit=1; value=4294967295; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {MessageFlowBody: destination=0; unit=0; value=1; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[Bbe; channel=0; {MessageTransferBody: destination=0; accept-mode=1; acquire-mode=0; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[be; channel=0; header (151 bytes); properties={{MessageProperties: content-length=28; content-type=amqp/map; app-id=qmf2; application-headers={method:V2:8:str16(response),qmf.agent:V2:6:str16(broker),qmf.opcode:V2:16:str16(_method_response)}; }{DeliveryProperties: routing-key=6e74cb0f-3114-46fd-a904-2f8d68778cba; }}]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[Ebe; channel=0; content (28 bytes) \x00\x00\x00\x18\x00\x00\x00\x01
_arguments\xA8\x00\x00\x00\x04\x00\x00\x00\x00]
2013-05-21 13:44:26 [Protocol] debug my-outgoing-link read protocol header: 1-0
2013-05-21 13:44:26 [Protocol] debug my-outgoing-link Received SASL-MECHANISMS(PLAIN)
2013-05-21 13:44:26 [Protocol] debug my-outgoing-link Sent SASL-INIT(PLAIN, \x00someuser\x00somepass, dell03)
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ExecutionSyncBody: }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {MessageCancelBody: destination=0; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {QueueDeleteBody: queue=8780b5d4-1f23-473a-b040-db82cefa69a0:0.0; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,9] }; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionCompletedBody: commands={ [0,11] }; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionDetachBody: name=8780b5d4-1f23-473a-b040-db82cefa69a0:0; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {SessionDetachedBody: name=8780b5d4-1f23-473a-b040-db82cefa69a0:0; code=0; }]
2013-05-21 13:44:26 [Protocol] trace RECV [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ConnectionCloseBody: reply-code=200; }]
2013-05-21 13:44:26 [Protocol] trace SENT [qpid.192.168.102.146:5672-192.168.102.104:39411]: Frame[BEbe; channel=0; {ConnectionCloseOkBody: }]
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscr...@qpid.apache.org
For additional commands, e-mail: users-h...@qpid.apache.org
