[
https://issues.apache.org/jira/browse/QPIDJMS-473?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16941880#comment-16941880
]
Robert Gemmell commented on QPIDJMS-473:
----------------------------------------
Some more outline for you and anyone else reading later
In AMQP 1.0 sending/receiving links are opened to specific node addresses, e.g
to a queue using its name. For 'anonymous' producer cases (either a
MessageProducer created with null as the destination, or the 'light weight'
JMSProducer instances) the address of the destination isnt known until the
point of send occuring. An extension mechanism was created to allow for a
single sending link to be created to an 'anonymous relay', to be used for
multiple destinations where each message sent carries its actual destination.
For servers that dont advertise support of this functionality, the client has a
fallback mechanism so that these 'anonymous producer' scenarios could at least
still work, albeit more slowly. It would seem ServiceBus does not advertise
'anonymous relay' support and so you ended up using the fallback mechanism, and
in concert with that you hit a bug in the JMS 2.0 additions made since it was
created and that we hadn't yet come across, due to mainly using servers that do
advertise the support.
0.46.0 resolves the bug, and QPIDJMS-476 now has the mentioned improvements
around increasing perf of the fallback mechanism.
> failure handling CompletionListener when using fallback anonymous producers
> ---------------------------------------------------------------------------
>
> Key: QPIDJMS-473
> URL: https://issues.apache.org/jira/browse/QPIDJMS-473
> Project: Qpid JMS
> Issue Type: Bug
> Components: qpid-jms-client
> Affects Versions: 0.45.0
> Environment: Windows 10/64
> Dell 5530 8 cores (possibly explaining why the send thread completes faster
> than the thread recording the SendComplete on the queue?)
> java 8
>
> Reporter: Consultant Leon
> Assignee: Robert Gemmell
> Priority: Critical
> Fix For: 0.46.0
>
> Attachments:
> fix_QPID-JMS-473_race_condition_where_SendCompletion_was_not_placed_on_asyncSendQueue_befo.patch
>
>
> When a server does not offer support for the 'anonymous relay' capability,
> the client falls back to opening and closing links to satisfy send requests
> for anonymous producers (i.e JMSProducer instances, and MessageProducers
> created without a destination). The fallback mechanism does not currently
> account for use of a CompletionListener during the send, and so fails to
> notify it. It should be updated to handle usage of a CompletionListener.
>
>
>
> ============
> Original Description:
>
> When I configure a completion listener and send 50 messages rapidly
> asynchronous I hit a race condition.
> Debugging the code proves that the envelope has not been placed on
> asyncSendQueue at the time the very first send completion arrives.
> This results in JmsSession line 1518 within the private AsyncCompletionTask
> class:
> SendCompletion completion = {color:#660e7a}asyncSendQueue{color}.peek();
> Returning *null* , as the asyncSendQueue does not yet contain the completion
> as it's still being populated in the other thread!
> The resulting null pointer exception is logged as a DEBUG message (!!! bad
> this should be a clear ERROR log with stack trace, it should never happen but
> if it does don't hide it this way !!!)
> Enabling debug logging then shows:
> 2019-09-19_03:53:00.526-DEBUG-[JmsSession
> [ID:811574d5-f47c-4dd3-82e9-c4aa4ce1d9b9:1:1] completion dispatcher]-Send
> completion task encounted unexpected error: null
> \{org.apache.qpid.jms.JmsSession:1567}
>
> Another comment on the logging style, the exception should be logged not
> ex.getMessage() !! (you can't see from the log that it's an NPE this way).
>
> Line 1567:
> {color:#660e7a}LOG{color}.debug({color:#008000}"Send completion task
> encounted unexpected error: {}"{color}, ex.getMessage());
> -->
> {color:#660e7a}LOG{color}.debug({color:#008000}"Send completion task
> encounted unexpected error"{color}, ex);
> (never assume getMessage() contains relevant data, log the stack unless 100%
> sure the exception is known and self descriptive but when are you 100% sure
> about such?)
> The problem is triggered by the design of the code at line 951:
>
> {color:#000080}if {color}(envelope.isCompletionRequired()) {
>
> {color:#660e7a}transactionContext{color}.send({color:#660e7a}connection{color},
> envelope, {color:#000080}new {color}ProviderSynchronization() {
> {color:#808000}@Override{color} {color:#000080}public void
> {color}onPendingSuccess() {
> {color:#808080}// Provider accepted the send request so new we place the
> marker in{color}{color:#808080} // the queue so that it can be completed
> asynchronously.{color}
> {color:#660e7a}asyncSendQueue{color}.addLast({color:#000080}new
> {color}SendCompletion({color:#660e7a}envelope{color},
> {color:#660e7a}listener{color}));
> }
> {color:#808000}@Override{color} {color:#000080}public void
> {color}onPendingFailure(ProviderException cause) {
> {color:#808080}// Provider has rejected the send request so we will throw
> the{color}{color:#808080} // exception that is to follow so no completion
> will be needed.{color} }
> });
> First the message is sent (and the sending is actually completed before the
> onPendingSuccess() is ever called!
> The design of this code should be changed to first record the outstanding
> send operation (so first do the asyncSendQueue.addLast) BEFORE sending the
> message.
> The method onPendingFailure can then implement logic to remove the
> SendCompletion from asyncSendQueue in the case the message could not be sent.
>
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
