azure-functions-durable-extension: Durable function fails with `TaskCanceledException` and never gets retried

Hi, we are upgrading two large durable function projects (5k+ orchestrations,150k+ function executions total daily) from in-process 3.1 to isolated 7.

We believe we are hitting this issue in our dev environments while testing and are investigating further. Happy to provide further info if needed. Thanks

(Still haven’t received the support case so will respond here for now)

Why is the host shutting down:

Scheduled shut down of worker instance or scaling; this leads to host shut down and potential cancellation of invocations (these intentionally by design never reach worker or user code). This is normal behaviour, there’s nothing out of place here.

Why are we “losing orchestration functions mid flow and the retry logic not isn’t working”:

TL;DR: Because DF manages ongoing invocations independently of the function host, and so when the host cancels an invocation and fails it (without sending it to the worker), it considers the invocation complete and does not retry it (even though that function invocation never actually executed).

• The orchestrator function get trigger and executes, as part of that an activity function gets invoked.
• We then get a shut down request and so we wait for this activity function to finish.
• We wait for the activity invocation but the orchestrator function itself doesn’t have an active invocation so we don’t consider it active; durable functions manages its own notion of “ongoing invocation” that is separate from the host.
• When the activity function finishes, we flag all invocations as complete and continue to shut down the host fully.
• Then, the orchestrator gets triggered again (because the activity finished), however this invocation request happens after we have begun full shut down so it gets rejected - we cancel and don’t invoke worker or user code.

Next steps:

We are going to try to repro this issue and work with the durable functions team to determine if this is a bug on their side or if we need to design some host changes to help durable handle cancellations so they can retry these invocations later on a different host instance than the one that is shutting down.

Thanks for the detailed response!

For most of our durable functions this isn’t a problem as we are primarily using them to work down a persisted queue or generate denormalized data so we run them again without issue, there are a few exceptions where this isn’t true and causing us a problem but we can work around in the short term.

Regarding the TaskCancelledException my only concern is that these errors are appearing in AppInsights which is what led to us investigating these issues.

The two scenarios that are affecting us are:

1. When we get a TaskCancelledException on a standard function or on the Durable Orchestration entry. These we can’t recover from as it never hits our code but we are seeing the errors in AppInsights, sounds like this isn’t an issue for standard functions as while we are seeing the error in AppInsights it sounds like they are retried by the host and do run. Not the same for Durable where the instance entry in table storage is being failed.
2. When we get a TaskCancelledException on an activity, this is bubbling up to the Orchestration function and we can try to handle this error and retry the Activity but that would be a lot of manual code in every Orchestration function we have.

Ideally, if the TaskCancelledException is happening internally in the host code we’d prefer never to see it or have to handle it as when it occurs and is logged in AppInsights we investigate, triage, etc. I’d be interested to know if you think we should be factoring this exception scenario in and specifically coding for it if it happens on an Activity or do you think this is an error we should never be seeing in AppInsights or handling ourselves.

Many thanks

Richard

I believe I understand what is going on. This appears to be a bug with the durable extension. Well, a misunderstanding of how function tirggering works. We were relying on the invocation cancellation exception to bubble out and we catch then abort this invocation. However, it does not appear to bubble out and instead surfaces as a function invocation result with a failed status - so we assume this invocation did finish.

@liliankasem something that we can consider is to review this behavior. We can sync offline and I’ll go over what I have found.

For the meantime, I am going to transfer this issue to the durable extension repo and address it there.

Thanks @jviau

I might need a little help understanding that. We are not referencing Microsoft.Azure.WebJobs.Extensions.DurableTask we are only referencing Microsoft.Azure.Functions.Worker.Extensions.DurableTask in isolated, this hasn’t had a release since 1.0.2 (April 7th 2023). I’m not seeing any dependencies to Microsoft.Azure.WebJobs.Extensions.DurableTask.

As I understand it Microsoft.Azure.WebJobs.Extensions.DurableTask is for the legacy and soon to be deprecated in-process with .net 8 I believe.

We’ve moved all our functions to isolated and removed all legacy packages for in-process and referencing the new ones such as Microsoft.Azure.Functions.Worker.Extensions.DurableTask. This is where we are seeing the problem, we never saw it in in-process on core/net5/6.

Many thanks.

@RichardBurns1982 , which version of the Durable Functions worker extension are you using?

“losing orchestration functions mid flow”

And these never start back up? Can you record the instance ID of one of these and call the get instance status API for one of these orchestrations: https://learn.microsoft.com/en-us/azure/azure-functions/durable/durable-functions-http-api#get-instance-status I want to know what state they are in.

It would also be helpful to get the type of trigger that is used by “***ShippingOrchestrationFunction”

Hello

Apologies for the slow reply!

We having been keeping pace with latest version as released. We are currently on:

Microsoft.Azure.Functions.Worker - 1.13.0 Microsoft.Azure.Functions.Worker.Extensions.DurableTask - 1.0.2

***ShippingOrchestrationFunction is an orchestration instance which is started by a Timer trigger.

These orchestration functions run a queue down so we aren’t too concerned about these failing as the next timer trigger will get it back up and running again and continue to work the queue down. Because of this, we try catch at the orchestration function in this instance and even in the event of an exception we handle and let the orchestration function complete successfully as we know it’ll start a new instance from our timer trigger if one isn’t running.

