Re: Qpid Jms Client 0.35.0 problem reading message after some message redeliveries
This has been identified as an issue in the Artemis broker's AMQP
implementation and fixed for the next release:
https://issues.apache.org/jira/browse/ARTEMIS-2082
On 08/10/2018 06:53 PM, Dan Langford wrote:
TLDR messages redelivered from artemis broker get into state where qpid jms
client api will not show me the properties or body. trying to determine if
its the broker sending down bad data or if its the client not supporting
some frame structure
I have a message on my broker right now (Artemis 2.6.2) its on a Queue
waiting to be delivered. I am connecting with Qpid Jms Client 0.35.0 and
the client is not revealing to me the properties or payload of the message.
below is my code. its using the simplified api we got in 2.0 (JmsContext)
to create a Consumer and the set a MessageListener. Then i do this on each
javax.jms.Message
for(Object name: Collections.list(message.getPropertyNames())) {
System.out.printf("property name=%s value=%s%n", name,
message.getObjectProperty((String) name));
}
System.out.printf("message payload=%s%n", message.getBody(String.class));
System.out.println("done");
and here are the frames i am seeing due to env variable PN_TRACE_FRM=true
(with some data scrubbed like hostnames)
[199721506:0] -> Open{
containerId='ID:12eea5d0-97f3-47d4-8d5a-e59c37452c10:1', hostname='
stage.myhost.org', maxFrameSize=1048576, channelMax=32767,
idleTimeOut=3, outgoingLocales=null, incomingLocales=null,
offeredCapabilities=null,
desiredCapabilities=[sole-connection-for-container, DELAYED_DELIVERY,
ANONYMOUS-RELAY, SHARED-SUBS], properties={product=QpidJMS, version=0.35.0,
platform=JVM: 1.8.0_181, 25.181-b13, Oracle Corporation, OS: Mac OS X,
10.13.6, x86_64}}
[199721506:0] <- Open{ containerId='node1', hostname='null',
maxFrameSize=131072, channelMax=65535, idleTimeOut=3,
outgoingLocales=null, incomingLocales=null,
offeredCapabilities=[sole-connection-for-container, DELAYED_DELIVERY,
SHARED-SUBS, ANONYMOUS-RELAY], desiredCapabilities=null,
properties={product=apache-activemq-artemis,
failover-server-list=[{hostname=node1, scheme=amqp, port=61616,
network-host=node2}], version=2.6.2}}
[199721506:0] -> Begin{remoteChannel=null, nextOutgoingId=1,
incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
[199721506:0] <- Begin{remoteChannel=0, nextOutgoingId=1,
incomingWindow=2147483647, outgoingWindow=2147483647, handleMax=65535,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
[199721506:1] -> Begin{remoteChannel=null, nextOutgoingId=1,
incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
[199721506:1] <- Begin{remoteChannel=1, nextOutgoingId=1,
incomingWindow=2147483647, outgoingWindow=2147483647, handleMax=65535,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
[199721506:1] ->
Attach{name='qpid-jms:receiver:ID:36414498-1cef-45b7-9829-65adf6b870b4:1:1:1:QUE-134b55356db040f68dd2f51413c1895c',
handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
source=Source{address='QUE-134b55356db040f68dd2f51413c1895c', 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}
[199721506:1] <-
Attach{name='qpid-jms:receiver:ID:36414498-1cef-45b7-9829-65adf6b870b4:1:1:1:QUE-134b55356db040f68dd2f51413c1895c',
handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
source=Source{address='QUE-134b55356db040f68dd2f51413c1895c', 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}
[199721506:1] -> Flow{nextIncomingId=1, incomingWindow=2047,
nextOutgoingId=1, outgoingWindow=2147483647, handle=0, deliveryCount=0,
linkCredit=1, available=null, drain=false, echo=false, properties=null}
[199721506:1] <- Transfer{handle=0,
Re: Qpid Jms Client 0.35.0 problem reading message after some message redeliveries
thank you i will reach out to the apache activemq artemis team.
On Mon, Aug 13, 2018 at 6:56 AM Robbie Gemmell
wrote:
> Theres a couple things going on. The main/first issue is the data
> coming from the broker, those extra 3 bytes you noted in the counts.
>
> They are located within the payload just after the AMQP header, and
> represent an encoded null followed by the typecode for a smalluint,
> but that is then followed seemingly not by a uint value but rather by
> the same remaining byte payload as in the original sending of the
> message. The encoded null within the transfer payload causes the
> message to present in decode as not having further content after the
> header, which can be considered a bug in proton-j. Essentially though
> the problem started when the broker sent a corrupt payload. The header
> it sent was fully-populated in both cases and identifical, and the 3
> bytes sent after dont appear to represent anything complete (but what
> came after is fine), so I think this is a bug within the broker
> itself.
>
> The JMSXDeliveryCount value remained 2 because the client initially
> bases it on the amqp delivery-count within the message, and that didnt
> change as the message was 'released', which is what happened
> inbetween. I assume you threw an exception from onMessage to achieve
> that, and so that behaviour relates to
> https://issues.apache.org/jira/browse/QPIDJMS-388
>
> Robbie
>
> On 10 August 2018 at 23:53, Dan Langford wrote:
> > TLDR messages redelivered from artemis broker get into state where qpid
> jms
> > client api will not show me the properties or body. trying to determine
> if
> > its the broker sending down bad data or if its the client not supporting
> > some frame structure
> >
> > I have a message on my broker right now (Artemis 2.6.2) its on a Queue
> > waiting to be delivered. I am connecting with Qpid Jms Client 0.35.0 and
> > the client is not revealing to me the properties or payload of the
> message.
> > below is my code. its using the simplified api we got in 2.0 (JmsContext)
> > to create a Consumer and the set a MessageListener. Then i do this on
> each
> > javax.jms.Message
> >
> >
> > for(Object name: Collections.list(message.getPropertyNames())) {
> > System.out.printf("property name=%s value=%s%n", name,
> > message.getObjectProperty((String) name));
> > }
> > System.out.printf("message payload=%s%n", message.getBody(String.class));
> > System.out.println("done");
> >
> >
> > and here are the frames i am seeing due to env variable PN_TRACE_FRM=true
> > (with some data scrubbed like hostnames)
> >
> >
> > [199721506:0] -> Open{
> > containerId='ID:12eea5d0-97f3-47d4-8d5a-e59c37452c10:1', hostname='
> > stage.myhost.org', maxFrameSize=1048576, channelMax=32767,
> > idleTimeOut=3, outgoingLocales=null, incomingLocales=null,
> > offeredCapabilities=null,
> > desiredCapabilities=[sole-connection-for-container, DELAYED_DELIVERY,
> > ANONYMOUS-RELAY, SHARED-SUBS], properties={product=QpidJMS,
> version=0.35.0,
> > platform=JVM: 1.8.0_181, 25.181-b13, Oracle Corporation, OS: Mac OS X,
> > 10.13.6, x86_64}}
> > [199721506:0] <- Open{ containerId='node1', hostname='null',
> > maxFrameSize=131072, channelMax=65535, idleTimeOut=3,
> > outgoingLocales=null, incomingLocales=null,
> > offeredCapabilities=[sole-connection-for-container, DELAYED_DELIVERY,
> > SHARED-SUBS, ANONYMOUS-RELAY], desiredCapabilities=null,
> > properties={product=apache-activemq-artemis,
> > failover-server-list=[{hostname=node1, scheme=amqp, port=61616,
> > network-host=node2}], version=2.6.2}}
> > [199721506:0] -> Begin{remoteChannel=null, nextOutgoingId=1,
> > incomingWindow=2047, outgoingWindow=2147483647 <(214)%20748-3647>,
> handleMax=65535,
> > offeredCapabilities=null, desiredCapabilities=null, properties=null}
> > [199721506:0] <- Begin{remoteChannel=0, nextOutgoingId=1,
> > incomingWindow=2147483647 <(214)%20748-3647>, outgoingWindow=2147483647
> <(214)%20748-3647>, handleMax=65535,
> > offeredCapabilities=null, desiredCapabilities=null, properties=null}
> > [199721506:1] -> Begin{remoteChannel=null, nextOutgoingId=1,
> > incomingWindow=2047, outgoingWindow=2147483647 <(214)%20748-3647>,
> handleMax=65535,
> > offeredCapabilities=null, desiredCapabilities=null, properties=null}
> > [199721506:1] <- Begin{remoteChannel=1, nextOutgoingId=1,
> > incomingWindow=2147483647 <(214)%20748-3647>, outgoingWindow=2147483647
> <(214)%20748-3647>, handleMax=65535,
> > offeredCapabilities=null, desiredCapabilities=null, properties=null}
> > [199721506:1] ->
> >
> Attach{name='qpid-jms:receiver:ID:36414498-1cef-45b7-9829-65adf6b870b4:1:1:1:QUE-134b55356db040f68dd2f51413c1895c',
> > handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
> > source=Source{address='QUE-134b55356db040f68dd2f51413c1895c',
> durable=NONE,
> > expiryPolicy=LINK_DETACH, timeout=0, dynamic=false,
> > dynamicNodeProperties=null, distributionMode=null, filter=null,
> >
Re: Qpid Jms Client 0.35.0 problem reading message after some message redeliveries
Theres a couple things going on. The main/first issue is the data
coming from the broker, those extra 3 bytes you noted in the counts.
They are located within the payload just after the AMQP header, and
represent an encoded null followed by the typecode for a smalluint,
but that is then followed seemingly not by a uint value but rather by
the same remaining byte payload as in the original sending of the
message. The encoded null within the transfer payload causes the
message to present in decode as not having further content after the
header, which can be considered a bug in proton-j. Essentially though
the problem started when the broker sent a corrupt payload. The header
it sent was fully-populated in both cases and identifical, and the 3
bytes sent after dont appear to represent anything complete (but what
came after is fine), so I think this is a bug within the broker
itself.
The JMSXDeliveryCount value remained 2 because the client initially
bases it on the amqp delivery-count within the message, and that didnt
change as the message was 'released', which is what happened
inbetween. I assume you threw an exception from onMessage to achieve
that, and so that behaviour relates to
https://issues.apache.org/jira/browse/QPIDJMS-388
Robbie
On 10 August 2018 at 23:53, Dan Langford wrote:
> TLDR messages redelivered from artemis broker get into state where qpid jms
> client api will not show me the properties or body. trying to determine if
> its the broker sending down bad data or if its the client not supporting
> some frame structure
>
> I have a message on my broker right now (Artemis 2.6.2) its on a Queue
> waiting to be delivered. I am connecting with Qpid Jms Client 0.35.0 and
> the client is not revealing to me the properties or payload of the message.
> below is my code. its using the simplified api we got in 2.0 (JmsContext)
> to create a Consumer and the set a MessageListener. Then i do this on each
> javax.jms.Message
>
>
> for(Object name: Collections.list(message.getPropertyNames())) {
> System.out.printf("property name=%s value=%s%n", name,
> message.getObjectProperty((String) name));
> }
> System.out.printf("message payload=%s%n", message.getBody(String.class));
> System.out.println("done");
>
>
> and here are the frames i am seeing due to env variable PN_TRACE_FRM=true
> (with some data scrubbed like hostnames)
>
>
> [199721506:0] -> Open{
> containerId='ID:12eea5d0-97f3-47d4-8d5a-e59c37452c10:1', hostname='
> stage.myhost.org', maxFrameSize=1048576, channelMax=32767,
> idleTimeOut=3, outgoingLocales=null, incomingLocales=null,
> offeredCapabilities=null,
> desiredCapabilities=[sole-connection-for-container, DELAYED_DELIVERY,
> ANONYMOUS-RELAY, SHARED-SUBS], properties={product=QpidJMS, version=0.35.0,
> platform=JVM: 1.8.0_181, 25.181-b13, Oracle Corporation, OS: Mac OS X,
> 10.13.6, x86_64}}
> [199721506:0] <- Open{ containerId='node1', hostname='null',
> maxFrameSize=131072, channelMax=65535, idleTimeOut=3,
> outgoingLocales=null, incomingLocales=null,
> offeredCapabilities=[sole-connection-for-container, DELAYED_DELIVERY,
> SHARED-SUBS, ANONYMOUS-RELAY], desiredCapabilities=null,
> properties={product=apache-activemq-artemis,
> failover-server-list=[{hostname=node1, scheme=amqp, port=61616,
> network-host=node2}], version=2.6.2}}
> [199721506:0] -> Begin{remoteChannel=null, nextOutgoingId=1,
> incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535,
> offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [199721506:0] <- Begin{remoteChannel=0, nextOutgoingId=1,
> incomingWindow=2147483647, outgoingWindow=2147483647, handleMax=65535,
> offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [199721506:1] -> Begin{remoteChannel=null, nextOutgoingId=1,
> incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535,
> offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [199721506:1] <- Begin{remoteChannel=1, nextOutgoingId=1,
> incomingWindow=2147483647, outgoingWindow=2147483647, handleMax=65535,
> offeredCapabilities=null, desiredCapabilities=null, properties=null}
> [199721506:1] ->
> Attach{name='qpid-jms:receiver:ID:36414498-1cef-45b7-9829-65adf6b870b4:1:1:1:QUE-134b55356db040f68dd2f51413c1895c',
> handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
> source=Source{address='QUE-134b55356db040f68dd2f51413c1895c', 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,
>
Qpid Jms Client 0.35.0 problem reading message after some message redeliveries
TLDR messages redelivered from artemis broker get into state where qpid jms
client api will not show me the properties or body. trying to determine if
its the broker sending down bad data or if its the client not supporting
some frame structure
I have a message on my broker right now (Artemis 2.6.2) its on a Queue
waiting to be delivered. I am connecting with Qpid Jms Client 0.35.0 and
the client is not revealing to me the properties or payload of the message.
below is my code. its using the simplified api we got in 2.0 (JmsContext)
to create a Consumer and the set a MessageListener. Then i do this on each
javax.jms.Message
for(Object name: Collections.list(message.getPropertyNames())) {
System.out.printf("property name=%s value=%s%n", name,
message.getObjectProperty((String) name));
}
System.out.printf("message payload=%s%n", message.getBody(String.class));
System.out.println("done");
and here are the frames i am seeing due to env variable PN_TRACE_FRM=true
(with some data scrubbed like hostnames)
[199721506:0] -> Open{
containerId='ID:12eea5d0-97f3-47d4-8d5a-e59c37452c10:1', hostname='
stage.myhost.org', maxFrameSize=1048576, channelMax=32767,
idleTimeOut=3, outgoingLocales=null, incomingLocales=null,
offeredCapabilities=null,
desiredCapabilities=[sole-connection-for-container, DELAYED_DELIVERY,
ANONYMOUS-RELAY, SHARED-SUBS], properties={product=QpidJMS, version=0.35.0,
platform=JVM: 1.8.0_181, 25.181-b13, Oracle Corporation, OS: Mac OS X,
10.13.6, x86_64}}
[199721506:0] <- Open{ containerId='node1', hostname='null',
maxFrameSize=131072, channelMax=65535, idleTimeOut=3,
outgoingLocales=null, incomingLocales=null,
offeredCapabilities=[sole-connection-for-container, DELAYED_DELIVERY,
SHARED-SUBS, ANONYMOUS-RELAY], desiredCapabilities=null,
properties={product=apache-activemq-artemis,
failover-server-list=[{hostname=node1, scheme=amqp, port=61616,
network-host=node2}], version=2.6.2}}
[199721506:0] -> Begin{remoteChannel=null, nextOutgoingId=1,
incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
[199721506:0] <- Begin{remoteChannel=0, nextOutgoingId=1,
incomingWindow=2147483647, outgoingWindow=2147483647, handleMax=65535,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
[199721506:1] -> Begin{remoteChannel=null, nextOutgoingId=1,
incomingWindow=2047, outgoingWindow=2147483647, handleMax=65535,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
[199721506:1] <- Begin{remoteChannel=1, nextOutgoingId=1,
incomingWindow=2147483647, outgoingWindow=2147483647, handleMax=65535,
offeredCapabilities=null, desiredCapabilities=null, properties=null}
[199721506:1] ->
Attach{name='qpid-jms:receiver:ID:36414498-1cef-45b7-9829-65adf6b870b4:1:1:1:QUE-134b55356db040f68dd2f51413c1895c',
handle=0, role=RECEIVER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
source=Source{address='QUE-134b55356db040f68dd2f51413c1895c', 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}
[199721506:1] <-
Attach{name='qpid-jms:receiver:ID:36414498-1cef-45b7-9829-65adf6b870b4:1:1:1:QUE-134b55356db040f68dd2f51413c1895c',
handle=0, role=SENDER, sndSettleMode=UNSETTLED, rcvSettleMode=FIRST,
source=Source{address='QUE-134b55356db040f68dd2f51413c1895c', 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}
[199721506:1] -> Flow{nextIncomingId=1, incomingWindow=2047,
nextOutgoingId=1, outgoingWindow=2147483647, handle=0, deliveryCount=0,
linkCredit=1, available=null, drain=false, echo=false, properties=null}
[199721506:1] <- Transfer{handle=0, deliveryId=0, deliveryTag=\x00,
messageFormat=0, settled=null, more=false, rcvSettleMode=null, state=null,
resume=false, aborted=false, batchable=false} (416) "\x00Sp\xc0\x0b\x05A@p
\x00\x00\x03\xe8@R\x01@R
