Delayed Retry on send error

1

I got these delayed retries, due to an “access denied”, when sending Commands to a foreign queue (RMQ). They are sent from a background Thread and not from a MessageHandler. Actually I was expecting an Exception when sending the Commands, but these errors happens after send. I have some questions

  • Are these messages durable? (also after service restart)
  • Where do they end if the error continues?
  • What is the behavior if I was using RequireImmediateDispatch? (I am not)

Delayed Retry will reschedule message ‘0b88ec10-bff6-4dce-a039-af690143fbad’ after a delay of 00:00:10 because of an exception:

System.Exception: Channel has been closed: AMQP close-reason, initiated by Peer, code=403, text='ACCESS_REFUSED - access to exchange 'MY_QUEUE' in vhost '/' refused for user 'MY_USER'',
 classId=60, methodId=40     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()     
 at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)     
 at NServiceBus.TransportReceiveToPhysicalMessageConnector.<Invoke>d__1.MoveNext() 
 in /_/src/NServiceBus.Core/Pipeline/Incoming/TransportReceiveToPhysicalMessageConnector.cs:line 60  --
 - End of stack trace from previous location where exception was thrown ---   
 at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()     at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)    
 at NServiceBus.MainPipelineExecutor.<Invoke>d__1.MoveNext() in /_/src/NServiceBus.Core/Pipeline/MainPipelineExecutor.cs:line 45  --
 - End of stack trace from previous location where exception was thrown ---     at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()   
 at NServiceBus.Transport.RabbitMQ.MessagePump.<Process>d__29.MoveNext() in /_/src/NServiceBus.Transport.RabbitMQ/Receiving/MessagePump.cs:line 266
2

@Stig_Christensen, can you clarify the part about

Are those commands sent in the context of an incoming message? If so, why from background thread and not from the message handler? If no, can you describe how are they sent?

3

No there is no incoming message, hence no MessageHandler. An old system needs to send Commands to another service, from a calculation thread.

The Commands are send with IMessageSession Send(string destination, object message)

4

In that case there are no retries. If the send operation fails it’s just lost.
You could try using something like:

It’s designed for scenarios like yours.

5

I don’t understand. Why do I get this Exception message then?

Delayed Retry will reschedule message ‘0b88ec10-bff6-4dce-a039-af690143fbad’ after a delay of 00:00:10 because of an exception:

NServicebus 7.4.4

6

Is that so, @mauroservienti? When a message is sent outside of a message handler and the sending operation fails, that should result in an exception, propagated to the user code.

7

How do you get this error? Is that from a log file? Do you have handlers in the endpoint for processing messages?

8

Yes, the log statement is from a log file. And yes there are handlers in the same process with Recoverability set up (Se code below)

I now see that I do not Wait on the IMessageSession Send(string destination, object message) which explains why I didn’t get the Exception on send. But it doesn’t explain the “Delayed Retry will reschedule message” log statement.

 private void SetRecoverability(EndpointConfiguration endpointConfiguration)
    {
      var recoverability = endpointConfiguration.Recoverability();
      recoverability.Delayed(
          customizations: delayed =>
          {
            delayed.NumberOfRetries(5);
            delayed.TimeIncrease(TimeSpan.FromSeconds(10));
          });
      recoverability.Immediate(
          customizations: imm =>
          {
            imm.NumberOfRetries(0);
          });
    }
9

Also I was wondering, does RequireImmediateDispatch make sense when sending outside an MessageHandler context?

10

Lack of awaiting would cause the issue.
The log file shows everything that’s happening. If you had a handler executing and retrying, it would be appearing in the log. If you trying to dissect a problem, isolate it and then observe. Otherwise you’ll have side effects of other features kicking in.

A send operation outside of a message handler is an immediate send already. See docs for details.

11

Great so the API is misleading when sending out of a MessageHandler, very important to know. Yes I now see it in the documentation.

Yes there could be side effect from the Message Handler, but I am pretty sure of my observation. I added a new Send operation to a brand new queue and forgot to grant write access. This is the only Send to this queue, and is only happening outside the MessageHandler context. The “Delayed Retry will reschedule message” Exceptions stack trace contains the RabbitMQ ACCESS_REFUSED to the named queue.

12

I’m a bit lost @Stig_Christensen. Let me recap:

  • the send operation happens outside the context of an incoming message (there is no incoming message and the code that sends is not in a message handler)
  • previously the error was not caught because of a missing await
  • when the send operation fails it goes through a set of retries (at least that’s what stated in the logs)

Is that correct?

In the original message the logs said:

access to exchange ‘MY_QUEUE’

Is MY_QUEUE a queue or an exchange?

Are you, by any chance, using the Transactional Session package?

13

Agree with your recap.
MY_QUEUE is the queue name
I am not using Transactional Session.

I will try to see if I can reproduce the error outside our (very large) code base

14

After I introduced proper waiting, the Exception happens as expected on Send. The “Delayed Retry will reschedule message” also seems to be gone.

Could it be that without the Wait, that the Send was batched with messages sent from within a MessageHandler?

15

When I think about it, a wait wouldn’t/couldn’t change any behavior. I will return if I can reproduce what I have seen