Azure / azure-service-bus-dotnet

☁️ .NET Standard client library for Azure Service Bus
https://azure.microsoft.com/services/service-bus
Other
235 stars 120 forks source link

System.ObjectDisposedException thrown by MessageReceiver.OnReceiveAsync #599

Open NickMoores opened 6 years ago

NickMoores commented 6 years ago

Actual Behavior

  1. Call RegisterMessageHandler on a MessageReceiver with AutoComplete=true. Provide an onExceptionHandler that logs to an ILogger.
  2. After several days of receiving messages in a windows service, the following exception was provided to the onExceptionHandler, and then emitted twice more in the same hour, before the windows service was stopped manually.
System.ObjectDisposedException: Cannot access a disposed object.
Object name: '$cbs'.
   at Microsoft.Azure.ServiceBus.Core.MessageReceiver.<OnReceiveAsync>d__86.MoveNext()
--- 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 Microsoft.Azure.ServiceBus.Core.MessageReceiver.<>c__DisplayClass64_0.<<ReceiveAsync>b__0>d.MoveNext()
--- 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 Microsoft.Azure.ServiceBus.RetryPolicy.<RunOperation>d__20.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at Microsoft.Azure.ServiceBus.RetryPolicy.<RunOperation>d__20.MoveNext()
--- 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 Microsoft.Azure.ServiceBus.Core.MessageReceiver.<ReceiveAsync>d__64.MoveNext()
--- 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 Microsoft.Azure.ServiceBus.Core.MessageReceiver.<ReceiveAsync>d__62.MoveNext()
--- 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 Microsoft.Azure.ServiceBus.MessageReceivePump.<MessagePumpTaskAsync>d__11.MoveNext()

Expected Behavior

  1. No ObjectDisposedException thrown.

Versions

AceHack commented 5 years ago

I've seen the same thing, I've also seen.

exception: "Microsoft.Azure.ServiceBus.MessageLockLostException: The lock supplied is invalid. Either the lock expired, or the message has already been removed from the queue, or was received by a different receiver instance. at Microsoft.Azure.ServiceBus.Core.MessageReceiver.DisposeMessagesAsync(IEnumerable1 lockTokens, Outcome outcome) at Microsoft.Azure.ServiceBus.RetryPolicy.RunOperation(Func1 operation, TimeSpan operationTimeout) at Microsoft.Azure.ServiceBus.RetryPolicy.RunOperation(Func1 operation, TimeSpan operationTimeout) at Microsoft.Azure.ServiceBus.Core.MessageReceiver.CompleteAsync(IEnumerable1 lockTokens) at Microsoft.Azure.ServiceBus.MessageReceivePump.CompleteMessageIfNeededAsync(Message message)"

SeanFeldman commented 5 years ago

MessageLockLostException is normal if you've exceeded max lock duration time.

On the other hand, ObjectDisposedException could be related to a bug fixed in a dependency AMQP library.

AceHack commented 5 years ago

So it’s normal to get the message lock in the receive error handler instead of a message in the receive handler? Seems like some internal logic underneath dropped the ball to me for that to happen.

SeanFeldman commented 5 years ago

So it’s normal to get the message lock in the receive error handler instead of a message in the receive handler? Seems like some internal logic underneath dropped the ball to me for that to happen.

Could you please share a repro or a sample code to look at? The devil is in details, as we all know.

AceHack commented 5 years ago

See below. Every once in a while, very random, The ReceiveExceptionAsync handler gets called with the MessageLockLostException like something internal went wrong listening on the subscription. This is with no message being received from ReceiveAsync handler.

var c = new SubscriptionClient(...)
c.RegisterMessageHandler(ReceiveAsync, ReceiveExceptionAsync);
...
Task ReceiveAsync(Message message, CancellationToken cancellationToken)
{
    _logger.Log("Got Message");
}
...
Task ReceiveExceptionAsync(ExceptionReceivedEventArgs exceptionReceivedEventArgs)
{
    _logger.Log(exceptionReceivedEventArgs.Exception.ToString());
}
SeanFeldman commented 5 years ago

Can you log aside from exception also details such as what operation caused error handler to be invoked?

AceHack commented 5 years ago

I don't understand, it was just sitting there subscribed you can from the stack it was in some message pump code. See below for the operation that sets up the error handler to be invoked.

c.RegisterMessageHandler(ReceiveAsync, ReceiveExceptionAsync);

SeanFeldman commented 5 years ago

ExceptionReceivedEventArgs.ExceptionReceivedContext.Action what I was after. Must have been receive. If that's the case, the message you got somehow had its lock token expired. If you can share a repro, please do.

xinchen10 commented 5 years ago

ObjectDisposedException with type "$cbs" means the underlying AMQP connection is closing while a put-token request is being made. OperationCanceledException may be a better exception type for this error condition. In a later major release of the AMQP library we are going to change the exception type. For now the application or upper layer SDK needs to handle ObjectDisposedException and retry.

SeanFeldman commented 5 years ago

@xinchen10 I'd almost want to see ASB client handling this and throwing ServiceBusException, setting IsTransient to true to indicate an operation should be retried.

ghost commented 5 years ago

What is it that as consumers of this library we should do when encountering this exception? It seems as this is just a transient issue and we don't need to retry explicitly? @xinchen10 looks like you are part of the Azure AMQP library so I'm thinking that the retry comment was for this library to handle.