Durable Functions CallActivityWithRetryAsync - Final Timer Not Accurate and Final Retry Never Executes

Jennifer Gonzalez 0 Reputation points
2023-03-30T22:36:12.6833333+00:00

I have a durable sub-orchestration which executes a CallActivityWithRetryAsync method using the following retry options:

var retryOptions = new RetryOptions(
    firstRetryInterval: TimeSpan.FromSeconds(5),
    maxNumberOfAttempts: 3);


await context.CallActivityWithRetryAsync("CancelOrder", retryOptions, request);

While testing an exception from the activity function, I am running into a strange issue with the retries. When I query the status of the sub-orchestration (using an HttpTrigger function that calls DurableClient.GetStatusAsync) this is the response (some of the proprietary data has been removed):

{
    "name": "IsTransferringOrchestrator",
    "instanceId": "bd84dcf77f23495b8b5dee143896a728:2",
    "createdTime": "2023-03-29T19:03:11.08446Z",
    "lastUpdatedTime": "2023-03-29T19:03:34.4080343Z",
    "input": {"proprietary data was here"},
    "output": null,
    "runtimeStatus": 0,
    "customStatus": 6,
    "history": [
        {
            "EventType": "ExecutionStarted",
            "Correlation": null,
            "ScheduledStartTime": null,
            "Generation": null,
            "Timestamp": "2023-03-29T19:03:11.08446Z",
            "FunctionName": "IsTransferringOrchestrator"
        },
        {
            "EventType": "TaskCompleted",
            "Timestamp": "2023-03-29T19:03:11.6793767Z",
            "ScheduledTime": "2023-03-29T19:03:11.1282732+00:00",
            "FunctionName": "UpdateTransferRequest"
        },
        {
            "EventType": "TaskCompleted",
            "Timestamp": "2023-03-29T19:03:13.5218006Z",
            "ScheduledTime": "2023-03-29T19:03:11.7068913+00:00",
            "FunctionName": "UpdateAttributes"
        },
        {
            "EventType": "TaskFailed",
            "Reason": "Activity function 'CancelOrder' failed",
            "FailureDetails": null,
            "Timestamp": "2023-03-29T19:03:17.698385Z",
            "ScheduledTime": "2023-03-29T19:03:13.543431+00:00",
			"FunctionName": "CancelOrder"
        },
        {
            "EventType": "TimerCreated",
            "FireAt": "2023-03-29T19:03:22.7302813Z",
            "Timestamp": "2023-03-29T19:03:17.7464718Z"
        },
        {
            "EventType": "TimerFired",
            "FireAt": "2023-03-29T19:03:22.7302813Z",
            "Timestamp": "2023-03-29T19:03:17.7464781Z"
        },
        {
            "EventType": "TaskFailed",
            "Reason": "Activity function 'CancelOrder' failed",
            "FailureDetails": null,
            "Timestamp": "2023-03-29T19:03:26.497628Z",
            "ScheduledTime": "2023-03-29T19:03:25.1508584+00:00",
            "FunctionName": "CancelOrder"
        },
        {
            "EventType": "TimerCreated",
            "FireAt": "2023-03-29T19:03:31.5337702Z",
            "Timestamp": "2023-03-29T19:03:26.5360503Z"
        },
        {
            "EventType": "TimerFired",
            "FireAt": "2023-03-29T19:03:31.5337702Z",
            "Timestamp": "2023-03-29T19:03:26.5360507Z"
        },
        {
            "EventType": "TaskFailed",
            "Reason": "Activity function 'CancelOrder' failed",
            "FailureDetails": null,
            "Timestamp": "2023-03-29T19:03:34.3241067Z",
            "ScheduledTime": "2023-03-29T19:03:33.5912344+00:00",
            "FunctionName": "CancelOrder"
        },
        {
            "EventType": "TimerCreated",
            "FireAt": "2023-03-29T19:03:34.3492792Z",
            "Timestamp": "2023-03-29T19:03:34.3515773Z"
        },
        {
            "EventType": "TimerFired",
            "FireAt": "2023-03-29T19:03:34.3492792Z",
            "Timestamp": "2023-03-29T19:03:34.3515777Z"
        }
    ]
}

You can see that the first 2 timers that are created are setup correctly, with the "FireAt" time being set to a 5 second delay from the timer's creation. The final timer, strangely, has a "FireAt" time that is BEFORE the "Timestamp" of the timer's creation. I believe this is causing the 3rd and final retry to never actually execute (as you can see there is no 3rd retry call to the activity function). This is causing a major issue as the sub-orchestration is left in a perpetually running state (runtimeStatus: 0), instead of a failed state as would be the case if we finished with a "TaskFailed".

Is there something I can change in the logic to get my final retry timer to be set correctly and make sure my 3rd activity retry actually gets called? I need to get my sub-orchestration into a proper failed state and not be stuck at "running" forever.

Not Monitored
Not Monitored
Tag not monitored by Microsoft.
37,798 questions
0 comments No comments
{count} votes