azure-sdk-for-net icon indicating copy to clipboard operation
azure-sdk-for-net copied to clipboard

ServiceBusTrigger shutdown throws TaskCanceledException

Open ahult opened this issue 3 years ago • 7 comments

We have an Azure Function that listens to a service bus via a batched service bus trigger. It seems that whenever the service bus listener shuts down it throws a TaskCanceledException causing an error log in our application insights. Not seeing any other actual functionality issues besides the error log however. This happens every time the listener shuts down. I hope this is the correct repo to put this issue in considering it's an issue with closing down the function host, but I'm seeing the exception originating from Azure.Messaging.ServiceBus so maybe the issue in on that end?

The trigger for the function looks like this:

[Function("SendEvent")]
public async Task RunAsync([ServiceBusTrigger("%QueueName%", Connection = "ServiceBusConnection", IsBatched = true)] string[] queueItems)
{
	...
}

With the following app settings provided in bicep:

{
	name: 'QueueName'
	value: queueName
}
{
	name: 'ServiceBusConnection__fullyQualifiedNamespace'
	value: servicebusNamespace
}
{
	name: 'ServiceBusConnection__credential'
	value: 'managedIdentity'
}
{
	name: 'ServiceBusConnection__clientId'
	value: serviceBusReceiverIdentityClientId
}

Here's a log from it happening (Oldest event first): image

Full exception here:

prod-queue-fp7nmlxt5whxm-78ceaf7a-012b-42a1-ad14-b80dfbb89c54: ReceiveBatchAsync Exception: System.Threading.Tasks.TaskCanceledException: A task was canceled.
   at Microsoft.Azure.Amqp.AsyncResult.End[TAsyncResult](IAsyncResult result)
   at Microsoft.Azure.Amqp.ReceivingAmqpLink.EndReceiveMessages(IAsyncResult result, IEnumerable`1& messages)
   at Microsoft.Azure.Amqp.ReceivingAmqpLink.<>c.<ReceiveMessagesAsync>b__27_1(IAsyncResult r)
   at System.Threading.Tasks.TaskFactory`1.FromAsyncCoreLogic(IAsyncResult iar, Func`2 endFunction, Action`1 endAction, Task`1 promise, Boolean requiresSynchronization)
--- End of stack trace from previous location ---
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver.ReceiveMessagesAsyncInternal(Int32 maxMessages, Nullable`1 maxWaitTime, TimeSpan timeout, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver.<>c.<<ReceiveMessagesAsync>b__40_0>d.MoveNext()
--- End of stack trace from previous location ---
   at Azure.Messaging.ServiceBus.ServiceBusRetryPolicy.RunOperation[T1,TResult](Func`4 operation, T1 t1, TransportConnectionScope scope, CancellationToken cancellationToken, Boolean logRetriesAsVerbose)
   at Azure.Messaging.ServiceBus.ServiceBusRetryPolicy.RunOperation[T1,TResult](Func`4 operation, T1 t1, TransportConnectionScope scope, CancellationToken cancellationToken, Boolean logRetriesAsVerbose)
   at Azure.Messaging.ServiceBus.Amqp.AmqpReceiver.ReceiveMessagesAsync(Int32 maxMessages, Nullable`1 maxWaitTime, CancellationToken cancellationToken)
   at Azure.Messaging.ServiceBus.ServiceBusReceiver.ReceiveMessagesAsync(Int32 maxMessages, Nullable`1 maxWaitTime, Boolean isProcessor, CancellationToken cancellationToken).

ahult avatar Sep 23 '22 14:09 ahult

@alrod @JoshLove-msft could you please take a look at this and let us know if you need any assistance on our side?

@ahult what plan/SKU are you currently using to host your Function App? That information may help us provide some mitigation options in the meantime.

fabiocav avatar Sep 28 '22 18:09 fabiocav

These errors are a result of the receive operation being cancelled when shutting down. It is logged as an error because it triggers an exception. It should be safe to ignore.

JoshLove-msft avatar Sep 28 '22 18:09 JoshLove-msft

@fabiocav We're hosting our Function App with a Consumption plan:

sku: {
    name: 'Y1'
    tier: 'dynamic'
}

Good to know it's safe to ignore, would be nice if it wasn't an error log though, since it happens so often it makes it easy to miss when other real errors occur. Previous attempts to suppress these logs via raising log level in host.json to Critical for Azure.Messaging.ServiceBus hasn't worked either, it seems these errors still slip through somehow. Maybe because the function is in the process of shutting down?

ahult avatar Sep 29 '22 08:09 ahult

Previous attempts to suppress these logs via raising log level in host.json to Critical for Azure.Messaging.ServiceBus hasn't worked either, it seems these errors still slip through somehow. Maybe because the function is in the process of shutting down?

It should be possible to suppress based on log level, though I wouldn't recommend it if you are needing to filter to Critical. Can you share your host.json config?

JoshLove-msft avatar Sep 29 '22 19:09 JoshLove-msft

Good to know it's safe to ignore, would be nice if it wasn't an error log though, since it happens so often it makes it easy to miss when other real errors occur.

The tricky part here is that the functions just use the ServiceBusReceiver under the hood which throws an exception and logs as an error in this scenario. We'd probably need to introduce new API surface to indicate that the error shouldn't be logged to avoid breaking anyone.

JoshLove-msft avatar Sep 29 '22 19:09 JoshLove-msft

It seems I may have been mistaken as testing again to suppress it does seem to work for me now, but as you say I don't want to raise log level to critical. I have added a filter on our alarms so it doesn't alert us for this specific error message any longer at least, I guess we have to live with the error logs in insights though for a while then.

ahult avatar Sep 30 '22 11:09 ahult

Hi @ahult. Thank you for opening this issue and giving us the opportunity to assist. We believe that this has been addressed. If you feel that further discussion is needed, please add a comment with the text “/unresolve” to remove the “issue-addressed” label and continue the conversation.

ghost avatar Jan 04 '23 20:01 ghost

Hi @ahult, since you haven’t asked that we “/unresolve” the issue, we’ll close this out. If you believe further discussion is needed, please add a comment “/unresolve” to reopen the issue.

ghost avatar Jan 11 '23 22:01 ghost

/unresolve

rejidasan-gd avatar Feb 18 '23 18:02 rejidasan-gd

Hi rejidasan-gd, only the original author of the issue can ask that it be unresolved. Please open a new issue with your scenario and details if you would like to discuss this topic with the team.

ghost avatar Feb 18 '23 18:02 ghost

Hi this issue is still happening for me. I can open a new issue

rejidasan-gd avatar Feb 18 '23 18:02 rejidasan-gd