Lab Guide: Durable Functions Replay Storm on Azure Functions Premium EP1¶

This lab guide documents a completed Azure Functions Premium EP1 experiment that captured a real Durable Functions replay storm. The objective is to prove, with reproducible evidence, that orchestration replay overhead can dominate end-to-end completion time even when activity execution remains stable.

Lab Metadata¶

1) Background¶

Durable Functions orchestrators are deterministic and replay event history every time the orchestration wakes. This is expected behavior, but replay cost scales with history size. If a long-running orchestration never resets history, replay overhead can increase enough to suppress throughput and inflate wall-clock completion time.

Replay growth model used in this lab¶

flowchart TD
    A[Large orchestration loop] --> B[History grows each iteration]
    B --> C[Every wake-up replays prior history]
    C --> D["Replay CPU/time per execution increases"]
    D --> E[Orchestrator request duration rises]
    E --> F[Executions per time window drop]
    F --> G[Wall-clock completion inflates]
    H[ContinueAsNew every N] --> I[History reset]
    I --> J[Replay cost returns to low baseline]
    J --> K[Throughput recovers]

Test topology and evidence channels¶

sequenceDiagram
    participant Operator as Lab Operator
    participant Start as HTTP Starter
    participant Orch as Durable Orchestrator
    participant Act as Durable Activity
    participant Hub as Durable Task Hub (Storage)
    participant AI as Application Insights

    Operator->>Start: POST /api/durable/start-replay-lab
    Start->>Orch: Start instance with input
    Orch->>Hub: Read history and schedule work
    Orch->>Act: call replay_lab_activity
    Act-->>Orch: Return tiny payload
    Orch->>AI: Emit ReplayIteration traces every 50 iterations
    Orch->>Hub: Append new durable events
    Operator->>AI: Query requests and traces

Experiment phases¶

Key known-good control signal¶

The activity body (replay_lab_activity) remained in the same latency band across all phases:

• Baseline: avg around 2.7 ms
• Incident: avg around 3.0-3.4 ms
• Recovery: avg around 2.8 ms

This is the primary control signal that isolates replay overhead as the changing variable.

RBAC discovery during setup (important context)¶

Before collecting replay evidence, the function host initially failed to index Durable functions because managed identity permissions were incomplete. Specifically, Storage Table Data Contributor was missing, causing 403 AuthorizationPermissionMismatch errors against task hub table operations.

The Bicep role set originally included Blob, Queue, File, and Account roles, but not Table role. Adding Table access fixed host indexing and enabled lab execution.

Required storage RBAC role set for this Durable setup:

1. Storage Account Contributor
2. Storage Blob Data Owner
3. Storage File Data Privileged Contributor
4. Storage Queue Data Contributor
5. Storage Table Data Contributor

Why this distinction matters¶

Replay incidents and storage authorization failures can both present as "Durable is slow/not progressing." This lab separates them:

• RBAC issue: startup/indexing failure, orchestration cannot run correctly
• Replay storm: orchestration runs, activity remains fast, orchestrator duration degrades with history growth

Phase-level objective map¶

Time-compression view of the run¶

gantt
    title Durable Replay Storm Experiment Timeline (UTC)
    dateFormat  HH:mm:ss
    axisFormat  %H:%M
    section Baseline
    50 iterations no reset                 :done, b1, 12:28:36, 5s
    section Incident
    2000 iterations no ContinueAsNew       :crit, i1, 12:29:22, 26m
    section Recovery
    2000 iterations ContinueAsNew=250      :done, r1, 12:56:18, 5m

Ground truth summary used in this document¶

2) Hypothesis¶

In this EP1 deployment, the severe slowdown in the 2000-iteration run is caused by replay overhead growth in the orchestrator history, not activity execution latency. Therefore, orchestrator duration should rise and throughput should fall during the no-reset run, while activity duration remains flat. Applying ContinueAsNew every 250 iterations should restore orchestrator duration and throughput to near-baseline ranges.

Causal chain¶

flowchart LR
    A[No ContinueAsNew] --> B[History size increases continuously]
    B --> C[Replay work per wake-up increases]
    C --> D[Orchestrator duration increases]
    D --> E[Executions per 2-minute bin decrease]
    E --> F[Total wall-clock completion inflates]
    G[ContinueAsNew every 250] --> H[History reset seven times]
    H --> I[Replay cost repeatedly returns to low baseline]
    I --> J[Orchestrator duration returns to ~45-47ms]
    J --> K[2000-iteration run completes in ~5 minutes]

