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/12/15 16:13:59 UTC
[jira] [Comment Edited] (QPIDJMS-239) Client ack session
occasionally seen to redeliver recovered messages out of order
[ https://issues.apache.org/jira/browse/QPIDJMS-239?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15751756#comment-15751756 ]
Keith Wall edited comment on QPIDJMS-239 at 12/15/16 4:13 PM:
--------------------------------------------------------------
I've attached two examples. The pattern I see can be summarised with a grep. The point the unexpected message appears seems to vary.
{noformat}
grep 'delivery dispatcher' TEST-org.apache.qpid.test.unit.ack.RecoverTest.testOrderingWithAsyncConsumer_0.20.0.txt
2016-12-15 15:58:48,531 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 0 and calling recover
2016-12-15 15:58:48,532 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 0 and calling recover
2016-12-15 15:58:48,533 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 0 and calling recover
2016-12-15 15:58:48,533 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 0 and calling recover
2016-12-15 15:58:48,534 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 0 and calling recover
2016-12-15 15:58:48,536 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Acknowledging message 0
2016-12-15 15:58:48,537 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 1 and calling recover
2016-12-15 15:58:48,540 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 1 and calling recover
2016-12-15 15:58:48,542 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 1 and calling recover
# Qpid JMS Client delivers 7th message rather than redelivering the 1st
2016-12-15 15:58:48,546 ERROR [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.InternalBrokerHolder Uncaught exception from thread JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher
junit.framework.AssertionFailedError: Received Message Out Of Order expected:<1> but was:<7>
{noformat}
was (Author: k-wall):
I've attached two examples. The pattern I see can be summarised with a grep. The point the unexpected message appears seems to vary.
{format}
grep 'delivery dispatcher' TEST-org.apache.qpid.test.unit.ack.RecoverTest.testOrderingWithAsyncConsumer_0.20.0.txt
2016-12-15 15:58:48,531 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 0 and calling recover
2016-12-15 15:58:48,532 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 0 and calling recover
2016-12-15 15:58:48,533 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 0 and calling recover
2016-12-15 15:58:48,533 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 0 and calling recover
2016-12-15 15:58:48,534 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 0 and calling recover
2016-12-15 15:58:48,536 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Acknowledging message 0
2016-12-15 15:58:48,537 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 1 and calling recover
2016-12-15 15:58:48,540 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 1 and calling recover
2016-12-15 15:58:48,542 DEBUG [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.a.RecoverTest Ignoring message 1 and calling recover
# Qpid JMS Client delivers 7th message rather than redelivering the 1st
2016-12-15 15:58:48,546 ERROR [JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher] o.a.q.t.u.InternalBrokerHolder Uncaught exception from thread JmsSession [ID:f702629f-cc27-4366-87a7-55c52282b0cf:1:1] delivery dispatcher
junit.framework.AssertionFailedError: Received Message Out Of Order expected:<1> but was:<7>
{format}
> Client ack session occasionally seen to redeliver recovered messages out of order
> ---------------------------------------------------------------------------------
>
> Key: QPIDJMS-239
> URL: https://issues.apache.org/jira/browse/QPIDJMS-239
> Project: Qpid JMS
> Issue Type: Bug
> Components: qpid-jms-client
> Affects Versions: 0.11.0, 0.20.0
> Reporter: Keith Wall
> Attachments: TEST-org.apache.qpid.test.unit.ack.RecoverTest.testOrderingWithAsyncConsumer.txt, TEST-org.apache.qpid.test.unit.ack.RecoverTest.testOrderingWithAsyncConsumer_0.20.0.txt
>
>
> Test org.apache.qpid.test.unit.ack.RecoverTest#testOrderingWithAsyncConsumer [1] fails occasional when run against the Java Broker. The test publishes a number of messages then uses an async message listener to consume them. For each message, the message listener recovers the session five times before finally acknowledging the message, then the cycle repeats. In failure case, I see the Qpid JMS Client delivery an unexpected message to the application after a sequence of expected.
> We have seen the failure on the Apache CI and I can reproduce the problem on my laptop (every 15-20 runs of the test).
> https://builds.apache.org/view/M-R/view/Qpid/job/Qpid-Java-Java-MMS-1.0/40/artifact/trunk/systests/target/surefire-reports/java-mms.1-0/TEST-org.apache.qpid.test.unit.ack.RecoverTest.testOrderingWithAsyncConsumer.txt
> I have reproduced locally against 0.20.0 too.
--
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