[ 
https://issues.apache.org/jira/browse/QPIDJMS-473?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16933557#comment-16933557
 ] 

Robbie Gemmell commented on QPIDJMS-473:
----------------------------------------

Thanks for the report, we will take a look when we get a chance.

>From your note about performance, I suspect that you are using 'anonymous' 
>producers (either JMSProducer instances, or a MessageProducer created with 
>null as the destination) and that Service Bus isnt advertising support for the 
>'ANONYMOUS-RELAY' capability, meaning the client has to fall back to creating 
>and closing a fixed-address sending link under the covers each time you do a 
>send, which effectively means it is still doing synchronous sending. I suspect 
>the issue is as much or more related to how that fallback process currently 
>works than the placement of the callback queue updates in the higher level, as 
>in the regular cases it wouldn't be possible to receive a disposition back 
>before those steps are taken given they process in a single thread.

Which is all to say, if you are using anonymous producer instances, you might 
instead try using fixed destination MessageProducer instances instead, which 
could both work around the issue and improve performance (first by not opening 
and closing links per send, and separately by allowing actual async sends on 
top).

> NPE in AsyncCompletionTask - race condition
> -------------------------------------------
>
>                 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
>            Priority: Critical
>         Attachments: 
> fix_QPID-JMS-473_race_condition_where_SendCompletion_was_not_placed_on_asyncSendQueue_befo.patch
>
>
> 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: dev-unsubscr...@qpid.apache.org
For additional commands, e-mail: dev-h...@qpid.apache.org

Reply via email to