Competing hypotheses and disproof criteria¶

Proof checklist¶

Falsification statement¶

The hypothesis would be rejected if either of the following were true:

• activity latency rose proportionally with orchestrator latency
• recovery with ContinueAsNew=250 did not restore duration and throughput

Neither condition occurred in the evidence.

3) Runbook¶

Variables (generic first, then concrete values)¶

RG="<resource-group>"
APP_NAME="<function-app-name>"
STORAGE_NAME="<storage-account-name>"
LOCATION="<azure-region>"
AI_APP_ID="<app-insights-app-id>"

Concrete values used in this completed experiment:

RG="rg-lab-ep1-shared"
APP_NAME="labep1shared-func"
STORAGE_NAME="labep1sharedstorage"
LOCATION="koreacentral"
AI_APP_ID="928dbc99-8353-4e70-889b-860f3401220e"

3.1 Validate deployment context¶

az functionapp show \
  --name "$APP_NAME" \
  --resource-group "$RG" \
  --output table

az storage account show \
  --name "$STORAGE_NAME" \
  --resource-group "$RG" \
  --output table

az monitor app-insights component show \
  --app "$AI_APP_ID" \
  --resource-group "$RG" \
  --output table

3.2 Validate Durable storage RBAC for managed identity¶

PRINCIPAL_ID=$(az functionapp identity show \
  --name "$APP_NAME" \
  --resource-group "$RG" \
  --query principalId \
  --output tsv)

STORAGE_SCOPE=$(az storage account show \
  --name "$STORAGE_NAME" \
  --resource-group "$RG" \
  --query id \
  --output tsv)

az role assignment list \
  --assignee "$PRINCIPAL_ID" \
  --scope "$STORAGE_SCOPE" \
  --output table

Expected role set:

3.3 Start baseline phase (50 iterations, no reset)¶

curl --request POST \
  --url "https://${APP_NAME}.azurewebsites.net/api/durable/start-replay-lab" \
  --header "Content-Type: application/json" \
  --data '{"iterations":50,"continueAsNewEvery":0,"instances":1}'

Expected baseline instance ID from recorded run:

7192e16593814d7f859c77558543c1da

3.4 Start incident phase (2000 iterations, no reset)¶

curl --request POST \
  --url "https://${APP_NAME}.azurewebsites.net/api/durable/start-replay-lab" \
  --header "Content-Type: application/json" \
  --data '{"iterations":2000,"continueAsNewEvery":0,"instances":1}'

Expected incident instance ID from recorded run:

7a21e8d1258a488bad8392f1bdfa36bf

3.5 Start recovery phase (2000 iterations, reset every 250)¶

curl --request POST \
  --url "https://${APP_NAME}.azurewebsites.net/api/durable/start-replay-lab" \
  --header "Content-Type: application/json" \
  --data '{"iterations":2000,"continueAsNewEvery":250,"instances":1}'

Expected recovery instance ID from recorded run:

58ce8fb52432461787717b8b1a83256b

3.6 Poll orchestration status (optional operator convenience)¶

INSTANCE_ID="7a21e8d1258a488bad8392f1bdfa36bf"

curl --request GET \
  --url "https://${APP_NAME}.azurewebsites.net/api/durable/status/${INSTANCE_ID}"

3.7 Core KQL queries (requests + traces)¶

Query A: Orchestrator duration timeline in 2-minute bins¶

let BaselineEnd = datetime(2026-04-07 12:29:22Z);
let IncidentEnd = datetime(2026-04-07 12:56:18Z);
let RunEnd = datetime(2026-04-07 13:02:00Z);
let baseline = requests
    | where timestamp >= datetime(2026-04-07 12:28:00Z) and timestamp < BaselineEnd
    | where cloud_RoleName == "labep1shared-func"
    | where operation_Name has "replay_storm_orchestrator"
    | extend phase = "Baseline";
let incident = requests
    | where timestamp >= BaselineEnd and timestamp < IncidentEnd
    | where cloud_RoleName == "labep1shared-func"
    | where operation_Name has "replay_storm_orchestrator"
    | extend phase = "Incident";
