Orchestration is stuck in the Running state

[andrey-malkov]

I've already gone through the troubleshooting guide, but it doesn't provide a solution for our specific case.

Our workflow is designed to scan the backlog table and initiate sub-orchestrator workflows to process backlog items. To manage iterations efficiently, we use the eternal orchestration pattern with ContinueAsNew, preventing performance issues associated with infinite loops. Additionally, we introduce delays between iterations using the IDurableOrchestrationContext.CreateTimer method.

using var pullingJobCts = new CancellationTokenSource();
await context.CreateTimer(context.CurrentUtcDateTime.Add(TimeSpan.FromMinutes(1)), pullingJobCts.Token);

We've been experiencing this issue for quite some time. Over the past two weeks, out of thousands of executions, approximately a dozen workflow instances have become stuck. Using the VS Code extension, I can see that the last recorded operation for these stuck workflows is TimerCreated.

I was finally able to capture messages for these instances in the control queue

Instance ID				Message ID				Deqeue count
38bf0b8588db420e8c5b992d47a8e735:1705	b7bde336-9125-4859-8dd7-d259dd0d4204	4549 
58dbd6970a4e4d8895a03af0a8fa1fad:998	bba78a46-7222-483a-87e1-74f76d0e17df 	6944 

their dequeue count values suggest that after the delay, the expected message to resume computation was never received, since 17 and 22 Jan. I've attached the messages body. You can see the event type is TimerFiredEvent.

b7bde336-9125-4859-8dd7-d259dd0d4204.json
bba78a46-7222-483a-87e1-74f76d0e17df.json

In the logs I found errors

2025-01-31T21:45:32Z [Error] An unexpected failure occurred while processing instance '58dbd6970a4e4d8895a03af0a8fa1fad:998': DurableTask.AzureStorage.Storage.DurableTaskStorageException: An error occurred while communicating with Azure Storage
---> Azure.RequestFailedException: The specified blob does not exist.

error-38bf0b8588db420e8c5b992d47a8e735-1705.txt
error-58dbd6970a4e4d8895a03af0a8fa1fad-998.txt

Thanks,
Andrei

[AnatoliB]

Seems to be related to Azure/durabletask#802

[AnatoliB]

@andrey-malkov While we investigate the root cause, would you be able to apply the workaround mentioned at Azure/durabletask#802 (comment)?

We solved our problem by replacing our calls to context.ContinueAsNew by context.StartNewOrchestration, after which no new failing instances were reported.

[andrey-malkov]

@AnatoliB yes I can try this approach, thank you.

We have two stuck instances in the green stage, and today got 5 new ones in the active blue stage. Please let me know if you need the app names, probably you can collect some additional info about the issue.

[andrey-malkov]

@AnatoliB I can't switch the implementation to StartNewOrchestration, by design we need ContinueAsNew

[AnatoliB]

@andrey-malkov We need your help to investigate it from the storage end. Please enable collecting storage diagnostic logs (Azure Portal -> Storage account -> Monitoring -> Diagnostic settings. We are interested in all blob operations. Please choose Log Analytics workspace as the destination.

Next, we will be able to find the following data in Log Analytics:

1. For orchestrations that are currently stuck, we can get the missing blob names. Please run the following query:

StorageBlobLogs
| where TimeGenerated > ago(1d)
| where Type == "StorageBlobLogs"
| where StatusText == "BlobNotFound"
| summarize min(TimeGenerated) by OperationName, StatusCode, ObjectKey, Category

The ObjectKey column will contain the blob names, and they will help us understand what kind of blobs are running into these troubles.

2. It would be great if we catch another orchestration getting stuck while these logs are enabled. In this case, we will be able to query the entire history of a problematic blob with a query like this:

StorageBlobLogs
| where TimeGenerated > ago(30d)
| where Type == "StorageBlobLogs"
| where ObjectKey == ... // from the previous query
| summarize min(TimeGenerated), max(TimeGenerated) by OperationName, StatusCode, StatusText
| order by min_TimeGenerated asc

Based on this query, we will be able to see whether there was an attempt to create this blob at all, or this attempt failed, or it succeeded by the blob got deleted later, etc.

[andrey-malkov]

@AnatoliB here is what I found using first query
/odmteuredtmdata/odmteuredteamsworkers-largemessages/84114ae5cb454be39a7b9411f60ed541:12163/history-0000000000000012-TaskCompleted-5DB6E75A-Result.json.gz
/odmteuredtmdata/odmteuredteamsworkers-largemessages/95ed4db6ab3146f689ed79ca66a9d359:2060/history-000000000000000E-TaskCompleted-11FAA563-Result.json.gz
/odmteuredtmdata/odmteuredteamsworkers-largemessages/0b047a22f90748d4ba0a96a1dc17247b:3829/history-0000000000000016-TaskCompleted-10F6B48F-Result.json.gz

this happened before I enabled the logs, so I am waiting for new occurrence to run second query

[andrey-malkov]

@AnatoliB the issue just occurred in the red worker

Instance ID
16e698a2858c46539d15bcefefc3ffa0:26428

ObjectKey
/odmteuredtmdata/odmteuredteamsworkers-largemessages/16e698a2858c46539d15bcefefc3ffa0:26428/history-00000000000000B5-TaskCompleted-07072749-Result.json.gz

Second query result

[andrey-malkov]

seems it's normal that blobs with the history prefix are deleted regularly, in the browser I see them only if "show deleted blobs" option is selected