Description of problem: Having a 3.1 (or also 3.0) C++ client using DIGEST-MD5 SASL mechanism over AMQP 1.0, it fails to consume messages from 3.2 broker. Version-Release number of selected component (if applicable): client: qpid-cpp-client-0.30-8.el6.x86_64 broker: qpid-cpp-server-0.34-5.el6.x86_64 How reproducible: 100% Steps to Reproduce: 1. On one machine, run 3.2 broker with DIGEST-MD5 and PLAIN and ANONYMOUS mechs enabled, and with admin/admin credentials set 2. On another machine, create a queue, send there 1000 messages and try to consume them over AMQP1.0 with DIGEST-MD5: qpid-config add queue test2 -b mrg32broker qpid-send -b admin/admin@mrg32broker -a "test2; { node: { type: queue} }" -m 1000 export QPID_LOG_ENABLE="trace+" qpid-receive -b admin/admin@mrg32broker --connection-options "{ protocol: amqp1.0, sasl-mechanism:'DIGEST-MD5' }" -a "test2; { node: { type: queue } , assert: never}" Actual results: qpid-receive stucks with trace log: 2015-10-06 09:56:35 [Protocol] trace [3eb23c9a-d498-4f7d-98c3-6eec80ebae2e]: 0 <- @attach(18) [name="test2_150f23c5-f629-4b2d-9bef-09c8f0fd7689", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="test2", durable=0, timeout=0, dynamic=false, distribution-mode=:move, capabilities=:queue], target=@target(41) [durable=0, timeout=0, dynamic=false], initial-delivery-count=0] 2015-10-06 09:56:35 [Network] debug tcp:train1:5672 decoded 138 bytes from 138 2015-10-06 09:56:35 [Messaging] debug Attach succeeded from test2 2015-10-06 09:56:35 [Messaging] debug wakeupDriver() 2015-10-06 09:56:35 [Security] trace tcp:train1:5672 Sasl::canEncode(): 0 || 0 2015-10-06 09:56:35 [Security] trace tcp:train1:5672 Sasl::canEncode(): 0 || 0 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 encode(65535) 2015-10-06 09:56:35 [Protocol] trace [3eb23c9a-d498-4f7d-98c3-6eec80ebae2e]: 0 -> @flow(19) [next-incoming-id=0, incoming-window=2147483647, next-outgoing-id=0, outgoing-window=0, handle=0, delivery-count=0, link-credit=1000, drain=false] 2015-10-06 09:56:35 [Network] debug tcp:train1:5672 encoded 42 bytes from 65535 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 encode(65535) 2015-10-06 09:56:35 [Messaging] debug In ConnectionContext::get(), current=0 2015-10-06 09:56:35 [Messaging] debug wakeupDriver() 2015-10-06 09:56:35 [Messaging] debug Waiting for message or for credit to be drained: credit=1000, queued=0 2015-10-06 09:56:35 [Security] trace tcp:train1:5672 Sasl::canEncode(): 0 || 0 2015-10-06 09:56:35 [Security] trace tcp:train1:5672 Sasl::canEncode(): 0 || 0 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 encode(65535) 2015-10-06 09:56:35 [Protocol] trace [3eb23c9a-d498-4f7d-98c3-6eec80ebae2e]: 0 -> @flow(19) [next-incoming-id=0, incoming-window=2147483647, next-outgoing-id=0, outgoing-window=0, handle=0, delivery-count=0, link-credit=1000, drain=true] 2015-10-06 09:56:35 [Network] debug tcp:train1:5672 encoded 42 bytes from 65535 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 encode(65535) 2015-10-06 09:56:35 [Security] trace tcp:train1:5672 Sasl::canEncode(): 0 || 0 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 decode(0) 2015-10-06 09:56:35 [Protocol] trace [3eb23c9a-d498-4f7d-98c3-6eec80ebae2e]: 0 -> @close(24) [error=@error(29) [condition=:"amqp:connection:framing-error", description="connection aborted"]] 2015-10-06 09:56:35 [Protocol] trace [3eb23c9a-d498-4f7d-98c3-6eec80ebae2e]: <- EOS 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 decode(0) 2015-10-06 09:56:35 [Protocol] trace [3eb23c9a-d498-4f7d-98c3-6eec80ebae2e]: <- EOS 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 decode(0) 2015-10-06 09:56:35 [Protocol] trace [3eb23c9a-d498-4f7d-98c3-6eec80ebae2e]: <- EOS 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 decode(65506) 2015-10-06 09:56:35 [Network] debug tcp:train1:5672 decoded 65506 bytes from 65506 2015-10-06 09:56:35 [Messaging] debug Waiting for message or for credit to be drained: credit=1000, queued=0 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 decode(29) 2015-10-06 09:56:35 [Network] debug tcp:train1:5672 decoded 29 bytes from 29 2015-10-06 09:56:35 [Messaging] debug Waiting for message or for credit to be drained: credit=1000, queued=0 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 decode(0) 2015-10-06 09:56:35 [Protocol] trace [3eb23c9a-d498-4f7d-98c3-6eec80ebae2e]: <- EOS 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 decode(0) 2015-10-06 09:56:35 [Protocol] trace [3eb23c9a-d498-4f7d-98c3-6eec80ebae2e]: <- EOS 2015-10-06 09:56:35 [Messaging] trace tcp:train1:5672 decode(31932) 2015-10-06 09:56:35 [Network] debug tcp:train1:5672 decoded 31932 bytes from 31932 2015-10-06 09:56:35 [Messaging] debug Waiting for message or for credit to be drained: credit=1000, queued=0 Expected results: qpid-receive to successfully consume messages Additional info: 1) Test variants: - using 3.1 client against 3.2 broker: fails, using 3.2 client: succeeds - using PLAIN, ANONYMOUS or even CRAM-MD5 authentication: succeeds - if queue has <100 messages (and never had 1000 or more), test succeeds 2) Key observation: log records 2015-10-06 09:56:35 [Messaging] debug In ConnectionContext::get(), current=0 2015-10-06 09:56:35 [Messaging] debug wakeupDriver() 2015-10-06 09:56:35 [Messaging] debug Waiting for message or for credit to be drained: credit=1000, queued=0 should appear before sending AMQP flow performative with drain=false and this flow is not expected to be sent by the client (just flow with drain=true should be there). At least any successful test had that. I.e. it sounds like a concurrency bug where DIGEST-MD5 mechanism causes proton(?) driver to wake up too late.