let recovery = requests
    | where timestamp >= IncidentEnd and timestamp < RunEnd
    | where cloud_RoleName == "labep1shared-func"
    | where operation_Name has "replay_storm_orchestrator"
    | extend phase = "Recovery";
union baseline, incident, recovery
| summarize
    executions = count(),
    avg_ms = round(avg(toreal(duration / 1ms)), 1),
    p95_ms = round(percentile(toreal(duration / 1ms), 95), 1),
    max_ms = round(max(toreal(duration / 1ms)), 1)
  by phase, bin(timestamp, 2m)
| order by timestamp asc

Query B: Activity duration timeline in 2-minute bins¶

let BaselineEnd = datetime(2026-04-07 12:29:22Z);
let IncidentEnd = datetime(2026-04-07 12:56:18Z);
let RunEnd = datetime(2026-04-07 13:02:00Z);
let baseline = requests
    | where timestamp >= datetime(2026-04-07 12:28:00Z) and timestamp < BaselineEnd
    | where cloud_RoleName == "labep1shared-func"
    | where operation_Name has "replay_lab_activity"
    | extend phase = "Baseline";
let incident = requests
    | where timestamp >= BaselineEnd and timestamp < IncidentEnd
    | where cloud_RoleName == "labep1shared-func"
    | where operation_Name has "replay_lab_activity"
    | extend phase = "Incident";
let recovery = requests
    | where timestamp >= IncidentEnd and timestamp < RunEnd
    | where cloud_RoleName == "labep1shared-func"
    | where operation_Name has "replay_lab_activity"
    | extend phase = "Recovery";
union baseline, incident, recovery
| summarize
    activities = count(),
    avg_ms = round(avg(toreal(duration / 1ms)), 1),
    p95_ms = round(percentile(toreal(duration / 1ms), 95), 1),
    max_ms = round(max(toreal(duration / 1ms)), 1)
  by phase, bin(timestamp, 2m)
| order by timestamp asc

Query C: Orchestrator-by-instance rollup¶

let BaselineId = "7192e16593814d7f859c77558543c1da";
let IncidentId = "7a21e8d1258a488bad8392f1bdfa36bf";
let RecoveryId = "58ce8fb52432461787717b8b1a83256b";
requests
| where cloud_RoleName == "labep1shared-func"
| where operation_Name has "replay_storm_orchestrator"
| where operation_Id in (BaselineId, IncidentId, RecoveryId)
| summarize
    executions = count(),
    avg_ms = round(avg(toreal(duration / 1ms)), 1),
    p95_ms = round(percentile(toreal(duration / 1ms), 95), 1),
    max_ms = round(max(toreal(duration / 1ms)), 1),
    start_time = min(timestamp),
    end_time = max(timestamp)
  by operation_Id
| order by start_time asc

Query D: ReplayIteration traces with parsing¶

let IncidentId = "7a21e8d1258a488bad8392f1bdfa36bf";
traces
| where timestamp >= datetime(2026-04-07 12:28:00Z) and timestamp < datetime(2026-04-07 13:02:00Z)
| where cloud_RoleName == "labep1shared-func"
| where message has "ReplayIteration"
| where operation_Id == IncidentId or operation_ParentId == IncidentId
| parse message with * "batch=" batch:int " iteration=" iter:int "/" total:int " elapsed=" elapsed_ms:real "ms"
| project timestamp, batch, iter, total, elapsed_ms, message
| order by timestamp asc

Query E: ContinueAsNew and completion traces¶

let RecoveryId = "58ce8fb52432461787717b8b1a83256b";
traces
| where timestamp >= datetime(2026-04-07 12:56:00Z) and timestamp < datetime(2026-04-07 13:02:00Z)
| where cloud_RoleName == "labep1shared-func"
| where message has_any ("ContinueAsNew", "Orchestration complete")
| where operation_Id == RecoveryId or operation_ParentId == RecoveryId
| project timestamp, message
| order by timestamp asc

Query F: 50-iteration marker intervals from traces¶

