You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@qpid.apache.org by "Keith Wall (JIRA)" <ji...@apache.org> on 2016/05/12 05:59:12 UTC
[jira] [Comment Edited] (QPID-7259)
qpid_tests.broker_0_10.message.MessageTests.test_window_flow_messages
occasionally fails against the Java Broker
[ https://issues.apache.org/jira/browse/QPID-7259?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15281234#comment-15281234 ]
Keith Wall edited comment on QPID-7259 at 5/12/16 5:58 AM:
-----------------------------------------------------------
It appears the test tries to control the completions manually, but there is a TODO left in the test code (Line 487), but it appears that something else (messaging itself??) is doing the completions too.
was (Author: k-wall):
It appears the test tries to control the completions manually, but there is a TODO left in the test code (Line 487), but it appears that something else (messaging itself??) is doing the completions too.
> qpid_tests.broker_0_10.message.MessageTests.test_window_flow_messages occasionally fails against the Java Broker
> ----------------------------------------------------------------------------------------------------------------
>
> Key: QPID-7259
> URL: https://issues.apache.org/jira/browse/QPID-7259
> Project: Qpid
> Issue Type: Bug
> Components: Python Test Suite
> Reporter: Keith Wall
> Priority: Minor
>
> Running {{qpid_tests.broker_0_10.message.MessageTests.test_window_flow_messages}} against the Java Broker (trunk), I occasionally see the following failure:
> {noformat}
> qpid_tests.broker_0_10.message.MessageTests.test_window_flow_messages ........................................................................................................................................................................... fail
> Error during test: Traceback (most recent call last):
> File "/Users/keith/py/bin/qpid-python-test", line 340, in run
> phase()
> File "/Users/keith/py/lib/python2.7/site-packages/qpid_tests/broker_0_10/message.py", line 489, in test_window_flow_messages
> self.assertEmpty(q)
> File "/Users/keith/py/lib/python2.7/site-packages/qpid_tests/broker_0_10/message.py", line 1109, in assertEmpty
> self.fail("Queue not empty, contains: " + extra.body)
> File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/unittest/case.py", line 412, in fail
> raise self.failureException(msg)
> AssertionError: Queue not empty, contains: Message 6
> {noformat}
> Turning debug on, you can see on the failing case, the client side emits an additional SessionCompleted(commands=[0, 0]), allowing the Broker to legitimately send message 6. In the passing case the SessionCompleted(commands=null) is sent instead.
> The failing case:
> {noformat}
> 016-05-11 23:16:16,341 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - RECV: [conn:6be9e091] ch=1 [S] MessageFlow(destination=c, unit=MESSAGE, value=5)
> 2016-05-11 23:16:16,341 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Session) - identify: ch=1, commandId=13
> 2016-05-11 23:16:16,341 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Session) - ssn:"test-session" ch=1 processed([13,13]) 12 12
> 2016-05-11 23:16:16,341 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Session) - ssn:"test-session" processed: {[0, 12]}
> 2016-05-11 23:16:16,341 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - SEND: [conn:6be9e091] ch=1 SessionCompleted(commands={[0, 13]})
> 2016-05-11 23:16:16,341 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - FLUSH: [conn:6be9e091]
> 2016-05-11 23:16:16,341 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Written 26 bytes
> 2016-05-11 23:16:16,341 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Read 0 byte(s)
> 2016-05-11 23:16:16,342 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Read 25 byte(s)
> 2016-05-11 23:16:16,342 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - RECV: [conn:6be9e091] ch=1 [S] MessageFlow(destination=c, unit=BYTE, value=4294967295)
> 2016-05-11 23:16:16,342 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Session) - identify: ch=1, commandId=14
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Session) - ssn:"test-session" ch=1 processed([14,14]) 13 13
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Session) - ssn:"test-session" processed: {[0, 13]}
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - SEND: [conn:6be9e091] ch=1 SessionCompleted(commands={[0, 14]})
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - FLUSH: [conn:6be9e091]
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Written 26 bytes
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Read 0 byte(s)
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - SEND: [conn:6be9e091] ch=1 SessionCommandPoint(commandId=0, commandOffset=0)
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - FLUSH: [conn:6be9e091]
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - SEND: [conn:6be9e091] ch=1 id=0 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 1"
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - SEND: [conn:6be9e091] ch=1 SessionFlush(completed=true)
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - FLUSH: [conn:6be9e091]
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - SEND: [conn:6be9e091] ch=1 id=1 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 2"
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - SEND: [conn:6be9e091] ch=1 id=2 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 3"
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - SEND: [conn:6be9e091] ch=1 id=3 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 4"
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - SEND: [conn:6be9e091] ch=1 id=4 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 5"
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Read 0 byte(s)
> 2016-05-11 23:16:16,343 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Written 369 bytes
> 2016-05-11 23:16:16,345 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Read 26 byte(s)
> 2016-05-11 23:16:16,345 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - RECV: [conn:6be9e091] ch=1 SessionCompleted(commands=[0, 0])
> 2016-05-11 23:16:16,345 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Session) - ssn:"test-session" complete(0, 0)
> 2016-05-11 23:16:16,345 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Session) - ssn:"test-session" commands remaining: 5
> 2016-05-11 23:16:16,345 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Read 0 byte(s)
> 2016-05-11 23:16:16,345 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.t.Connection) - SEND: [conn:6be9e091] ch=1 id=5 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 6"
> 2016-05-11 23:16:16,345 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Read 0 byte(s)
> 2016-05-11 23:16:16,345 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Written 65 bytes
> 2016-05-11 23:16:16,346 DEBUG [IO-/0:0:0:0:0:0:0:1:54458] (o.a.q.s.t.NonBlockingConnection) - Read 30 byte(s)
> {noformat}
> A passing case:
> {noformat}
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - RECV: [conn:287b2153] ch=1 [S] MessageFlow(destination=c, unit=BYTE, value=4294967295)
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Session) - identify: ch=1, commandId=14
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Session) - ssn:"test-session" ch=1 processed([14,14]) 13 13
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Session) - ssn:"test-session" processed: {[0, 13]}
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - SEND: [conn:287b2153] ch=1 SessionCompleted(commands={[0, 14]})
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - FLUSH: [conn:287b2153]
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.s.t.NonBlockingConnection) - Written 26 bytes
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.s.t.NonBlockingConnection) - Read 0 byte(s)
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - SEND: [conn:287b2153] ch=1 SessionCommandPoint(commandId=0, commandOffset=0)
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - FLUSH: [conn:287b2153]
> 2016-05-11 23:16:13,660 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - SEND: [conn:287b2153] ch=1 id=0 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 1"
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - SEND: [conn:287b2153] ch=1 SessionFlush(completed=true)
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - FLUSH: [conn:287b2153]
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - SEND: [conn:287b2153] ch=1 id=1 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 2"
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - SEND: [conn:287b2153] ch=1 id=2 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 3"
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - SEND: [conn:287b2153] ch=1 id=3 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 4"
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - SEND: [conn:287b2153] ch=1 id=4 [B] MessageTransfer(destination=c, acceptMode=EXPLICIT, acquireMode=PRE_ACQUIRED)
> DeliveryProperties(routingKey=q)
> body="Message 5"
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.s.t.NonBlockingConnection) - Read 0 byte(s)
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.s.t.NonBlockingConnection) - Written 369 bytes
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.s.t.NonBlockingConnection) - Read 18 byte(s)
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - RECV: [conn:287b2153] ch=1 SessionCompleted(commands=null)
> 2016-05-11 23:16:13,661 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.s.t.NonBlockingConnection) - Read 0 byte(s)
> 2016-05-11 23:16:14,664 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.s.t.NonBlockingConnection) - Read 26 byte(s)
> 2016-05-11 23:16:14,664 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Connection) - RECV: [conn:287b2153] ch=1 SessionCompleted(commands=[0, 4])
> 2016-05-11 23:16:14,664 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Session) - ssn:"test-session" complete(0, 4)
> 2016-05-11 23:16:14,664 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.t.Session) - ssn:"test-session" commands remaining: 1
> 2016-05-11 23:16:14,664 DEBUG [IO-/0:0:0:0:0:0:0:1:54457] (o.a.q.s.t.NonBlockingConnection) - Read 0 byte(s)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@qpid.apache.org
For additional commands, e-mail: dev-help@qpid.apache.org