On Sun, Feb 12, 2012 at 6:19 AM, Gordon Sim <[email protected]> wrote: > On 02/11/2012 10:07 PM, Brandon Pedersen wrote: >> >> On Sat, Feb 11, 2012 at 11:05 AM, Gordon Sim<[email protected]> wrote: >>> >>> On 02/10/2012 11:38 PM, Brandon Pedersen wrote: >>> Try export QPID_LOG_ENABLE=trace+ in the client console before you run >>> your >>> test... it may be some simple error that isn't getting handled cleanly. >> >> >> Here is the output from running with that: >> 2012-02-11 14:53:38 info Trying to connect to localhost... >> 2012-02-11 14:53:38 debug TCPConnector created for 0-10 >> 2012-02-11 14:53:38 info Connecting: 127.0.0.1:5672 >> 2012-02-11 14:53:38 debug RECV [[127.0.0.1:50491-localhost:5672]]: >> INIT(0-10) >> 2012-02-11 14:53:38 trace RECV [[127.0.0.1:50491-localhost:5672]]: >> Frame[BEbe; channel=0; {ConnectionStartBody: >> >> server-properties={qpid.federation_tag:V2:36:str16(997761a1-4009-442f-8500-850a18324403)}; >> mechanisms=str16{V2:8:str16(AMQPLAIN), V2:5:str16(PLAIN), >> V2:8:str16(CRAM-MD5)}; locales=str16{V2:5:str16(en_US)}; }] >> 2012-02-11 14:53:38 trace SENT [[127.0.0.1:50491-localhost:5672]]: >> Frame[BEbe; channel=0; {ConnectionStartOkBody: >> >> client-properties={qpid.client_pid:F4:int32(13708),qpid.client_ppid:F4:int32(2345),qpid.client_process:V2:6:str16(python),qpid.session_flow:F4:int32(1)}; >> mechanism=; response=xxxxxx; locale=en_US; }] > > > The line above is odd. The mechanism is not specified. It looks like the > cyrus sasl integration is not built into your libs. However, it does seem > that the broker responds to this which would indicate that for whatever > reason it did authenticate successfully, so this may not be relevant to the > issue. > > I have cyrus enabled and see something different. I also see clear errors > being sent in a connection-close for any authentication related problems, > which again suggests the oddness above is not the issue here. > > >> 2012-02-11 14:53:38 trace RECV [[127.0.0.1:50491-localhost:5672]]: >> Frame[BEbe; channel=0; {ConnectionTuneBody: channel-max=256; >> max-frame-size=65535; heartbeat-min=0; heartbeat-max=0; }] >> 2012-02-11 14:53:38 trace SENT [[127.0.0.1:50491-localhost:5672]]: >> Frame[BEbe; channel=0; {ConnectionTuneOkBody: channel-max=256; >> max-frame-size=65535; heartbeat=0; }] >> 2012-02-11 14:53:38 trace SENT [[127.0.0.1:50491-localhost:5672]]: >> Frame[BEbe; channel=0; {ConnectionOpenBody: virtual-host=; >> capabilities=void{}; insist=1; }] >> 2012-02-11 14:53:39 trace RECV [[127.0.0.1:50491-localhost:5672]]: >> Frame[BEbe; channel=0; {ConnectionOpenOkBody: known-hosts=void{}; }] >> 2012-02-11 14:53:39 debug Known-brokers for connection: >> 2012-02-11 14:53:39 info Connection [127.0.0.1:50491-localhost:5672] >> connected to tcp:localhost:5672 >> 2012-02-11 14:53:39 debug Connection [127.0.0.1:50491-localhost:5672] >> no security layer in place >> 2012-02-11 14:53:39 info Connected to localhost >> 2012-02-11 14:53:39 debug Added known-hosts, reconnect-urls=[localhost] >> 2012-02-11 14:53:39 debug SessionState::SessionState .: 0x7f9ba4001178 >> 2012-02-11 14:53:39 trace SENT [[127.0.0.1:50491-localhost:5672]]: >> Frame[BEbe; channel=1; {SessionAttachBody: >> name=3892ce4f-42ad-4acb-b015-769382ec726d; }] >> 2012-02-11 14:53:39 warning Connection [127.0.0.1:50491-localhost:5672] >> closed >> 2012-02-11 14:53:39 debug Exception constructed: Connection >> [127.0.0.1:50491-localhost:5672] closed >> 2012-02-11 14:53:39 debug Exception constructed: Connection >> [127.0.0.1:50491-localhost:5672] closed >> >> Doesn't really appear much more helpful other than that it says there >> is an exception of some kind. > > > I think that is just in response to the connection being closed. > > >> I just did a quick trace with wireshark and it also shows the same >> sequence but I noticed something that may be a little strange, the >> sequence goes like this: >> ....some setup... >> connection.start-ok (client -> server) >> connection.tune (server -> client) >> connection.tune-ok connection.open (client -> server) >> connection.open-ok [Malformed packet] -- it says an exception >> occurred here but I don't see any extra data, and this was from server >> -> client >> What is also weird is that the client now sends a session.open command >> and the server responds and resets the connections with FIN, ACK, >> supposedly since there was an error with the previous command > > > The supposedly malformed frame seems to make it ok to the client. Is there > anything in the network of your virtual env that could be causing problems? > What happens if you try to connect with the c++ client itself (e.g. using > one of the test programs or examples)?
OK, I tried using the C++ messaging spout program and got the same error. I realized I hadn't installed libsasl2-dev on this machine which is probably why you saw that the sasl libs weren't there. So I installed them and recompiled but now I am getting a different exception: 2012-02-13 11:05:21 warning Closing connection due to internal-error: Sasl error: SASL(-4): no mechanism available: No worthy mechs found (qpid/SaslFactory.cpp:280) internal-error: Sasl error: SASL(-4): no mechanism available: No worthy mechs found (qpid/SaslFactory.cpp:280) I don't have a great understanding of SASL and not sure what this means or how to fix it... Thanks, -Brandon --------------------------------------------------------------------- Apache Qpid - AMQP Messaging Implementation Project: http://qpid.apache.org Use/Interact: mailto:[email protected]