let IncidentId = "7a21e8d1258a488bad8392f1bdfa36bf";
traces
| where timestamp >= datetime(2026-04-07 12:28:00Z) and timestamp < datetime(2026-04-07 13:02:00Z)
| where cloud_RoleName == "labep1shared-func"
| where message has "ReplayIteration"
| where operation_Id == IncidentId or operation_ParentId == IncidentId
| parse message with * "iteration=" iter:int "/" total:int *
| where iter % 50 == 0
| project timestamp, iter, total, message
| order by timestamp asc
| serialize
| extend previous_timestamp = prev(timestamp)
| extend interval_seconds = iif(isnull(previous_timestamp), real(null), toreal(datetime_diff('second', timestamp, previous_timestamp)))

3.8 Execute KQL with Azure CLI¶

az monitor log-analytics query \
  --workspace "$LOG_WORKSPACE_ID" \
  --analytics-query "let StartTime = datetime(2026-04-07 12:28:00Z); let EndTime = datetime(2026-04-07 13:02:00Z); AppRequests | where TimeGenerated >= StartTime and TimeGenerated < EndTime | where AppRoleName == 'labep1shared-func' | where OperationName has 'replay_storm_orchestrator' | summarize executions = count(), avg_ms = round(avg(DurationMs), 1), p95_ms = round(percentile(DurationMs, 95), 1), max_ms = round(max(DurationMs), 1) by bin(TimeGenerated, 2m) | order by TimeGenerated asc" \
  --output table

az monitor log-analytics query \
  --workspace "$LOG_WORKSPACE_ID" \
  --analytics-query "let StartTime = datetime(2026-04-07 12:28:00Z); let EndTime = datetime(2026-04-07 13:02:00Z); AppRequests | where TimeGenerated >= StartTime and TimeGenerated < EndTime | where AppRoleName == 'labep1shared-func' | where OperationName has 'replay_lab_activity' | summarize activities = count(), avg_ms = round(avg(DurationMs), 1), p95_ms = round(percentile(DurationMs, 95), 1), max_ms = round(max(DurationMs), 1) by bin(TimeGenerated, 2m) | order by TimeGenerated asc" \
  --output table

az monitor log-analytics query \
  --workspace "$LOG_WORKSPACE_ID" \
  --analytics-query "AppTraces | where TimeGenerated >= datetime(2026-04-07 12:56:00Z) and TimeGenerated < datetime(2026-04-07 13:02:00Z) | where AppRoleName == 'labep1shared-func' | where Message has_any ('ContinueAsNew', 'Orchestration complete') | project TimeGenerated, Message | order by TimeGenerated asc" \
  --output table

3.9 Decision flow during live troubleshooting¶

flowchart TD
    A[Durable orchestration slowdown detected] --> B{Host indexing healthy?}
    B -->|No| C[Check managed identity + storage RBAC]
    C --> D[Fix missing Table role if absent]
    B -->|Yes| E{Activity duration increasing?}
    E -->|Yes| F["Investigate activity logic/dependencies"]
    E -->|No| G[Investigate replay growth pattern]
    G --> H{ContinueAsNew configured?}
    H -->|No| I[Apply periodic ContinueAsNew]
    H -->|Yes| J[Tune batch size and checkpoint cadence]
    I --> K[Re-run and compare 2-minute bins]
    J --> K

4) Experiment Log¶

4.1 Execution ledger (recorded run)¶

4.2 Orchestrator duration timeline (requests, 2-minute bins)¶

Derived contrasts:

4.3 Activity duration control signal (requests)¶

Cross-check sample bins:

4.4 ReplayIteration progress evidence¶

Observed wall-clock spacing between 50-iteration trace batches:

Recorded trace excerpts from the incident run (instance 7a21e8d1258a488bad8392f1bdfa36bf):

2026-04-07T12:29:42.103Z ReplayIteration instance=0 batch=0 iteration=50/2000 elapsed=1ms
2026-04-07T12:30:02.841Z ReplayIteration instance=0 batch=0 iteration=100/2000 elapsed=2ms
2026-04-07T12:30:22.517Z ReplayIteration instance=0 batch=0 iteration=150/2000 elapsed=3ms
2026-04-07T12:31:05.923Z ReplayIteration instance=0 batch=0 iteration=250/2000 elapsed=5ms
2026-04-07T12:33:12.446Z ReplayIteration instance=0 batch=0 iteration=500/2000 elapsed=10ms
2026-04-07T12:40:17.851Z ReplayIteration instance=0 batch=0 iteration=1000/2000 elapsed=20ms
2026-04-07T12:48:39.203Z ReplayIteration instance=0 batch=0 iteration=1500/2000 elapsed=35ms
2026-04-07T12:52:44.617Z ReplayIteration instance=0 batch=0 iteration=1850/2000 elapsed=45ms
2026-04-07T12:55:28.492Z ReplayIteration instance=0 batch=0 iteration=2000/2000 elapsed=53ms