In the example details I have below the orchestration instance has a status of Failed which can’t happen from our code as we are handling and logging exceptions but not letting them bubble up and fail the orchestration instance.

Hopefully this helps to track down the problem as something before our Orchestration function is invoked has failed the durable task.

App Insights: InvocationId: 1e02dcd1-36e3-4bf3-b154-41acec35ed95 Exception type: System.Threading.Tasks.TaskCanceledException FormattedMessage: Executed ‘Functions.ReconcileTransactionLocationsShippingOrchestrationFunction’ (Failed, Id=1e02dcd1-36e3-4bf3-b154-41acec35ed95, Duration=24ms)

Associated Table Storage Durable Function: Partition Key: 74e3409e5dec5610b457dbfd1a25691d ExecutionId: 16cb566b7a164ca3b656c26c393bf1e3 Created Time: 2023-04-23T02:00:00.4598939Z Runtime Status: Failed Output:

{"message":"Function 'ReconcileTransactionLocationsShippingOrchestrationFunction' failed with an unhandled exception.","details":"System.Threading.Tasks.TaskCanceledException: A task was canceled.\r\n   at Microsoft.Azure.WebJobs.Script.Description.WorkerFunctionInvoker.InvokeCore(Object[] parameters, FunctionInvocationContext context) in /_/src/WebJobs.Script/Description/Workers/WorkerFunctionInvoker.cs:line 96\r\n   at Microsoft.Azure.WebJobs.Script.Description.FunctionInvokerBase.Invoke(Object[] parameters) in /_/src/WebJobs.Script/Description/FunctionInvokerBase.cs:line 82\r\n   at Microsoft.Azure.WebJobs.Script.Description.FunctionGenerator.Coerce[T](Task`1 src) in /_/src/WebJobs.Script/Description/FunctionGenerator.cs:line 225\r\n   at Microsoft.Azure.WebJobs.Host.Executors.FunctionInvoker`2.InvokeAsync(Object instance, Object[] arguments) in C:\\projects\\azure-webjobs-sdk-rqm4t\\src\\Microsoft.Azure.WebJobs.Host\\Executors\\FunctionInvoker.cs:line 52\r\n   at Microsoft.Azure.WebJobs.Extensions.DurableTask.OutOfProcMiddleware.<>c__DisplayClass10_0.<<CallOrchestratorAsync>b__0>d.MoveNext() in D:\\a\\_work\\1\\s\\src\\WebJobs.Extensions.DurableTask\\OutOfProcMiddleware.cs:line 124\r\n--- End of stack trace from previous location ---\r\n   at Microsoft.Azure.WebJobs.Host.Executors.TriggeredFunctionExecutor`1.<>c__DisplayClass7_0.<<TryExecuteAsync>b__0>d.MoveNext() in C:\\projects\\azure-webjobs-sdk-rqm4t\\src\\Microsoft.Azure.WebJobs.Host\\Executors\\TriggeredFunctionExecutor.cs:line 50\r\n--- End of stack trace from previous location ---\r\n   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.InvokeWithTimeoutAsync(IFunctionInvoker invoker, ParameterHelper parameterHelper, CancellationTokenSource timeoutTokenSource, CancellationTokenSource functionCancellationTokenSource, Boolean throwOnTimeout, TimeSpan timerInterval, IFunctionInstance instance) in C:\\projects\\azure-webjobs-sdk-rqm4t\\src\\Microsoft.Azure.WebJobs.Host\\Executors\\FunctionExecutor.cs:line 581\r\n   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithWatchersAsync(IFunctionInstanceEx instance, ParameterHelper parameterHelper, ILogger logger, CancellationTokenSource functionCancellationTokenSource) in C:\\projects\\azure-webjobs-sdk-rqm4t\\src\\Microsoft.Azure.WebJobs.Host\\Executors\\FunctionExecutor.cs:line 527\r\n   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithLoggingAsync(IFunctionInstanceEx instance, FunctionStartedMessage message, FunctionInstanceLogEntry instanceLogEntry, ParameterHelper parameterHelper, ILogger logger, CancellationToken cancellationToken) in C:\\projects\\azure-webjobs-sdk-rqm4t\\src\\Microsoft.Azure.WebJobs.Host\\Executors\\FunctionExecutor.cs:line 306\r\n   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.ExecuteWithLoggingAsync(IFunctionInstanceEx instance, FunctionStartedMessage message, FunctionInstanceLogEntry instanceLogEntry, ParameterHelper parameterHelper, ILogger logger, CancellationToken cancellationToken) in C:\\projects\\azure-webjobs-sdk-rqm4t\\src\\Microsoft.Azure.WebJobs.Host\\Executors\\FunctionExecutor.cs:line 352\r\n   at Microsoft.Azure.WebJobs.Host.Executors.FunctionExecutor.TryExecuteAsync(IFunctionInstance functionInstance, CancellationToken cancellationToken) in C:\\projects\\azure-webjobs-sdk-rqm4t\\src\\Microsoft.Azure.WebJobs.Host\\Executors\\FunctionExecutor.cs:line 108"}

Support Request Id: 2304190050002817

We can provide as many invocation ids as required across multiple environments.

Thanks again for all the responses, it’s appreciated.

@liliankasem Thanks for you help, just to be clear do you mean a support request within our Azure subscription?

Yup!