AzureStorage: a permanent history-load failure in ScheduleOrchestrationStatePrefetch increases memory without limit

Start in OrchestrationSessionManager.ScheduleOrchestrationStatePrefetch, in the catch block that logs OrchestrationProcessingFailure, sleeps, and then awaits Task.Run on a recursive call. The retry chain is what keeps each failed attempt's exception alive. The issue says a fix is already in #1418, so check that pull request before starting. Done means a history-load failure that never recovers no longer grows the set of retained exceptions, which the always-failing tracking-store test in #1418 checks.

Summary

When OrchestrationSessionManager.ScheduleOrchestrationStatePrefetch cannot load the history of a pending batch, it logs OrchestrationProcessingFailure and waits 5 seconds. Then it awaits a recursive call of itself in the catch block:

catch (Exception e)
{
    this.settings.Logger.OrchestrationProcessingFailure(...);

    // Sleep briefly to avoid a tight failure loop.
    await Task.Delay(TimeSpan.FromSeconds(5));

    // This is a background operation so failure is not an option. All exceptions must be handled.
    // To avoid starvation, we need to re-enqueue this async operation instead of retrying in a loop.
    await Task.Run(() => this.ScheduleOrchestrationStatePrefetch(node, traceActivityId, cancellationToken));
}

If the failure is permanent, no attempt completes. Each failed attempt then stays in memory, and memory increases without a limit while the process runs.

Cause

• The catch block contains await. Thus, the compiler keeps the caught exception in a state-machine field (<>7__wrap2). The code clears this field only after the awaited recursive call completes.
• Task.Run(Func<Task>) returns a proxy task (UnwrapPromise). The proxy completes only when the inner task completes.
• Thus, each attempt keeps the previous attempt. Each exception keeps its Azure.RequestFailedException and the Azure.Response (HTTP request, response, headers, and content stream).
• The path from the GC root is: timer queue -> Task+DelayPromise (the 5-second delay) -> newest state machine -> UnwrapPromise -> older state machine -> ... -> oldest state machine.

The awaited recursion came from #633. Before #633, the retry put a new work item in a DispatchQueue and then returned. Thus, a failed attempt did not wait for the next attempt.

Affected versions

DurableTask.AzureStorage 1.9.4 and later. The retry code is the same in 2.0.0, 2.10.0, and main (99296e0f).

What we saw

• A worker process on DurableTask.AzureStorage 2.0.0 (.NET 10) ran for 14 days. A full-memory dump had 239,392 live AsyncStateMachineBox<...<ScheduleOrchestrationStatePrefetch>d__25> objects. It had the same number of DurableTaskStorageException, Azure.RequestFailedException, HttpRequestMessage, and HttpResponseMessage objects. Together they used about 2.7 GB, which was almost all of the live managed heap.
• One orchestration instance caused all of it. Its history referred to a large-message blob that did not exist (404 BlobNotFound). 239,392 attempts x 5.04 seconds = the process uptime.

Repro

Use Microsoft.Azure.DurableTask.AzureStorage 2.0.0, Microsoft.Azure.DurableTask.Core 3.0.0, and Azurite:

1. Start an orchestration that calls an activity. The activity returns a string of 50,000 characters, so the History row stores the result in the {taskhub}-largemessages container. Then the orchestration waits for an external event.
2. Delete the result blob of that History row.
3. Raise an event to the instance.

Result:

Time after the event	Failed attempts	Live prefetch state machines	Live exception pairs
60 s	12	12	12
210 s	40	40	40

The heap increased by about 12 KB for each attempt. When the same blob was uploaded again, the next attempt was successful, and all the retained objects were released.

The new unit test in #1418 shows the same behavior with a tracking store that always fails. Without the fix, all 19 earlier exceptions stay in memory.

Triggers

Each history-load failure that does not stop causes this problem. Examples:

• A History row refers to a large-message blob that does not exist. In 2.0.0, one cause is a late message for an execution that ContinueAsNew replaced. #1189 fixed that case in 2.1.0. A missing blob of the current execution has the same effect in 2.10.0 and main.
• A permanent authorization failure (403), a missing History table, or invalid event data.

Other notes

• No setting controls this retry. The delay does not use the cancellation token.
• A partition lease move does not stop the retries. A new owner of the partition can start its own chain for the same instance.

Related

• #1215 (the same stack trace), #802, and #1189.
• Fix: #1418