[QPID-8058] [Broker-J][AMQP 1.0] Broker does not respond to drain request from consumer of management temporary destination

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: qpid-java-broker-7.0.0
• Fix Version/s: qpid-java-broker-7.0.1
• Component/s: Broker-J
• Assignee: Keith Wall
• Reporter: Alex Rudyy
• Created: 06/Dec/17 15:59
• Updated: 08/Feb/18 21:26
• Resolved: 08/Jan/18 15:26

Description

Test AmqpManagementTest.testCreateQueueOnBrokerManagement failed with the following error:

org.apache.qpid.jms.JmsOperationTimedOutException: Remote did not respond to a drain request in time

As per exception message, the client sent the Flow with drain=true but Broker did not reply on it

2017-12-05 18:20:13,950          DEBUG [IO-/127.0.0.1:48726] o.a.q.s.p.frame RECV[/127.0.0.1:48726|1] : Flow{nextIncomingId=0,incomingWindow=2047,nextOutgoingId=2,outgoingWindow=2147483647,handle=0,deliveryCount=0,linkCredit=1000,drain=true}

See the test log attached.

Broker-J does not respond on flow performative with drain flag coming from consumers of temporary destinations created on management nodes ($management).

Test attached receiver link for temporary destination created on management mode:

2017-12-05 18:20:11,760          DEBUG [IO-/127.0.0.1:48726] o.a.q.s.p.frame RECV[/127.0.0.1:48726|1] : Attach{name=qpid-jms:receiver:ID:0ea0fec9-455c-47db-b15e-4fd09c0c48d6:1:1:1:TempQueuecdf2fb78-beda-4456-9e2c-dd2dd4d9a53e,handle=0,role=receiver,sndSettleMode=unsettled,rcvSettleMode=first,source=Source{address=TempQueuecdf2fb78-beda-4456-9e2c-dd2dd4d9a53e,durable=none,expiryPolicy=link-detach,timeout=0,dynamic=false,defaultOutcome=Modified{deliveryFailed=true},outcomes=[amqp:accepted:list, amqp:rejected:list, amqp:released:list, amqp:modified:list],capabilities=[temporary-queue]},target=Target{}}
2017-12-05 18:20:11,763          DEBUG [IO-/127.0.0.1:48726] o.a.q.s.p.frame SEND[/127.0.0.1:48726|1] : Attach{name=qpid-jms:receiver:ID:0ea0fec9-455c-47db-b15e-4fd09c0c48d6:1:1:1:TempQueuecdf2fb78-beda-4456-9e2c-dd2dd4d9a53e,handle=0,role=sender,sndSettleMode=unsettled,rcvSettleMode=first,source=Source{address=TempQueuecdf2fb78-beda-4456-9e2c-dd2dd4d9a53e,durable=none,expiryPolicy=link-detach,dynamic=false,defaultOutcome=Modified{deliveryFailed=true},outcomes=[amqp:accepted:list, amqp:released:list, amqp:rejected:list],capabilities=[]},target=Target{},unsettled={},initialDeliveryCount=0,offeredCapabilities=[SHARED-SUBS],properties={}}

Granted credit

2017-12-05 18:20:11,765          DEBUG [IO-/127.0.0.1:48726] o.a.q.s.p.frame RECV[/127.0.0.1:48726|1] : Flow{nextIncomingId=0,incomingWindow=2047,nextOutgoingId=1,outgoingWindow=2147483647,handle=0,deliveryCount=0,linkCredit=1000}

Broker sent Transfer

2017-12-05 18:20:13,949          DEBUG [IO-/127.0.0.1:48726] o.a.q.s.p.frame SEND[/127.0.0.1:48726|1] : Transfer{handle=0,deliveryId=0,deliveryTag=\x00\x00\x00\x00\x00\x00\x00\x00,messageFormat=0}

and immediately after transfer received Flow with drain=true

2017-12-05 18:20:13,950          DEBUG [IO-/127.0.0.1:48726] o.a.q.s.p.frame RECV[/127.0.0.1:48726|1] : Flow{nextIncomingId=0,incomingWindow=2047,nextOutgoingId=2,outgoingWindow=2147483647,handle=0,deliveryCount=0,linkCredit=1000,drain=true}

There was no message left on message source but broker did not send flow back.

The existing implementation of ManagementNode#pullMessage does not notify its ConsumerTarget when there is no messages left to send.

Only users of AMQP management are affected by the bug.