Skip to content

Step-dispatch latency grows linearly with accumulated run history (~0.3s per round per transition) — 65% of a 311-step run's wall time #3026

Open

Description

@shtefcs

We run @workflow/ai@5.0.0-beta.11 + workflow@5.0.0-beta.24 on Vercel (IAD1). On long agent runs, the time between step completions grows linearly with the number of accumulated steps, even for trivial bookkeeping steps.

Measurement (a 311-step, 92-minute agent run on a preview deployment, all numbers from step createdAt/startedAt/completedAt timestamps via the workflow API):

  • Every step's own execution is fast: non-LLM steps complete in 0.1–0.5s once started; queue delay (startedAt − createdAt) ≈ 0 for all 311 steps.
  • But the per-TRANSITION gap (previous step end → next step created) grows from ~1.9s avg (round 2) to ~16.6s avg (round 50). Linear fit across rounds: gap = 1.45s + 0.297s × round, R² = 0.94. With ~6 transitions per agent round that's ~96s of pure engine overhead per round by round 50.
  • Budget: of 70.6 min of active run time, only 24.7 min (35%) is inside LLM steps; 45.9 min (65%) is inter-step time, 97.9% of which is not attributable to any step's execution or queue delay.
  • The growth is uniform across step types — a 0.1s credit-deduction step pays the same ~15s transition cost as an LLM step by round 50 — which points at per-dispatch run-history replay/rehydration cost rather than anything payload-specific.
  • Context: our conversation payloads are large (268K→589K tokens across the run), so O(history) work that re-reads/deserializes accumulated step results would scale badly here. We already strip the request.body echo from doStreamStep returns via a local patch (the core of [ai] Reduce doStreamStep step boundary payload #1932 / DurableAgent/WorkflowAgent duplicates doStreamStep return size #1929) — this measurement is with that strip active.
  • History: we reported the same shape in April at much smaller magnitude (961ms→2,135ms over 77 steps) and [core] Combine flow+step bundle and process steps eagerly #1338 flattened it to 0.27–0.47s. It has returned at ~10× on longer runs.

Our own mitigation (collapsing per-round bookkeeping steps) reduced dispatches per round from 6–7 to 3, which helps proportionally — but the per-dispatch growth itself looks engine-side.

Question: is per-dispatch cost expected to scale with accumulated run history in the current scheduler, and is there a knob or planned fix? Happy to share the full 311-step timing table and run IDs privately.

Activity

  1. NathanColosimo commented on Jul 21, 2026

    @NathanColosimo
    Contributor

    Step to step overhead shouldn't be 1.9s on the same run especially at the start (for example your 1.9s round 2)

    Can you double check your otel?

    Additionally, upgrade to the latest v5 beta version, this should help with large payloads, workflow@5.0.0-beta.24 is not the latest.

  2. TooTallNate commented on Jul 23, 2026

    @TooTallNate
    Member

    You'd probably be interested in RFC: VM Snapshot Runtime which intends to solve long-running / forever workflow runs.

  3. kaijiabo commented on Aug 4, 2026

    @kaijiabo

    Adding a second dataset on this. Same shape, different scale, and measured on newer versions than the original report — so the two open questions above (otel accuracy, and whether upgrading fixes it) both get an answer.

    Setup: workflow@5.0.0-beta.36, @workflow/core@5.0.0-beta.36, @ai-sdk/workflow@1.0.28, Vercel managed world, production. Two completed agent runs, 767 and 756 steps.

    Method

    No otel. Every number below comes from the workflow API's own step records (/v1/workflow/v2/runs/{runId}/steps, fully paginated), using the timestamps the engine writes:

    • gap = clientCreatedAt[i+1] − completedAt[i] — engine time between one step finishing and the next being created
    • dispatch = startedAt − clientCreatedAt — queue/dispatch time
    • duration = completedAt − startedAt — the step's own work

    Steps sorted by clientCreatedAt. Gaps where the next step was created before the previous finished (overlapping parallel steps) are negative and excluded: 565 of 766 usable in run A, 578 of 755 in run B.

    On statistics: raw per-step gaps are heavy-tailed, so an OLS fit on raw points gives a misleadingly low R² (0.008 for i ≥ 100; 0.001 across all points) even though the trend is strong and monotonic. I'm therefore reporting Spearman rank correlation on the raw data — which assumes neither linearity nor normality — plus decile medians. Both are in the table so the result doesn't rest on a modelling choice.

    Result

    run A (767 steps) run B (756 steps)
    gap median, first quartile → last 0.61s → 2.94s (4.8×) 0.50s → 1.74s (3.5×)
    gap vs step index, Spearman ρ 0.898 (n=565) 0.843 (n=578)
    decile-median linear fit 0.0040·i + 0.11 s, R² 0.972 0.0021·i + 0.26 s, R² 0.960
    dispatch median, first → last quartile 0.068s → 0.048s, ρ = −0.07 0.038s → 0.044s, ρ = +0.06
    duration median, first → last quartile 0.591s → 0.376s, ρ = −0.10 0.392s → 0.323s, ρ = −0.02
    blobStorageBytes 48,196,199 27,505,071

    Run A gap medians across 7 equal index buckets (seconds): 0.51 · 0.78 · 1.05 · 1.51 · 2.13 · 2.39 · 3.07

    Only the gap grows. Dispatch and duration are flat or very slightly decreasing across the same runs (|ρ| ≤ 0.10). So this isn't queue pressure and it isn't steps getting slower — the growth is entirely in engine time between steps. In run A that's 33.0 of 47.7 minutes of wall clock.

    On the two questions raised above

    "Step-to-step overhead shouldn't be 1.9s at round 2 — check your otel." That looks right, and this dataset supports the pushback. Measured from engine timestamps rather than otel, the early-run median gap is 0.5–0.6s, not 1.9s. The elevated baseline in the original report appears to be a measurement artifact. The growth, however, reproduces cleanly at ρ ≈ 0.85–0.90.

    "Upgrade to the latest v5 beta, this should help with large payloads." We did — beta.24 → beta.36, five days before these runs. The growth persists at this scale. Worth noting the merged payload work (#1932/#1929) reduced the doStreamStep return; the step input is unchanged.

    Possible mechanism

    Between these two runs the fitted slope differs 1.94× and blobStorageBytes differs 1.75×, in the same direction. That's two runs, so it's suggestive rather than conclusive — but it is consistent with per-dispatch cost scaling with accumulated journal size.

    A concrete contributor: doStreamStep(conversationPrompt, …) takes the conversation as its first argument, so the full and growing prompt is journaled as step input on every model call — 78 and 80 times respectively in these runs. That signature is unchanged in @ai-sdk/workflow@1.0.50, and I couldn't find an existing issue covering the input side (as opposed to the return). Happy to open one separately if that's the right place for it.

    Questions

    1. Is per-dispatch cost expected to scale with accumulated journal size in the current managed-world scheduler?
    2. Is there a supported way to reduce the journaled step input for the AI SDK integration — or is RFC #1298 the intended answer? It's been quiet since March, so it'd help to know whether to plan around it.
    3. Anything measurable we can do today beyond reducing step count per turn?

    Run IDs, the full per-step timing tables, and the analysis script are available privately if useful.

  4. shtefcs commented on Sep 1, 2026

    @shtefcs
    Author

    Some production data that might help quantify this. We run a coding agent on @ai-sdk/workflow 1.0.30 with workflow core 5.0.0-beta.42 (later beta.46), Vercel managed world, region iad1.

    One real run: the actual conversation was 463KB. The journal for that run was 54.41MB, about 117x larger. We decrypted the step payloads to see where the bytes go:

    • doStreamStep inputs (conversationPrompt plus serializedTools): 29.97MB. The full conversation and the full tool catalog are journaled again on every model step, so this grows roughly linearly with step count.
    • Tool step inputs carrying ctx.messages: 20.65MB. The engine passes the whole conversation into every tool execute, and that gets journaled per call. We worked around this on our side by stripping messages at the step boundary and passing a small projection instead, which cut a 300-call run by roughly 371MB.
    • All step outputs combined: 0.70MB.

    Replay cost is what makes the size matter. We measured journal replay at roughly 0.5 to 0.7 seconds per MB on invocation re-entry. On long runs that compounds into minutes of pure re-reading.

    Happy to share methodology. Everything above came from workflow inspect steps --decrypt on real runs plus timing the re-entry gaps from the event log.

  5. rpinckne commented on Sep 23, 2026

    @rpinckne

    We hit the same shape: a linear per-transition gap on long WorkflowAgent runs. It went from about 0.36 s to 3.7 s between the model step and the next tool step over an 837-step run, and the prepare-to-model hop grew too. We traced the largest part of it to retained-VM demotion, which we filed as #4316.

    WorkflowAgent passes the provider model instance into its model step. AI SDK provider models implement [WORKFLOW_SERIALIZE], so dehydrating that argument records guest-code execution. getRetentionDecision then returns serialization_executed_workflow_code, and the next inline pass is a full replay of the event log, once per model call. That gives O(steps) work per round, which matches the linear fit above.

    How to confirm on your run:

    1. Run with DEBUG=workflow:runtime:debug.
    2. Look for the retention decision reason serialization_executed_workflow_code after each model step.
    3. Check that the growing gap sits after the model step rather than after plain-data steps. In our runs the gaps after steps that take only plain data stayed flat.

    What worked for us: reducing the model argument to a plain { classId, data } envelope in the workflow body, and reviving it inside the step. Retention then held across model calls, and the per-call replay disappeared. The repro and details are in #4316.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions