You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@qpid.apache.org by Clemens Vasters <cl...@microsoft.com.INVALID> on 2017/09/19 12:10:20 UTC
JMS message consumer behavior
This may be my ignorance of JMS details, but why does a Qpid JMS consumer go off and happily prefetch messages when its associated Session/Connection hasn't even been start()'ed yet?
I just got misled by the trace output into believing that my app code's receive/callback usage was wrong.
Here:
Connection connection = cf.createConnection(csb.getSasKeyName(), csb.getSasKey());
// Create Session, no transaction, client ack
Session session = connection.createSession(false, Session.CLIENT_ACKNOWLEDGE);
// Create consumer
MessageConsumer consumer = session.createConsumer(queue);
consumer.setMessageListener(message -> {
try {
// receives message is passed to callback
logger.info(String.format("Received message %d with sq#: %s",
totalReceived.incrementAndGet(), message.getJMSMessageID()));
message.acknowledge();
} catch (Exception e) {
logger.error(e);
}
});
//connection.start();
If I just let the app spin after this, it'll start logging prefetch events
...
2017-09-19 14:04:42,515 [windows.net:-1]] - TRACE AmqpProvider - New Proton Event: DELIVERY
2017-09-19 14:04:42,515 [windows.net:-1]] - TRACE AmqpConsumer - AmqpConsumer { ID:fce87003-90ac-4fb9-8e83-fdb4cd975a6a:2:1:1 } has incoming Message(s).
2017-09-19 14:04:42,517 [windows.net:-1]] - DEBUG AmqpConsumer - Dispatching received message: JmsInboundMessageDispatch { sequence = 1, messageId = ID:21a39efc-8501-45e8-8c67-d3483ca03874:1:1:1-5, consumerId = ID:fce87003-90ac-4fb9-8e83-fdb4cd975a6a:2:1:1 }
...
But my callback is never invoked.
Once I call start() on the connection (which I now do right after creating the connection in my code), the callback does get invoked.
That is quite confusing.
Re: JMS message consumer behavior
Posted by Rob Godfrey <ro...@gmail.com>.
On 19 September 2017 at 14:10, Clemens Vasters <
clemensv@microsoft.com.invalid> wrote:
> This may be my ignorance of JMS details, but why does a Qpid JMS consumer
> go off and happily prefetch messages when its associated Session/Connection
> hasn't even been start()'ed yet?
>
>
To be clear this is not *JMS* defined semantics, but an implementation
choice in the Qpid JMS client. I'll let Tim / Robbie speak to why that
choice was made (if it is intentional). I note there is already a JIRA
questioning the pre-fetch behaviour of consumers on stopped connections:
https://issues.apache.org/jira/browse/QPIDJMS-297 (albeit this is relating
to consumers on connections that were started and then subsequently
stopped).
-- Rob
I just got misled by the trace output into believing that my app code's
> receive/callback usage was wrong.
>
> Here:
>
> Connection connection = cf.createConnection(csb.getSasKeyName(),
> csb.getSasKey());
> // Create Session, no transaction, client ack
> Session session = connection.createSession(false,
> Session.CLIENT_ACKNOWLEDGE);
> // Create consumer
> MessageConsumer consumer = session.createConsumer(queue);
> consumer.setMessageListener(message -> {
> try {
> // receives message is passed to callback
> logger.info(String.format("Received message %d with sq#: %s",
> totalReceived.incrementAndGet(),
> message.getJMSMessageID()));
> message.acknowledge();
> } catch (Exception e) {
> logger.error(e);
> }
> });
> //connection.start();
> If I just let the app spin after this, it'll start logging prefetch events
>
> ...
> 2017-09-19 14:04:42,515 [windows.net:-1]] - TRACE AmqpProvider
> - New Proton Event: DELIVERY
> 2017-09-19 14:04:42,515 [windows.net:-1]] - TRACE AmqpConsumer
> - AmqpConsumer { ID:fce87003-90ac-4fb9-8e83-fdb4cd975a6a:2:1:1 }
> has incoming Message(s).
> 2017-09-19 14:04:42,517 [windows.net:-1]] - DEBUG AmqpConsumer
> - Dispatching received message: JmsInboundMessageDispatch { sequence
> = 1, messageId = ID:21a39efc-8501-45e8-8c67-d3483ca03874:1:1:1-5,
> consumerId = ID:fce87003-90ac-4fb9-8e83-fdb4cd975a6a:2:1:1 }
> ...
>
> But my callback is never invoked.
>
> Once I call start() on the connection (which I now do right after creating
> the connection in my code), the callback does get invoked.
>
> That is quite confusing.
>
Re: JMS message consumer behavior
Posted by Robbie Gemmell <ro...@gmail.com>.
Feel free to raise a JIRA at https://issues.apache.org/jira/projects/QPIDJMS.
If a server is aggressively handing messages out to other consumers
before an existing consumer releases or consumes it and counts that as
redelivery, and an application has a somewhat odd setup, then I can
see that yes the early prefetch (which as I say, just happens to be
what it does) could be undesirable. Any prefetch might even be, in
which case it can be disabled.
On 19 September 2017 at 15:02, Clemens Vasters
<cl...@microsoft.com.invalid> wrote:
> If there's a "start" operation on the connection, a client on that connection shouldn't start prefetching before that, IMO. Prefetch starts the expiration clock on the server for locks and depending on how the app does its setup and whether starting depends on user action, the client might silently drain a queue here, including eating up several redeliveries.
>
> -----Original Message-----
> From: Robbie Gemmell [mailto:robbie.gemmell@gmail.com]
> Sent: Tuesday, September 19, 2017 3:59 PM
> To: users@qpid.apache.org
> Subject: Re: JMS message consumer behavior
>
> On 19 September 2017 at 13:10, Clemens Vasters <cl...@microsoft.com.invalid> wrote:
>> This may be my ignorance of JMS details, but why does a Qpid JMS consumer go off and happily prefetch messages when its associated Session/Connection hasn't even been start()'ed yet?
>>
>
> Mainly its just 'because it does', i.e. it doesn't have any specific smarts in there to delay it. There are actually some advantages to doing that, and some downsides.
>
> As Rob said, JMS doesnt speak to this at all, prefetching isn't something it addresses, so its just an implementation detail as far as thats concerned.
>
>> I just got misled by the trace output into believing that my app code's receive/callback usage was wrong.
>
> Assuming you wanted to received messages with the Consumer you created, it was actually wrong in that you had any such usage without calling start(), but I can see what you are saying, the logging is speaking to details of its internal operation but if you thought it was really describing handing messages to the application it could mislead.
>
>>
>> Here:
>>
>> Connection connection = cf.createConnection(csb.getSasKeyName(),
>> csb.getSasKey()); // Create Session, no transaction, client ack
>> Session session = connection.createSession(false,
>> Session.CLIENT_ACKNOWLEDGE); // Create consumer MessageConsumer
>> consumer = session.createConsumer(queue);
>> consumer.setMessageListener(message -> {
>> try {
>> // receives message is passed to callback
>> logger.info(String.format("Received message %d with sq#: %s",
>> totalReceived.incrementAndGet(), message.getJMSMessageID()));
>> message.acknowledge();
>> } catch (Exception e) {
>> logger.error(e);
>> }
>> });
>> //connection.start();
>> If I just let the app spin after this, it'll start logging prefetch
>> events
>>
>> ...
>> 2017-09-19 14:04:42,515 [windows.net:-1]] - TRACE AmqpProvider - New Proton Event: DELIVERY
>> 2017-09-19 14:04:42,515 [windows.net:-1]] - TRACE AmqpConsumer - AmqpConsumer { ID:fce87003-90ac-4fb9-8e83-fdb4cd975a6a:2:1:1 } has incoming Message(s).
>> 2017-09-19 14:04:42,517 [windows.net:-1]] - DEBUG AmqpConsumer - Dispatching received message: JmsInboundMessageDispatch { sequence = 1, messageId = ID:21a39efc-8501-45e8-8c67-d3483ca03874:1:1:1-5, consumerId = ID:fce87003-90ac-4fb9-8e83-fdb4cd975a6a:2:1:1 }
>> ...
>>
>> But my callback is never invoked.
>>
>> Once I call start() on the connection (which I now do right after creating the connection in my code), the callback does get invoked.
>>
>> That is quite confusing.
>
> To be fair, that would happen regardless as it is behaviour JMS does dictate, you just wouldnt have seen any logging in the alternative case, and with more familiarity of the protocol spec would perhaps have figured it out a little easier. Most folks won't understand the spec enough to get that, or maybe turn up the logging at all, and will just be left with the silly JMS behaviour and resort to google/stackoverflow for the age old 'you need to start the connection' answer. JMSContext from JMS 2.0 auto-starts things by default to avoid such issues.
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org For additional commands, e-mail: users-help@qpid.apache.org
>
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org
RE: JMS message consumer behavior
Posted by Clemens Vasters <cl...@microsoft.com.INVALID>.
If there's a "start" operation on the connection, a client on that connection shouldn't start prefetching before that, IMO. Prefetch starts the expiration clock on the server for locks and depending on how the app does its setup and whether starting depends on user action, the client might silently drain a queue here, including eating up several redeliveries.
-----Original Message-----
From: Robbie Gemmell [mailto:robbie.gemmell@gmail.com]
Sent: Tuesday, September 19, 2017 3:59 PM
To: users@qpid.apache.org
Subject: Re: JMS message consumer behavior
On 19 September 2017 at 13:10, Clemens Vasters <cl...@microsoft.com.invalid> wrote:
> This may be my ignorance of JMS details, but why does a Qpid JMS consumer go off and happily prefetch messages when its associated Session/Connection hasn't even been start()'ed yet?
>
Mainly its just 'because it does', i.e. it doesn't have any specific smarts in there to delay it. There are actually some advantages to doing that, and some downsides.
As Rob said, JMS doesnt speak to this at all, prefetching isn't something it addresses, so its just an implementation detail as far as thats concerned.
> I just got misled by the trace output into believing that my app code's receive/callback usage was wrong.
Assuming you wanted to received messages with the Consumer you created, it was actually wrong in that you had any such usage without calling start(), but I can see what you are saying, the logging is speaking to details of its internal operation but if you thought it was really describing handing messages to the application it could mislead.
>
> Here:
>
> Connection connection = cf.createConnection(csb.getSasKeyName(),
> csb.getSasKey()); // Create Session, no transaction, client ack
> Session session = connection.createSession(false,
> Session.CLIENT_ACKNOWLEDGE); // Create consumer MessageConsumer
> consumer = session.createConsumer(queue);
> consumer.setMessageListener(message -> {
> try {
> // receives message is passed to callback
> logger.info(String.format("Received message %d with sq#: %s",
> totalReceived.incrementAndGet(), message.getJMSMessageID()));
> message.acknowledge();
> } catch (Exception e) {
> logger.error(e);
> }
> });
> //connection.start();
> If I just let the app spin after this, it'll start logging prefetch
> events
>
> ...
> 2017-09-19 14:04:42,515 [windows.net:-1]] - TRACE AmqpProvider - New Proton Event: DELIVERY
> 2017-09-19 14:04:42,515 [windows.net:-1]] - TRACE AmqpConsumer - AmqpConsumer { ID:fce87003-90ac-4fb9-8e83-fdb4cd975a6a:2:1:1 } has incoming Message(s).
> 2017-09-19 14:04:42,517 [windows.net:-1]] - DEBUG AmqpConsumer - Dispatching received message: JmsInboundMessageDispatch { sequence = 1, messageId = ID:21a39efc-8501-45e8-8c67-d3483ca03874:1:1:1-5, consumerId = ID:fce87003-90ac-4fb9-8e83-fdb4cd975a6a:2:1:1 }
> ...
>
> But my callback is never invoked.
>
> Once I call start() on the connection (which I now do right after creating the connection in my code), the callback does get invoked.
>
> That is quite confusing.
To be fair, that would happen regardless as it is behaviour JMS does dictate, you just wouldnt have seen any logging in the alternative case, and with more familiarity of the protocol spec would perhaps have figured it out a little easier. Most folks won't understand the spec enough to get that, or maybe turn up the logging at all, and will just be left with the silly JMS behaviour and resort to google/stackoverflow for the age old 'you need to start the connection' answer. JMSContext from JMS 2.0 auto-starts things by default to avoid such issues.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org For additional commands, e-mail: users-help@qpid.apache.org
Re: JMS message consumer behavior
Posted by Robbie Gemmell <ro...@gmail.com>.
On 19 September 2017 at 13:10, Clemens Vasters
<cl...@microsoft.com.invalid> wrote:
> This may be my ignorance of JMS details, but why does a Qpid JMS consumer go off and happily prefetch messages when its associated Session/Connection hasn't even been start()'ed yet?
>
Mainly its just 'because it does', i.e. it doesn't have any specific
smarts in there to delay it. There are actually some advantages to
doing that, and some downsides.
As Rob said, JMS doesnt speak to this at all, prefetching isn't
something it addresses, so its just an implementation detail as far as
thats concerned.
> I just got misled by the trace output into believing that my app code's receive/callback usage was wrong.
Assuming you wanted to received messages with the Consumer you
created, it was actually wrong in that you had any such usage without
calling start(), but I can see what you are saying, the logging is
speaking to details of its internal operation but if you thought it
was really describing handing messages to the application it could
mislead.
>
> Here:
>
> Connection connection = cf.createConnection(csb.getSasKeyName(), csb.getSasKey());
> // Create Session, no transaction, client ack
> Session session = connection.createSession(false, Session.CLIENT_ACKNOWLEDGE);
> // Create consumer
> MessageConsumer consumer = session.createConsumer(queue);
> consumer.setMessageListener(message -> {
> try {
> // receives message is passed to callback
> logger.info(String.format("Received message %d with sq#: %s",
> totalReceived.incrementAndGet(), message.getJMSMessageID()));
> message.acknowledge();
> } catch (Exception e) {
> logger.error(e);
> }
> });
> //connection.start();
> If I just let the app spin after this, it'll start logging prefetch events
>
> ...
> 2017-09-19 14:04:42,515 [windows.net:-1]] - TRACE AmqpProvider - New Proton Event: DELIVERY
> 2017-09-19 14:04:42,515 [windows.net:-1]] - TRACE AmqpConsumer - AmqpConsumer { ID:fce87003-90ac-4fb9-8e83-fdb4cd975a6a:2:1:1 } has incoming Message(s).
> 2017-09-19 14:04:42,517 [windows.net:-1]] - DEBUG AmqpConsumer - Dispatching received message: JmsInboundMessageDispatch { sequence = 1, messageId = ID:21a39efc-8501-45e8-8c67-d3483ca03874:1:1:1-5, consumerId = ID:fce87003-90ac-4fb9-8e83-fdb4cd975a6a:2:1:1 }
> ...
>
> But my callback is never invoked.
>
> Once I call start() on the connection (which I now do right after creating the connection in my code), the callback does get invoked.
>
> That is quite confusing.
To be fair, that would happen regardless as it is behaviour JMS does
dictate, you just wouldnt have seen any logging in the alternative
case, and with more familiarity of the protocol spec would perhaps
have figured it out a little easier. Most folks won't understand the
spec enough to get that, or maybe turn up the logging at all, and will
just be left with the silly JMS behaviour and resort to
google/stackoverflow for the age old 'you need to start the
connection' answer. JMSContext from JMS 2.0 auto-starts things by
default to avoid such issues.
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@qpid.apache.org
For additional commands, e-mail: users-help@qpid.apache.org