[ https://issues.apache.org/jira/browse/ARTEMIS-2659?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17074746#comment-17074746 ]
Timothy A. Bish commented on ARTEMIS-2659: ------------------------------------------ Running tests off master today I see instability in test case: AmqpSendReceiveTest.testAcceptWithoutSettling:88 » test timed out after 60000... It looks as though the receiver has offered credit but never gets a message which seems like there could be an underlying bug still in the credit handling code. > 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 > Priority: Blocker > Fix For: 2.12.0 > > > 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)