4.5 ContinueAsNew evidence (7 resets + final completion)¶

The recovery run emitted seven reset transitions and one completion event.

Recorded trace excerpts from the recovery run (instance 58ce8fb52432461787717b8b1a83256b):

2026-04-07T12:56:52.114Z ContinueAsNew at iteration 250/2000, batch=0, resetting history
2026-04-07T12:57:23.507Z ContinueAsNew at iteration 500/2000, batch=1, resetting history
2026-04-07T12:57:55.891Z ContinueAsNew at iteration 750/2000, batch=2, resetting history
2026-04-07T12:58:27.204Z ContinueAsNew at iteration 1000/2000, batch=3, resetting history
2026-04-07T12:58:59.618Z ContinueAsNew at iteration 1250/2000, batch=4, resetting history
2026-04-07T12:59:31.033Z ContinueAsNew at iteration 1500/2000, batch=5, resetting history
2026-04-07T13:00:03.447Z ContinueAsNew at iteration 1750/2000, batch=6, resetting history
2026-04-07T13:01:21.862Z Orchestration complete: instance=0 total=2000 batches=8

Transition table:

4.6 Phase-by-phase interpretation¶

4.7 Normal vs abnormal profile¶

4.8 Common misdiagnoses observed in this lab¶

4.9 RBAC discovery log (separate from replay root cause)¶

4.10 Evidence verdict¶

Final verdict: Hypothesis supported.

Expected Evidence¶

Before Trigger (Baseline)¶

During Incident¶

After Recovery¶

Evidence Timeline¶

gantt
    title Durable Replay Storm Evidence Timeline (EP1)
    dateFormat  HH:mm:ss
    axisFormat  %H:%M
    section Baseline
    Baseline start                                 :milestone, m1, 12:28:36, 0s
    Baseline complete                              :milestone, m2, 12:28:41, 0s
    section Incident
    Incident start                                 :milestone, m3, 12:29:22, 0s
    Orchestrator avg reaches ~356ms (mid incident) :crit, i1, 12:36:00, 2m
    Orchestrator avg reaches ~641ms (peak)         :crit, i2, 12:52:00, 2m
    Incident complete                              :milestone, m4, 12:55:28, 0s
    section Recovery
    Recovery start                                 :milestone, m5, 12:56:18, 0s
    ContinueAsNew sequence active                  :done, r1, 12:56:20, 4m
    Recovery complete                              :milestone, m6, 13:01:21, 0s

Evidence Chain: Why This Proves the Hypothesis¶

Evidence chain matrix:

Query-to-evidence mapping¶

Operator verification checklist¶

1. Confirm every duration conversion snippet uses toreal(duration / 1ms).
2. Confirm instance IDs and timestamps match the run ledger.
3. Confirm no fake minute-indexed telemetry IDs are present.
4. Confirm tail order is See Also then Sources.

Clean Up¶

If this was a temporary environment, remove the resource group.

az group delete \
  --name "$RG" \
  --yes \
  --no-wait

If this is a shared EP1 lab environment, skip deletion and only stop test traffic.

Related Playbook¶

• Durable replay and orchestration latency playbook

See Also¶

• Lab guide: Cold start
• Lab guide: Timer missed schedules
• Lab guide: Queue backlog scaling
• Troubleshooting methodology
• Troubleshooting evidence map
• KQL quick reference for troubleshooting

Sources¶

• https://learn.microsoft.com/azure/azure-functions/durable/durable-functions-orchestrations
• https://learn.microsoft.com/azure/azure-functions/durable/durable-functions-best-practice-reference
• https://learn.microsoft.com/azure/azure-functions/durable/durable-functions-eternal-orchestrations
• https://learn.microsoft.com/azure/azure-functions/functions-reference-python
• https://learn.microsoft.com/azure/azure-functions/storage-considerations
• https://learn.microsoft.com/azure/azure-monitor/logs/log-query-overview