[
https://issues.apache.org/jira/browse/ARTEMIS-2659?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17078349#comment-17078349
]
Timothy A. Bish commented on ARTEMIS-2659:
------------------------------------------
Another one that has happened once so far
Failed tests:
JMSMessageGroupsTest.testMessageGroupsAMQPProducerAMQPConsumer:79->testMessageGroups:126->testGroupFirst:231->readMessagesOnBroker:286->Assert.assertEquals:555->Assert.assertEquals:118->Assert.failNotEquals:743->Assert.fail:88
Sequence order should match expected:<11> but was:<12>
> AMQP integration test instabilities, failure to deliver messages, etc
> ---------------------------------------------------------------------
>
> Key: ARTEMIS-2659
> URL: https://issues.apache.org/jira/browse/ARTEMIS-2659
> Project: ActiveMQ Artemis
> Issue Type: Bug
> Components: AMQP
> Affects Versions: 2.12.0
> Reporter: Robbie Gemmell
> Assignee: Clebert Suconic
> Priority: Blocker
> Fix For: 2.12.0
>
> Time Spent: 0.5h
> Remaining Estimate: 0h
>
> Changes in the last few weeks seem to have destabilised the AMQP integration
> tests on master. I often run these as part of testing out Qpid JMS changes
> and releases (by running e.g: mvn clean install -DskipTests && cd
> tests/integration-tests/ && mvn -Ptests
> -Dtest=org.apache.activemq.artemis.tests.integration.amqp.* test). I ran them
> on February 24th without issue while doing the Qpid JMS 0.49.0 release, but
> now I see repeated failures in various tests (either with the 0.45.0 client
> currently used by Artemis, or updated with the 0.49.0 release that worked
> fine before, or updated with the 0.50.0 release that tests fine with the
> Artemis 2.11.0 codebase).
> I often see AmqpLargeMessageTest fail. In particular, usually
> testSendFixedSizedMessages and/or testSendSmallerMessages. I also see some
> unexpected exceptions during test runs. I also noticed an odd behaviour in a
> passing AmqpLargeMessageTest run that may relate to some of the others.
> I decided to detail these all here in 1 JIRA as I think they may relate to or
> be interactions of more than one change, e.g perhaps these amongst others:
> [https://github.com/apache/activemq-artemis/pull/2986]
> https://issues.apache.org/jira/browse/ARTEMIS-1975
> [https://github.com/apache/activemq-artemis/pull/3012]
> https://issues.apache.org/jira/browse/ARTEMIS-2642
> [https://github.com/apache/activemq-artemis/pull/3019]
> https://issues.apache.org/jira/browse/ARTEMIS-2658
> https://issues.apache.org/jira/browse/ARTEMIS-2617
>
> Below is a quick overview of the test failures or issues I see:
> =====================
> Essentially some of the AmqpLargeMessageTest tests (usually
> testSendFixedSizedMessages and/or testSendSmallerMessages) times out with the
> client waiting for a message that never arrives.
> In this case for AmqpLargeMessageTest # testSendFixedSizedMessages it seems
> like it was the second sub-run, "doTestSendLargeMessage(65536 * 2);", which
> is I think the first the broker considers 'large'.
> Running with protocol trace showed in this case the client sent a message to
> the broker, then tried to consume it, and the client and broker then sit
> heartbeating each other with no sign an outgoing Transfer was generated by
> the broker. As the test is using a receive-without-timeout call, it sits
> there until the test itself times out.
> {noformat}
> [588596832:1] ->
> Attach{name='qpid-jms:sender:ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1:testSendFixedSizedMessages',
> handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
> source=Source{address='ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1',
> durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false,
> dynamicNodeProperties=null, distributionMode=null, filter=null,
> defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list,
> amqp:released:list, amqp:modified:list], capabilities=null},
> target=Target{address='testSendFixedSizedMessages', durable=NONE,
> expiryPolicy=SESSION_END, timeout=0, dynamic=false,
> dynamicNodeProperties=null, capabilities=[queue]}, unsettled=null,
> incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null,
> offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [734665003:1] <-
> Attach{name='qpid-jms:sender:ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1:testSendFixedSizedMessages',
> handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
> source=Source{address='ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1',
> durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false,
> dynamicNodeProperties=null, distributionMode=null, filter=null,
> defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list,
> amqp:released:list, amqp:modified:list], capabilities=null},
> target=Target{address='testSendFixedSizedMessages', durable=NONE,
> expiryPolicy=SESSION_END, timeout=0, dynamic=false,
> dynamicNodeProperties=null, capabilities=[queue]}, unsettled=null,
> incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=null,
> offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [734665003:1] ->
> Attach{name='qpid-jms:sender:ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1:testSendFixedSizedMessages',
> handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
> source=Source{address='ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1',
> durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false,
> dynamicNodeProperties=null, distributionMode=null, filter=null,
> defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list,
> amqp:released:list, amqp:modified:list], capabilities=null},
> target=Target{address='testSendFixedSizedMessages', durable=NONE,
> expiryPolicy=SESSION_END, timeout=0, dynamic=false,
> dynamicNodeProperties=null, capabilities=[queue]}, unsettled=null,
> incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null,
> offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [734665003:1] -> Flow{nextIncomingId=1, incomingWindow=2147483647,
> nextOutgoingId=1, outgoingWindow=2147483647, handle=0, deliveryCount=0,
> linkCredit=1000, available=null, drain=false, echo=false, properties=null}
> [588596832:1] <-
> Attach{name='qpid-jms:sender:ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1:testSendFixedSizedMessages',
> handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
> source=Source{address='ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1',
> durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false,
> dynamicNodeProperties=null, distributionMode=null, filter=null,
> defaultOutcome=null, outcomes=[amqp:accepted:list, amqp:rejected:list,
> amqp:released:list, amqp:modified:list], capabilities=null},
> target=Target{address='testSendFixedSizedMessages', durable=NONE,
> expiryPolicy=SESSION_END, timeout=0, dynamic=false,
> dynamicNodeProperties=null, capabilities=[queue]}, unsettled=null,
> incompleteUnsettled=false, initialDeliveryCount=null, maxMessageSize=null,
> offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [588596832:1] <- Flow{nextIncomingId=1, incomingWindow=2147483647,
> nextOutgoingId=1, outgoingWindow=2147483647, handle=0, deliveryCount=0,
> linkCredit=1000, available=null, drain=false, echo=false, properties=null}
> [588596832:1] -> Transfer{handle=0, deliveryId=0, deliveryTag=\x00,
> messageFormat=0, settled=false, more=true, rcvSettleMode=null, state=null,
> resume=false, aborted=false, batchable=false} (131050)
> "\x00Sr\xc1)\x04\xa3\x0ex-opt-jms-destQ\x00\xa3\x12x-opt-jms-msg-typeQ\x03\x00Ss\xd0\x00\x00\x00z\x00\x00\x00\x0a\xa1/ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1-1@\xa1\x1atestSendFixedSizedMessages@@@\xa3\x18application/octet-stream@@\x83\x00\x00\x01p\xe2\xfez<\x00Su\xb0\x00\x02\x00\x00\xabFe\xdc]\x0d\xb1\xd5\x86\xa2\xd0X8\xbe\x13q\x06}\x9c\x9b\xfc\xb4~&\xb1\xf9\xfc_QM"\x9a\x83\x01^\x0cH\x98\x1dPg8+D\x81V\xcf\xaa{\x8dY\x8f\xea\x01b\x0c\xd5\x9d\xf1A>\xd5\xe2-\xc3\x9c\xf0\xc1\xd2("?\x95\xd3&\xeb\xe7t!c\x16\xea\x1dt\xf9o\xca\x95\xd0-\xb2\xd1\xcd8\xa7\x02\x07\x89\xd0HM\x04\xb3\xa69\xba\x8c\xa5.&_\xc6s\x1a\x16*\x93\x13\xdd\xdb\x91\xd6\xf40\x8e\x18\xf4S\xce\xea\xa7+i\xda\xef\xa1\x9b\x13\x06\xad47\xb1\xe7\xd1\x04\xa6O\xbe=\xaa\xa4\xb9\xc1.S\xc4\xdc\x1a\xd8Vv\xb1T]\xb1*\x0e\x8b_	\xcbD\xf0sc\x89\xa3l\x90\xa2\x1aV\xb5xP\xac\xfb*\x0f\x1d\x97\xfd\xcc\xfb<ul\x0ck\xba\xc9\xbeu\x91\xab\xe3\xb7\xd7T\xfd\xa1\xcf\xfb(_\xf5\xb8\x8b\xf36
>
> \x8aN\xe4\xb0H\xf0%\x80\xcf\x0c\xef\x13s=G\xdd\x9d;\x81\xb1~\xafD\xc2\xe1\xb9Kx$}\x7f"...(truncated)
> [588596832:1] -> Transfer{handle=0, deliveryId=0, deliveryTag=\x00,
> messageFormat=0, settled=false, more=false, rcvSettleMode=null, state=null,
> resume=false, aborted=false, batchable=false} (206)
> "=?\xedxH\xef\xa8\xd1\xcc\xf5\xc3\xa0N\xdc\xab\xbe\xeb\x96\x94\xdcwD\x03R\xd9\xd4\xbd\xcd\xb6\x82\x90\x99/\xc4\x133(\xca-a@\xf9\xbb\xe6\xfeF\xd4\xb9\xcc\xbeG<\x9b\xde\x8ec\xb3\x85q\x1f\xf3rR\xac\xd9\xe9\xf7\x0cxP\xcaY+j\xd9\x02\xd0\x94.\x0b\x8dQ<\x15\x16\x09\x0f>\x94\x13\xb4\x98\xbc$\xf7-\xed\xc5\x98\x1e\xe4\xb46k\x02>Vd\xb7\xe4\x1e\x8bt\xe0K\xffVV\x1bZ(\xf7\xff)\xf1\x0c\xe0Q\x0e
>
> \xcc>\xfb+\xe6|\xfc,?\xb2\xcf\xab\xeb\xf2\xfd\x89\x82\xe3\x997/\x05\xc7H\x17\x175\xe1C\xbcnx\x17\x19\x83W\x1f\xde\x12\xbc\xe7<\xbb\xc8?\xb9\xeb\xa2\x09\x87\x84\xd2\x07\x1b'\x81Sw\xf2:\xaam\xe4jE[\x01\xa4\x19\xae\x11\xdf\xa9\xa3\xe5\xc3"
> [588596832:1] ->
> Attach{name='qpid-jms:receiver:ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1:testSendFixedSizedMessages',
> handle=1, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
> source=Source{address='testSendFixedSizedMessages', durable=NONE,
> expiryPolicy=LINK_DETACH, timeout=0, dynamic=false,
> dynamicNodeProperties=null, distributionMode=null, filter=null,
> defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=null,
> messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list,
> amqp:released:list, amqp:modified:list], capabilities=[queue]},
> target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END,
> timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null},
> unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null,
> maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null,
> properties=null}
> [734665003:1] <- Transfer{handle=0, deliveryId=0, deliveryTag=\x00,
> messageFormat=0, settled=false, more=true, rcvSettleMode=null, state=null,
> resume=false, aborted=false, batchable=false} (131050)
> "\x00Sr\xc1)\x04\xa3\x0ex-opt-jms-destQ\x00\xa3\x12x-opt-jms-msg-typeQ\x03\x00Ss\xd0\x00\x00\x00z\x00\x00\x00\x0a\xa1/ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1-1@\xa1\x1atestSendFixedSizedMessages@@@\xa3\x18application/octet-stream@@\x83\x00\x00\x01p\xe2\xfez<\x00Su\xb0\x00\x02\x00\x00\xabFe\xdc]\x0d\xb1\xd5\x86\xa2\xd0X8\xbe\x13q\x06}\x9c\x9b\xfc\xb4~&\xb1\xf9\xfc_QM"\x9a\x83\x01^\x0cH\x98\x1dPg8+D\x81V\xcf\xaa{\x8dY\x8f\xea\x01b\x0c\xd5\x9d\xf1A>\xd5\xe2-\xc3\x9c\xf0\xc1\xd2("?\x95\xd3&\xeb\xe7t!c\x16\xea\x1dt\xf9o\xca\x95\xd0-\xb2\xd1\xcd8\xa7\x02\x07\x89\xd0HM\x04\xb3\xa69\xba\x8c\xa5.&_\xc6s\x1a\x16*\x93\x13\xdd\xdb\x91\xd6\xf40\x8e\x18\xf4S\xce\xea\xa7+i\xda\xef\xa1\x9b\x13\x06\xad47\xb1\xe7\xd1\x04\xa6O\xbe=\xaa\xa4\xb9\xc1.S\xc4\xdc\x1a\xd8Vv\xb1T]\xb1*\x0e\x8b_	\xcbD\xf0sc\x89\xa3l\x90\xa2\x1aV\xb5xP\xac\xfb*\x0f\x1d\x97\xfd\xcc\xfb<ul\x0ck\xba\xc9\xbeu\x91\xab\xe3\xb7\xd7T\xfd\xa1\xcf\xfb(_\xf5\xb8\x8b\xf36
>
> \x8aN\xe4\xb0H\xf0%\x80\xcf\x0c\xef\x13s=G\xdd\x9d;\x81\xb1~\xafD\xc2\xe1\xb9Kx$}\x7f"...(truncated)
> [734665003:1] <- Transfer{handle=0, deliveryId=0, deliveryTag=\x00,
> messageFormat=0, settled=false, more=false, rcvSettleMode=null, state=null,
> resume=false, aborted=false, batchable=false} (206)
> "=?\xedxH\xef\xa8\xd1\xcc\xf5\xc3\xa0N\xdc\xab\xbe\xeb\x96\x94\xdcwD\x03R\xd9\xd4\xbd\xcd\xb6\x82\x90\x99/\xc4\x133(\xca-a@\xf9\xbb\xe6\xfeF\xd4\xb9\xcc\xbeG<\x9b\xde\x8ec\xb3\x85q\x1f\xf3rR\xac\xd9\xe9\xf7\x0cxP\xcaY+j\xd9\x02\xd0\x94.\x0b\x8dQ<\x15\x16\x09\x0f>\x94\x13\xb4\x98\xbc$\xf7-\xed\xc5\x98\x1e\xe4\xb46k\x02>Vd\xb7\xe4\x1e\x8bt\xe0K\xffVV\x1bZ(\xf7\xff)\xf1\x0c\xe0Q\x0e
>
> \xcc>\xfb+\xe6|\xfc,?\xb2\xcf\xab\xeb\xf2\xfd\x89\x82\xe3\x997/\x05\xc7H\x17\x175\xe1C\xbcnx\x17\x19\x83W\x1f\xde\x12\xbc\xe7<\xbb\xc8?\xb9\xeb\xa2\x09\x87\x84\xd2\x07\x1b'\x81Sw\xf2:\xaam\xe4jE[\x01\xa4\x19\xae\x11\xdf\xa9\xa3\xe5\xc3"
> [734665003:1] <-
> Attach{name='qpid-jms:receiver:ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1:testSendFixedSizedMessages',
> handle=1, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
> source=Source{address='testSendFixedSizedMessages', durable=NONE,
> expiryPolicy=LINK_DETACH, timeout=0, dynamic=false,
> dynamicNodeProperties=null, distributionMode=null, filter=null,
> defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=null,
> messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list,
> amqp:released:list, amqp:modified:list], capabilities=[queue]},
> target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END,
> timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null},
> unsettled=null, incompleteUnsettled=false, initialDeliveryCount=null,
> maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null,
> properties=null}
> [734665003:1] ->
> Attach{name='qpid-jms:receiver:ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1:testSendFixedSizedMessages',
> handle=1, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
> source=Source{address='testSendFixedSizedMessages', durable=NONE,
> expiryPolicy=LINK_DETACH, timeout=0, dynamic=false,
> dynamicNodeProperties=null, distributionMode=null, filter=null,
> defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=null,
> messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list,
> amqp:released:list, amqp:modified:list], capabilities=[queue]},
> target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END,
> timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null},
> unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0,
> maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null,
> properties=null}
> [588596832:1] <-
> Attach{name='qpid-jms:receiver:ID:f683c24d-7a3c-473a-ae88-d6bef89633ce:1:1:1:testSendFixedSizedMessages',
> handle=1, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
> source=Source{address='testSendFixedSizedMessages', durable=NONE,
> expiryPolicy=LINK_DETACH, timeout=0, dynamic=false,
> dynamicNodeProperties=null, distributionMode=null, filter=null,
> defaultOutcome=Modified{deliveryFailed=true, undeliverableHere=null,
> messageAnnotations=null}, outcomes=[amqp:accepted:list, amqp:rejected:list,
> amqp:released:list, amqp:modified:list], capabilities=[queue]},
> target=Target{address='null', durable=NONE, expiryPolicy=SESSION_END,
> timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null},
> unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0,
> maxMessageSize=null, offeredCapabilities=null, desiredCapabilities=null,
> properties=null}
> [588596832:1] -> Flow{nextIncomingId=1, incomingWindow=2047,
> nextOutgoingId=3, outgoingWindow=2147483647, handle=1, deliveryCount=0,
> linkCredit=1000, available=null, drain=false, echo=false, properties=null}
> [734665003:1] <- Flow{nextIncomingId=1, incomingWindow=2047,
> nextOutgoingId=3, outgoingWindow=2147483647, handle=1, deliveryCount=0,
> linkCredit=1000, available=null, drain=false, echo=false, properties=null}
> [734665003:1] -> Disposition{role=RECEIVER, first=0, last=0, settled=true,
> state=Accepted{}, batchable=false}
> [588596832:1] <- Disposition{role=RECEIVER, first=0, last=0, settled=true,
> state=Accepted{}, batchable=false}
> [734665003:0] -> Empty Frame
> [588596832:0] -> Empty Frame
> [588596832:0] <- Empty Frame
> [734665003:0] <- Empty Frame
> {noformat}
> =======================================
> I'd also draw attention to AmqpLargeMessageTest # testSend1MBMessage, as I
> noticed that although this particular AmqpLargeMessageTest run had actually
> passed rather than failing the above tests, the output for
> 'testSend1MBMessage' showed the broker doing something unexpected which could
> perhaps be related to the above failures.
> It sends an empty final Transfer frame for the message it is giving to the
> consumer, indicating that there is no more payload, while the previous
> Transfer which actually contained the final payload had still indicated more
> payload was to come by setting "more=true". It is a legal protocol trace but
> it should never really happen in a broker.
> It suggests that the delivery send isnt being completed at the point the last
> payload has been added, with the transport output then generated, and only
> later is the delivery being indicated completed somehow and further transport
> output generated that sends the final transfer.
> {noformat}
> [207826248:1] -> Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
> messageFormat=0, settled=false, more=true, rcvSettleMode=null, state=null,
> resume=false, aborted=false, batchable=false} (1024)
> "c\xa3\xa13\xf3\xbcH\x10\x7f\x14\xd9\xce+\x17\x1d\x17
> \xad,\x89\x94\xbb\xaf\x80\x84\x1dU\xcc\xa9EZ\xff\x80\x8e\x9d\x09&\xc7\xd5\xc5\xb8d-\x0dQ?^\x15\xa7\xd0\x93\x8cP\x93kM\xd6\xb3\xe4_m>\xe3\xd5N\xe1w{\xff>\x93\x96\xad\xdeM\x8d;\xa4\xee\xc3\xd9Z;\x16\xee5wc\xf5\xb7\x90#\xb6j\x16t\xb4\xd1\x97\xe9I\xc5\x89k\xda\x0d~4\xdb,\x86\xa2i\x81f\xf9\xbf\x92\xa7q\xad\x9a\x0aj\x03\x931\xd1\xf1HN\x8e\xce4\xce\xe7\xa1\x0d)\xc6\x14\x15\xf5F>\xd7\xe8\x98&\xb1,|e\x9dh\xc9\xa7Y\xa7V\x10\x18\xfa\x1b`\x9a\xb2@\x08\xd6\xf7\x01p\x9e=]{\x18\x84+|\xfarE\x8b\x8a\x03(s\x02\x8e\xc9\xb7\x0a\xb3D\xc6mv\xd2\xed\x0c\x8eI\xe1\x90h\x1c-\x1e\xfd2*\xf4\xd2\xab\xb671\xa7\xa9W\xf2\xd2\xcaU\xef\xb3\x17t\x1a\xef7\xd1lX\x08\x14\x88~\x0d{v\x91g\xf2\x94\x8f\x06Oi\xc3\xb8\x14\xa5\x9cj\xfb\xb1\xeb\x00\xe5\xb5o~\x1ej\x84\x82em\xe5\xd97\x8a\xd6\x1cF\xc8\xa74\xd8;UDz\xfa\x19\xcc\x89\xaf\x9cj5\xe0w\xaf"X\x0d\xc8\xd4\x84\x9d\xc81\xa56vRa\xe1\xe2\x09\xb4\xd2\xefc\xf1Zk\xba\x04\xdb\x11"\xba\x07#%>\xfd\x0c\x9bv\xb2\x98\xac(\xab\x9f#5\xb5\xa5\xdb\x9dfv}V\x8b\x0f"...(truncated)
> [207826248:1] -> Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
> messageFormat=0, settled=false, more=true, rcvSettleMode=null, state=null,
> resume=false, aborted=false, batchable=false} (176)
> "\xec\x8d\xc3\xdf\xa3\xf6\xfc\x971\xdb9\x8a\xa6!\x15\x06\xbb\xa3\xd9Z\x19\xef\xa6,c\x84h\xa0
> \x99|?|u|\xad\x08\x01\xdd\x8ezj
> R\xcd0\xdd\xe3L\x9d\xe4\xba\xa2\xdd\x0b\xc0\xea\x9b\xf3\xafp\x03\xa8\x877\xbaZ\xe14{(\xcc\xcd\xb1\x93\xd5\x91\xbbEF\xc8I\xa4\xda\xba\xd2\x05VP\xf1\xa1\xddpi1\xc4#:\x15\xf1\xc0\x85x\xe5\x13\xac\xf7\x15\xafL\x07\x85\x0d\x99\x13G\x0c\xa9\xb6\xdb\xfc\xcen\xb6X0\x11\x09|\xd6!\xe4\xa2\xf7r2?\xd55\x95\xf9c\xf3\x81\x97t\xa2\xabA\x1f\xa5k\xa2\x83,y\xed\x8c\x8c!F;\xf9\x95W\xf6\x0dM+\x13\xf3\x134\xc80I"
> ...
> [207826248:1] -> Transfer{handle=1, deliveryId=0, deliveryTag=\x00,
> messageFormat=0, settled=false, more=false, rcvSettleMode=null, state=null,
> resume=false, aborted=false, batchable=false} (0) ""
> {noformat}
> =======================================
> I also see TopicDurableTests testSharedNonDurableSubscription fail quite
> often, rejecting the link attach with a not-found error indicating an invalid
> destination while creating the shared topic consumer. The test runs the
> squence 10 times in a loop, I havent looked into when it fails, but in this
> particular case it seemed to fail on the second loop (i.e iteration 1,
> 0-based count). Perhaps a race between tearing down an old shared
> subscription and a new one establishing?
> {noformat}
> Tests run: 2, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 0.378 sec <<<
> FAILURE! - in
> org.apache.activemq.artemis.tests.integration.amqp.TopicDurableTests
> testSharedNonDurableSubscription(org.apache.activemq.artemis.tests.integration.amqp.TopicDurableTests)
> Time elapsed: 0.179 sec <<< ERROR!
> javax.jms.InvalidDestinationException: AMQ119010: source address does not
> exist [condition = amqp:not-found]
> at
> org.apache.qpid.jms.provider.exceptions.ProviderInvalidDestinationException.toJMSException(ProviderInvalidDestinationException.java:37)
> at
> org.apache.qpid.jms.provider.exceptions.ProviderInvalidDestinationException.toJMSException(ProviderInvalidDestinationException.java:23)
> at
> org.apache.qpid.jms.exceptions.JmsExceptionSupport.create(JmsExceptionSupport.java:80)
> at
> org.apache.qpid.jms.exceptions.JmsExceptionSupport.create(JmsExceptionSupport.java:112)
> at
> org.apache.qpid.jms.JmsConnection.createResource(JmsConnection.java:698)
> at
> org.apache.qpid.jms.JmsMessageConsumer.<init>(JmsMessageConsumer.java:125)
> at
> org.apache.qpid.jms.JmsSharedMessageConsumer.<init>(JmsSharedMessageConsumer.java:29)
> at
> org.apache.qpid.jms.JmsSession.createSharedConsumer(JmsSession.java:625)
> at
> org.apache.qpid.jms.JmsSession.createSharedConsumer(JmsSession.java:613)
> at
> org.apache.activemq.artemis.tests.integration.amqp.TopicDurableTests.testSharedNonDurableSubscription(TopicDurableTests.java:149)
> {noformat}
> {noformat}
> ...
> [main] 12:50:51,254 INFO [org.apache.activemq.artemis.core.server]
> AMQ221001: Apache ActiveMQ Artemis Message Broker version 2.12.0-SNAPSHOT
> [localhost, nodeID=c4269bc3-6784-11ea-bb9b-000c29e9f622]
> testSharedNonDurableSubscription; iteration: 0
> messages sent
> Mesages receivedJmsTextMessage {
> org.apache.qpid.jms.provider.amqp.message.AmqpJmsTextMessageFacade@4af6da0 }
> count: 10
> Mesages receivedJmsTextMessage {
> org.apache.qpid.jms.provider.amqp.message.AmqpJmsTextMessageFacade@1d68c19f }
> count: 9
> Mesages receivedJmsTextMessage {
> org.apache.qpid.jms.provider.amqp.message.AmqpJmsTextMessageFacade@13af3c42 }
> count: 8
> Mesages receivedJmsTextMessage {
> org.apache.qpid.jms.provider.amqp.message.AmqpJmsTextMessageFacade@a689345 }
> count: 7
> Mesages receivedJmsTextMessage {
> org.apache.qpid.jms.provider.amqp.message.AmqpJmsTextMessageFacade@1790aaef }
> count: 6
> Mesages receivedJmsTextMessage {
> org.apache.qpid.jms.provider.amqp.message.AmqpJmsTextMessageFacade@e5706d0 }
> count: 5
> Mesages receivedJmsTextMessage {
> org.apache.qpid.jms.provider.amqp.message.AmqpJmsTextMessageFacade@52923679 }
> count: 5
> Mesages receivedJmsTextMessage {
> org.apache.qpid.jms.provider.amqp.message.AmqpJmsTextMessageFacade@9ad718d }
> count: 3
> Mesages receivedJmsTextMessage {
> org.apache.qpid.jms.provider.amqp.message.AmqpJmsTextMessageFacade@4b55997e }
> count: 2
> Mesages receivedJmsTextMessage {
> org.apache.qpid.jms.provider.amqp.message.AmqpJmsTextMessageFacade@630a01d6 }
> count: 2
> messages received
> testSharedNonDurableSubscription; iteration: 1
> [main] 12:50:51,416 INFO [org.apache.activemq.artemis.core.server]
> AMQ221002: Apache ActiveMQ Artemis Message Broker version 2.12.0-SNAPSHOT
> [c4269bc3-6784-11ea-bb9b-000c29e9f622] stopped, uptime 0.174 seconds
> ...
> {noformat}
> =======================================
> I've also seen several cases of exception like the following during the
> tests. This one came from an earler run of the testSend1MBMessage test
> mentioned earlier:
> {noformat}
> [main] 14:51:10,416 INFO [org.apache.activemq.artemis.core.server]
> AMQ221001: Apache ActiveMQ Artemis Message Broker version 2.12.0-SNAPSHOT
> [localhost, nodeID=bf089402-63a7-11ea-875e-000c29e9f622]
> [Thread-1 (activemq-netty-threads)] 14:51:10,482 WARN
> [org.apache.activemq.artemis.core.server] AMQ222061: Client connection
> failed, clearing up resources for session bf0efca4-63a7-11ea-875e-000c29e9f622
> [Thread-1 (activemq-netty-threads)] 14:51:10,483 WARN
> [org.apache.activemq.artemis.core.server] AMQ222107: Cleared up resources for
> session bf0efca4-63a7-11ea-875e-000c29e9f622
> [Thread-1
> (ActiveMQ-server-org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl$6@407cf41)]
> 14:51:10,602 ERROR [org.apache.activemq.artemis.core.server] AMQ224065:
> Failed to remove auto-created queue testSend1MBMessage:
> ActiveMQShutdownException[errorType=SHUTDOWN_ERROR message=Journal must be in
> state=LOADED, was [STOPPED]]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.checkJournalIsLoaded(JournalImpl.java:1086)
> [artemis-journal-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendDeleteRecordTransactional(JournalImpl.java:1159)
> [artemis-journal-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalBase.appendDeleteRecordTransactional(JournalBase.java:98)
> [artemis-journal-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.core.journal.impl.JournalImpl.appendDeleteRecordTransactional(JournalImpl.java:92)
> [artemis-journal-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.core.persistence.impl.journal.AbstractJournalStorageManager.deleteQueueBinding(AbstractJournalStorageManager.java:1345)
> [artemis-server-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.core.server.impl.QueueImpl.deleteQueue(QueueImpl.java:2182)
> [artemis-server-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.core.server.impl.ActiveMQServerImpl.destroyQueue(ActiveMQServerImpl.java:2177)
> [artemis-server-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.core.server.impl.QueueManagerImpl.performAutoDeleteQueue(QueueManagerImpl.java:72)
> [artemis-server-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.core.server.impl.QueueManagerImpl.doIt(QueueManagerImpl.java:44)
> [artemis-server-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:42)
> [artemis-commons-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.utils.actors.OrderedExecutor.doTask(OrderedExecutor.java:31)
> [artemis-commons-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> org.apache.activemq.artemis.utils.actors.ProcessorBase.executePendingTasks(ProcessorBase.java:66)
> [artemis-commons-2.12.0-SNAPSHOT.jar:2.12.0-SNAPSHOT]
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> [rt.jar:1.8.0_181]
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> [rt.jar:1.8.0_181]
> {noformat}
> =======================================
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
