Skip to content

[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension - #3543

Closed
VaguelySerious wants to merge 1 commit into
mainfrom
peter/race-repro-diagnostics
Closed

[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension#3543
VaguelySerious wants to merge 1 commit into
mainfrom
peter/race-repro-diagnostics

Conversation

@VaguelySerious

@VaguelySeriousVaguelySerious commented Aug 14, 2026

Copy link
Copy Markdown
Member

Draft / diagnostics — not for merge as-is. This PR carries the offline reproduction and instrumentation for the residual CORRUPTED_EVENT_LOG failures on spec-6 (slot-identity) runs, most recently wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro on the #3519 preview, 1/14).

What the data shows

Reconstructed from the run's full event log (staging o11y) plus per-invocation runtime logs:

  • The final round's 8th finalizeStep was created under two different correlation ids by two different invocations (…QMWZ eagerly at slot 630, …QMX0 lazily at slot 631), and both executed (duplicate step execution). A third trajectory (the failing replayer) assigned …QMWZ to a releaseStep, which is the decrypted divergence: step event …QMWZ belongs to "finalizeStep", but the current step consumer is "releaseStep".
  • The writer of slot 630 replayed a dense, gap-free 610-event prefix (eventCount: 610 in its logs) and continued correctly. Nothing it did was wrong given what it loaded.

Offline reproduction (in this PR)

storm-log-replay.test.ts rebuilds the run's exact log shape (slot order, entity kinds, step names, ULID ranks remapped onto the test harness's deterministic sequence) and replays it through a faithful port of stepStormReproWorkflow:

  • Replaying the full 655-event log reproduces the production divergence verbatim, at the same event.
  • Replaying the writer's exact 610-event prefix reproduces the writer's committed binding (rank 198 = finalizeStep) as a clean suspension — the writer was prefix-determined.

storm-log-sweep.test.ts (opt-in via STORM_LOG_SWEEP=1) sweeps prefix lengths:

len<=611: rank197=releaseStep rank198=finalizeStep
len>=612: rank197=releaseStep rank198=releaseStep rank199=finalizeStep
len>=630: deterministic ReplayDivergenceError at the rank-198 create

The flip event (slot 612) is an ordinary finalize step_completed. Note also that at len 610 the settled branch's finalize draw (its waking event is at slot 577) lands after draws woken at slots 588–602.

Diagnosis

Replay is deterministic for a byte-identical log, but draw order is not stable under log extension: a branch's post-Promise.race continuation draws its next correlation id at a point in the microtask schedule that depends on how much log is loaded, not at its waking event's log position. Two honest replayers holding different-length (both dense, both valid) snapshots therefore bind the same ordinal to different steps; each commits creates from its own trajectory; the log ends up carrying mutually inconsistent bindings, and every replayer that loads past the conflicting create fails deterministically → 4 recovery replays → CORRUPTED_EVENT_LOG.

This is the property the delivery-barrier work (step-delivery-ordering.test.ts, step-delivery-hop-count.test.ts) pins for adjacent-event shapes; the storm shape (8-wide Promise.race + finally + interleaved recover chains) escapes it. race-padded-draw-ordering.test.ts (also in this PR) shows the minimal 2-branch race shape is correctly ordered cold+warm, so the escape needs the wider interleaving.

Also included: runtime.ts DIAG probes (error-level array-order check before each pass, per-suspension draw-binding log, array-order dump on divergence) so the preview repro lane produces the same forensics without ClickHouse spelunking. The array-order probe has stayed silent locally — the events array is not the problem.

Fix directions (follow-up, not in this PR)

  1. Pin draw order to delivery order: deliver one waking event at a time and let the VM reach quiescence before delivering the next, so every draw is attributable to the delivery that caused it regardless of log length. Replay-latency cost is in-VM microtasks only.
  2. Call-site-derived correlation ids: removes ordinal renaming entirely; a wrong-trajectory writer then produces duplicate/orphan creates instead of conflicting bindings (needs *_created tolerance to become sound).
  3. Currency-checking the fence (412 when the log moved at all) would also close it but serializes fan-out; rejected before (wfs#724 scoping).

🤖 Generated with Claude Code

@VaguelySerious@claude
[core] Diagnostics for residual slot-mode CORRUPTED_EVENT_LOG: offlin…
3e060e3
…e replay of the corrupted storm log + draw-order probes
Offline replay tests built from the actual corrupted event log of
wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro, preview, spec 6):
- storm-log-replay.test.ts: a faithful replay of the full 655-event log
reproduces the production divergence verbatim; a faithful replay of the
corrupting writer's exact 610-event prefix reproduces the writer's
committed binding, proving the writer was prefix-determined and the
binding conflict is created by log growth, not by a misbehaving writer.
- storm-log-sweep.test.ts (STORM_LOG_SWEEP=1): sweeps prefix lengths and
finds the flip at slot 612 - a branch's post-Promise.race draw is not
pinned to its waking event's log position, so the ordinal it draws
depends on how much log is loaded.
- race-padded-draw-ordering.test.ts: the minimal 2-branch race shape stays
correctly ordered cold+warm (regression coverage for the barrier fix).
- runtime.ts DIAG probes (array order before each pass, draw bindings per
suspension, array-order dump on divergence) for the preview repro lane.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@changeset-bot

changeset-botBot commented Aug 14, 2026

Copy link
Copy Markdown

🦋 Changeset detected

Latest commit: 3e060e3

The changes in this PR will be included in the next version bump.

This PR includes changesets to release 0 packages

When changesets are added to this PR, you'll see the packages that this PR includes changesets for and the associated semver types

Not sure what this means? Click here to learn what changesets are.

Click here if you're a maintainer who wants to add another changeset to this PR

@vercel

vercelBot commented Aug 14, 2026•
edited
Loading

Copy link
Copy Markdown
Contributor

The latest updates on your projects. Learn more about Vercel for GitHub.

ProjectDeploymentActionsUpdated (UTC)
example-nextjs-workflow-turbopackReadyReadyPreviewAug 14, 2026 1:20am
example-nextjs-workflow-webpackReadyReadyPreviewAug 14, 2026 1:20am
example-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-astro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-express-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-fastify-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-hono-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nestjs-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nitro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nuxt-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-python-workflowErrorErrorAug 14, 2026 1:20am
workbench-sveltekit-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-tanstack-start-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-vite-workflowReadyReadyPreviewAug 14, 2026 1:20am
workflow-docsReadyReadyPreview, v0Aug 14, 2026 1:20am
workflow-swc-playgroundReadyReadyPreviewAug 14, 2026 1:20am
workflow-tarballsReadyReadyPreviewAug 14, 2026 1:20am
workflow-webReadyReadyPreviewAug 14, 2026 1:20am

@github-actions

github-actionsBot commented Aug 14, 2026•
edited
Loading

Copy link
Copy Markdown
Contributor

🧪 E2E Test Results

✅ All tests passed

E2E Test Summary

Summary
PassedFailedSkippedTotal
✅ ▲ Vercel Production346605904056
✅ 💻 Local Development367305394212
✅ 📦 Local Production381005584368
✅ 🐘 Local Postgres381005584368
✅ 🪟 Windows31200312
✅ vercel-multi-region270027
Total150980224517343
Details by Category

✅ ▲ Vercel Production

AppPassedFailedSkipped
✅ astro-node128028
✅ astro-quickjs128028
✅ example-node128028
✅ example-quickjs128028
✅ express-node128028
✅ express-quickjs128028
✅ fastify-node128028
✅ fastify-quickjs128028
✅ hono-node128028
✅ hono-quickjs128028
✅ nest-node128028
✅ nest-quickjs128028
✅ nextjs-turbopack-node15303
✅ nextjs-turbopack-quickjs15303
✅ nextjs-webpack-node15303
✅ nextjs-webpack-quickjs15303
✅ nitro-node128028
✅ nitro-quickjs128028
✅ nuxt-node128028
✅ nuxt-quickjs128028
✅ sveltekit-node14709
✅ sveltekit-quickjs14709
✅ tanstack-start-node128028
✅ tanstack-start-quickjs128028
✅ vite-node128028
✅ vite-quickjs128028

✅ 💻 Local Development

AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026

✅ 📦 Local Production

AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026

✅ 🐘 Local Postgres

AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026

✅ 🪟 Windows

AppPassedFailedSkipped
✅ nextjs-turbopack-node15600
✅ nextjs-turbopack-quickjs15600

✅ vercel-multi-region

AppPassedFailedSkipped
✅ nextjs-turbopack2700

📋 View full workflow run

@github-actions

github-actionsBot commented Aug 14, 2026•
edited
Loading

Copy link
Copy Markdown
Contributor

📊 Workflow Benchmarks

commit 3e060e3 · Fri, 14 Aug 2026 01:38:46 GMT · run logs

Backend: vercel · app: nextjs-turbopack

MetricScenarioBest (ms)P75 (ms)P90 (ms)P99 (ms)Samples
TTFSstep1400 (+267%) 🔻1462 🔴 (+31%) 🔻1499 🔴 (+32%) 🔻1651 🔴 (+7.8%)30
TTFSstream427 (-58%) 💚1462 🔴 (+38%) 🔻1476 🔴 (+38%) 🔻1516 🔴 (+37%) 🔻30
TTFShook + stream1601 (+25%) 🔻1729 🔴 (+25%) 🔻1770 🔴 (+24%) 🔻7898 🔴 (+388%) 🔻30
Fan-out TTFSPromise.all(100 steps)8828 (-1.0%)10480 (+5.3%)10486 (+4.0%)21261 (+57%) 🔻10
Fan-out TTLSPromise.all(100 steps)17523 (-0.8%)19125 (+1.3%)20601 (+8.4%)29694 (+27%) 🔻10
STSO1020 steps (inline)123 (±0%)155 (-19%) 💚171 (-25%) 💚229 (-61%) 💚1019
WO1020 steps152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚1
SLstream latency78 (-1.3%)121 🔴 (+10%)165 🔴 (+28%) 🔻364 🔴 (+6.1%)30
SOstream overhead (text)105 (-5.4%)172 (-4.4%)284 (+38%) 🔻8011 🔴 (+1226%) 🔻30
SOstream overhead (structured)102 (+6.3%)161 (+3.2%)185 (+11%)301 (+65%) 🔻30
📈 STSO distribution vs main (inline / queue-hop histograms)

1020 steps (inline)

Cumulative STSO time: main 194368ms → this run 152318ms (Δ -42050ms, -22%)

 100-150 ms ███████░░░░░░░░░░░░░░░░┃ main 180 this 661 +481
150-200 ms ███████████┃███████████ main 627 this 324 -303
200-250 ms ┃████ main 134 this 28 -106
250-300 ms ┃ main 29 this 4 -25
300-350 ms ┃ main 15 this 2 -13
350-400 ms ┃ main 11 this 0 -11
400-450 ms ┃ main 4 this 0 -4
450-500 ms ┃ main 5 this 0 -5
500-550 ms ┃ main 3 this 0 -3
550-600 ms ┃ main 1 this 0 -1
600-650 ms ┃ main 5 this 0 -5
650-700 ms ┃ main 1 this 0 -1
750-800 ms ┃ main 1 this 0 -1
800-850 ms ┃ main 1 this 0 -1
1100-1150 ms ┃ main 1 this 0 -1
4450-4500 ms ┃ main 1 this 0 -1
ℹ️ Metric definitions & methodology

The collapsed STSO distribution section above buckets every step gap of the sequential-steps run (not a sampled window), split by whether the step ending the gap ran inline — in the same warm process as the step before it, so the gap is pure framework overhead — or after a queue-hop — the first step of a fresh process, which pays queue dispatch, client reinit and event-log replay. Bars overlay the two runs: █ is main, ┃ marks where this run lands, ░ bridges the gap when this run has more samples in a bucket.

Best/P75/P90/P99 deltas compare against the most recent benchmark run on main at the time of this run. 🔻 flags a delta worse than +15%, 💚 one better than −15%.

Metrics — TTFS: time to first step body (in-deployment start() → first step body, deployment clocks) · Fan-out TTFS: fan-out time to first step (in-deployment start() → first of the parallel step bodies to complete) · Fan-out TTLS: fan-out time to last step (in-deployment start() → last of the parallel step bodies to complete, i.e. when the Promise.all resolves) · STSO: step-to-step overhead (gap between consecutive step bodies) · WO: workflow overhead (whole-run time outside step bodies, in-deployment anchored) · SL: stream latency (in-deployment write → read propagation, readAt - writtenAt) · SO: stream overhead (end-to-end write+consume time beyond the modelled generation window)

Scenarios — step: one trivial no-op step, no stream; no hooks, so the run stays in turbo mode (in-process fast path) · stream: one streaming step; no hooks, so the run stays in turbo mode (in-process fast path) · hook + stream: registers a hook before one step, which exits turbo mode (dispatch path) · 1020 steps: 1020 trivial sequential steps; STSO is measured between consecutive steps in the given step ranges, and WO is the whole-run overhead outside step bodies · Promise.all(100 steps): 100 trivial no-op steps started together in a single Promise.all; Fan-out TTFS is the first of them to complete and Fan-out TTLS the last, both from the in-deployment clientStart, so their gap is the spread the runtime adds across the fan-out · stream latency: parallel reader/writer steps on a dedicated stream; SL is the in-deployment write->read propagation (readAt - writtenAt) · stream overhead (text): writer streams 300 variable-length text token deltas paced at 100/s for 3s (a haiku-size LLM's token throughput) while a parallel reader drains the whole stream; SO is the end-to-end write+consume time beyond the 3s generation window (overhead/backpressure) · stream overhead (structured): same workload as stream overhead (text), but each delta is an AI-SDK-style structured object ({ type: 'text-delta', id, text }) instead of a raw string, so the SO gap vs the text scenario is the added serialization cost

🔴 marks a percentile over its target (within target is left unmarked). Targets (p75/p90/p99, ms) — TTFS 200/300/600 · SL 50/60/125 · SO 250/500/1000

All metrics are measured from deployment-side timestamps only. Runs are triggered by an in-deployment route that stamps the anchor (clientStart) right before start(), so the CI runner’s request and its path through api.vercel.com sit outside every measured window. TTFS = in-deployment start() → first step body (turbo uses the in-process fast path, non-turbo the dispatch path), and includes the VQS dispatch hop plus any /flow cold start. Fan-out TTFS/TTLS are the first and last step completions of a single Promise.all over trivial steps, from the same anchor, so the gap between the two rows is the spread the runtime adds across the fan-out. STSO/WO are measured between step bodies on the deployment. SL is measured inside the workflow (parallel reader/writer steps), so it no longer includes the api.vercel.com read path.

Cold starts are kept in the numbers on purpose — they are part of real bursty-workload latency. The workbench deployment cold-starts the /flow invocation for a large fraction of runs, inflating P75+; the Best column shows the fastest (warm-start) sample for comparison.

@github-actions

github-actionsBot commented Aug 14, 2026

Copy link
Copy Markdown
Contributor

Sim World

Simulated world deterministic testing for races. Traces

🟠 Mint-ordered log — 3 fail of 41 total

log=mint-ordered · fence=per-spec

scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
❌ in-flight-before-decisionfailed91.0mMISMATCH1
❌ in-flight-before-decision-countedfailed91.0mMISMATCH1
❌ in-flight-after-decisionfailed91.0mMISMATCH1
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0

Full trace: world-sim-mint.txt

🟢 Append-only log — 0 fail of 41 total

log=append-only · fence=per-spec

scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
✅ in-flight-before-decisioncompleted171.0mok0
✅ in-flight-before-decision-countedcompleted171.0mok0
✅ in-flight-after-decisioncompleted192.0mok0
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0

Full trace: world-sim-append-only.txt

@VaguelySerious

VaguelySerious commented Aug 14, 2026

Copy link
Copy Markdown
MemberAuthor

(AI) Local postgres soak addendum: 120 step-storm attempts with the DIAG probes reproduced the same class in 29/120 runs. Each affected run diverges repeatedly at one fixed low slot (58–84, the round-0/1 boundary) while the log keeps growing (e.g. evnt_…059 at eventCounts 114, 145, 249), i.e. a committed binding conflict, not a transient race. The step-entity table shows the signature directly: mint order …F3<F4<F5<F6<F7 (all recoverStep) committed at slots 64, 66, 62, 60, 59 — last-minted first — and the surrounding ordinals are a scrambled interleaving of recover/finalize/release groups from disagreeing trajectories.

Two operational notes from the soak:

  • These runs surface as stuck (divergence-thrash), not CORRUPTED_EVENT_LOG — the storm's extra wakes keep starting fresh deliveries whose divergence count restarts, so the 3-strike exhaustion rarely triggers locally. Stuck-rate is therefore the number to watch locally, not the corrupted-rate.
  • The array-order probe stayed silent across all 120 runs (16k suspension snapshots): the events array is slot-ordered everywhere; the instability is in draw scheduling, not log assembly. Also, the errorMessage field of the DIAG divergence log is dropped by renderStructuredFields (log-format.ts wellKnown handling) — same gap that hides divergence reasons in production logs; worth fixing alongside.

@VaguelySeriousVaguelySerious mentioned this pull request Aug 14, 2026
Merged
Sign up for freeto join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

No reviews

Assignees

No one assigned

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

1 participant

@VaguelySerious
, 'i'); if (__m === '*' || __re.test(location.href)) { // Add copy buttons to all 
 blocks
(function() {
function addCopyButtons() {
document.querySelectorAll('pre code').forEach(function(codeBlock) {
if (codeBlock.parentElement.hasAttribute('data-copy-added')) return;
codeBlock.parentElement.setAttribute('data-copy-added', 'true');
var btn = document.createElement('button');
btn.textContent = 'Copy';
btn.style.cssText = 'position:absolute;top:4px;right:4px;padding:2px 8px;font-size:11px;background:#4ecdc4;border:none;border-radius:4px;color:#1a1a2e;cursor:pointer;opacity:0.7;transition:opacity 0.2s;';
btn.onmouseover = function() { this.style.opacity = '1'; };
btn.onmouseout = function() { this.style.opacity = '0.7'; };
btn.onclick = function() {
navigator.clipboard.writeText(codeBlock.textContent).then(function() {
btn.textContent = 'Copied!';
setTimeout(function() { btn.textContent = 'Copy'; }, 1500);
});
};
codeBlock.parentElement.style.position = 'relative';
codeBlock.parentElement.appendChild(btn);
});
}
addCopyButtons();
// Re-run on dynamic content
var observer = new MutationObserver(addCopyButtons);
observer.observe(document.body, { childList: true, subtree: true });
})();
}
} catch(__e) { console.warn('[Userscript:Add Copy Buttons to Code Blocks]', __e); }
})();
(function(){
try {
var __m = "github.com";
var __re = new RegExp('^' + "github\\.com" + '
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension by VaguelySerious · Pull Request #3543 · vercel/workflow · GitHub
Skip to content
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension - #3543
Closed
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Closed
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension#3543
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Conversation
@VaguelySerious
@VaguelySeriousVaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

Member
Draft / diagnostics — not for merge as-is. This PR carries the offline reproduction and instrumentation for the residual CORRUPTED_EVENT_LOG failures on spec-6 (slot-identity) runs, most recently wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro on the #3519 preview, 1/14).
What the data shows
Reconstructed from the run's full event log (staging o11y) plus per-invocation runtime logs:
  • The final round's 8th finalizeStep was created under two different correlation ids by two different invocations (…QMWZ eagerly at slot 630, …QMX0 lazily at slot 631), and both executed (duplicate step execution). A third trajectory (the failing replayer) assigned …QMWZ to a releaseStep, which is the decrypted divergence: step event …QMWZ belongs to "finalizeStep", but the current step consumer is "releaseStep".
  • The writer of slot 630 replayed a dense, gap-free 610-event prefix (eventCount: 610 in its logs) and continued correctly. Nothing it did was wrong given what it loaded.
Offline reproduction (in this PR)
storm-log-replay.test.ts rebuilds the run's exact log shape (slot order, entity kinds, step names, ULID ranks remapped onto the test harness's deterministic sequence) and replays it through a faithful port of stepStormReproWorkflow:
  • Replaying the full 655-event log reproduces the production divergence verbatim, at the same event.
  • Replaying the writer's exact 610-event prefix reproduces the writer's committed binding (rank 198 = finalizeStep) as a clean suspension — the writer was prefix-determined.
storm-log-sweep.test.ts (opt-in via STORM_LOG_SWEEP=1) sweeps prefix lengths:
len<=611: rank197=releaseStep rank198=finalizeStep
len>=612: rank197=releaseStep rank198=releaseStep rank199=finalizeStep
len>=630: deterministic ReplayDivergenceError at the rank-198 create

The flip event (slot 612) is an ordinary finalize step_completed. Note also that at len 610 the settled branch's finalize draw (its waking event is at slot 577) lands after draws woken at slots 588–602.
Diagnosis
Replay is deterministic for a byte-identical log, but draw order is not stable under log extension: a branch's post-Promise.race continuation draws its next correlation id at a point in the microtask schedule that depends on how much log is loaded, not at its waking event's log position. Two honest replayers holding different-length (both dense, both valid) snapshots therefore bind the same ordinal to different steps; each commits creates from its own trajectory; the log ends up carrying mutually inconsistent bindings, and every replayer that loads past the conflicting create fails deterministically → 4 recovery replays → CORRUPTED_EVENT_LOG.
This is the property the delivery-barrier work (step-delivery-ordering.test.ts, step-delivery-hop-count.test.ts) pins for adjacent-event shapes; the storm shape (8-wide Promise.race + finally + interleaved recover chains) escapes it. race-padded-draw-ordering.test.ts (also in this PR) shows the minimal 2-branch race shape is correctly ordered cold+warm, so the escape needs the wider interleaving.
Also included: runtime.ts DIAG probes (error-level array-order check before each pass, per-suspension draw-binding log, array-order dump on divergence) so the preview repro lane produces the same forensics without ClickHouse spelunking. The array-order probe has stayed silent locally — the events array is not the problem.
Fix directions (follow-up, not in this PR)
  1. Pin draw order to delivery order: deliver one waking event at a time and let the VM reach quiescence before delivering the next, so every draw is attributable to the delivery that caused it regardless of log length. Replay-latency cost is in-VM microtasks only.
  2. Call-site-derived correlation ids: removes ordinal renaming entirely; a wrong-trajectory writer then produces duplicate/orphan creates instead of conflicting bindings (needs *_created tolerance to become sound).
  3. Currency-checking the fence (412 when the log moved at all) would also close it but serializes fan-out; rejected before (wfs#724 scoping).
🤖 Generated with Claude Code
@VaguelySerious@claude
[core] Diagnostics for residual slot-mode CORRUPTED_EVENT_LOG: offlin…
3e060e3
…e replay of the corrupted storm log + draw-order probes
Offline replay tests built from the actual corrupted event log of
wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro, preview, spec 6):
- storm-log-replay.test.ts: a faithful replay of the full 655-event log
reproduces the production divergence verbatim; a faithful replay of the
corrupting writer's exact 610-event prefix reproduces the writer's
committed binding, proving the writer was prefix-determined and the
binding conflict is created by log growth, not by a misbehaving writer.
- storm-log-sweep.test.ts (STORM_LOG_SWEEP=1): sweeps prefix lengths and
finds the flip at slot 612 - a branch's post-Promise.race draw is not
pinned to its waking event's log position, so the ordinal it draws
depends on how much log is loaded.
- race-padded-draw-ordering.test.ts: the minimal 2-branch race shape stays
correctly ordered cold+warm (regression coverage for the barrier fix).
- runtime.ts DIAG probes (array order before each pass, draw bindings per
suspension, array-order dump on divergence) for the preview repro lane.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@changeset-bot
changeset-botBot
commented
Aug 14, 2026

Copy link


Copy Markdown

🦋 Changeset detected
Latest commit: 3e060e3
The changes in this PR will be included in the next version bump.
This PR includes changesets to release 0 packages
When changesets are added to this PR, you'll see the packages that this PR includes changesets for and the associated semver types
Not sure what this means? Click here to learn what changesets are.
Click here if you're a maintainer who wants to add another changeset to this PR
@vercel
vercelBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
The latest updates on your projects. Learn more about Vercel for GitHub.
ProjectDeploymentActionsUpdated (UTC)
example-nextjs-workflow-turbopackReadyReadyPreviewAug 14, 2026 1:20am
example-nextjs-workflow-webpackReadyReadyPreviewAug 14, 2026 1:20am
example-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-astro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-express-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-fastify-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-hono-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nestjs-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nitro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nuxt-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-python-workflowErrorErrorAug 14, 2026 1:20am
workbench-sveltekit-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-tanstack-start-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-vite-workflowReadyReadyPreviewAug 14, 2026 1:20am
workflow-docsReadyReadyPreview, v0Aug 14, 2026 1:20am
workflow-swc-playgroundReadyReadyPreviewAug 14, 2026 1:20am
workflow-tarballsReadyReadyPreviewAug 14, 2026 1:20am
workflow-webReadyReadyPreviewAug 14, 2026 1:20am
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
🧪 E2E Test Results
✅ All tests passed
E2E Test Summary
Summary
PassedFailedSkippedTotal
✅ ▲ Vercel Production346605904056
✅ 💻 Local Development367305394212
✅ 📦 Local Production381005584368
✅ 🐘 Local Postgres381005584368
✅ 🪟 Windows31200312
✅ vercel-multi-region270027
Total150980224517343
Details by Category
✅ ▲ Vercel Production
AppPassedFailedSkipped
✅ astro-node128028
✅ astro-quickjs128028
✅ example-node128028
✅ example-quickjs128028
✅ express-node128028
✅ express-quickjs128028
✅ fastify-node128028
✅ fastify-quickjs128028
✅ hono-node128028
✅ hono-quickjs128028
✅ nest-node128028
✅ nest-quickjs128028
✅ nextjs-turbopack-node15303
✅ nextjs-turbopack-quickjs15303
✅ nextjs-webpack-node15303
✅ nextjs-webpack-quickjs15303
✅ nitro-node128028
✅ nitro-quickjs128028
✅ nuxt-node128028
✅ nuxt-quickjs128028
✅ sveltekit-node14709
✅ sveltekit-quickjs14709
✅ tanstack-start-node128028
✅ tanstack-start-quickjs128028
✅ vite-node128028
✅ vite-quickjs128028
✅ 💻 Local Development
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 📦 Local Production
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🐘 Local Postgres
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🪟 Windows
AppPassedFailedSkipped
✅ nextjs-turbopack-node15600
✅ nextjs-turbopack-quickjs15600
✅ vercel-multi-region
AppPassedFailedSkipped
✅ nextjs-turbopack2700
📋 View full workflow run
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
📊 Workflow Benchmarks
commit 3e060e3 · Fri, 14 Aug 2026 01:38:46 GMT · run logs
Backend: vercel · app: nextjs-turbopack
MetricScenarioBest (ms)P75 (ms)P90 (ms)P99 (ms)Samples
TTFSstep1400 (+267%) 🔻1462 🔴 (+31%) 🔻1499 🔴 (+32%) 🔻1651 🔴 (+7.8%)30
TTFSstream427 (-58%) 💚1462 🔴 (+38%) 🔻1476 🔴 (+38%) 🔻1516 🔴 (+37%) 🔻30
TTFShook + stream1601 (+25%) 🔻1729 🔴 (+25%) 🔻1770 🔴 (+24%) 🔻7898 🔴 (+388%) 🔻30
Fan-out TTFSPromise.all(100 steps)8828 (-1.0%)10480 (+5.3%)10486 (+4.0%)21261 (+57%) 🔻10
Fan-out TTLSPromise.all(100 steps)17523 (-0.8%)19125 (+1.3%)20601 (+8.4%)29694 (+27%) 🔻10
STSO1020 steps (inline)123 (±0%)155 (-19%) 💚171 (-25%) 💚229 (-61%) 💚1019
WO1020 steps152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚1
SLstream latency78 (-1.3%)121 🔴 (+10%)165 🔴 (+28%) 🔻364 🔴 (+6.1%)30
SOstream overhead (text)105 (-5.4%)172 (-4.4%)284 (+38%) 🔻8011 🔴 (+1226%) 🔻30
SOstream overhead (structured)102 (+6.3%)161 (+3.2%)185 (+11%)301 (+65%) 🔻30
📈 STSO distribution vs main (inline / queue-hop histograms)
1020 steps (inline)
Cumulative STSO time: main 194368ms → this run 152318ms (Δ -42050ms, -22%)
 100-150 ms ███████░░░░░░░░░░░░░░░░┃ main 180 this 661 +481
150-200 ms ███████████┃███████████ main 627 this 324 -303
200-250 ms ┃████ main 134 this 28 -106
250-300 ms ┃ main 29 this 4 -25
300-350 ms ┃ main 15 this 2 -13
350-400 ms ┃ main 11 this 0 -11
400-450 ms ┃ main 4 this 0 -4
450-500 ms ┃ main 5 this 0 -5
500-550 ms ┃ main 3 this 0 -3
550-600 ms ┃ main 1 this 0 -1
600-650 ms ┃ main 5 this 0 -5
650-700 ms ┃ main 1 this 0 -1
750-800 ms ┃ main 1 this 0 -1
800-850 ms ┃ main 1 this 0 -1
1100-1150 ms ┃ main 1 this 0 -1
4450-4500 ms ┃ main 1 this 0 -1

ℹ️ Metric definitions & methodology
The collapsed STSO distribution section above buckets every step gap of the sequential-steps run (not a sampled window), split by whether the step ending the gap ran inline — in the same warm process as the step before it, so the gap is pure framework overhead — or after a queue-hop — the first step of a fresh process, which pays queue dispatch, client reinit and event-log replay. Bars overlay the two runs: █ is main, ┃ marks where this run lands, ░ bridges the gap when this run has more samples in a bucket.
Best/P75/P90/P99 deltas compare against the most recent benchmark run on main at the time of this run. 🔻 flags a delta worse than +15%, 💚 one better than −15%.
Metrics — TTFS: time to first step body (in-deployment start() → first step body, deployment clocks) · Fan-out TTFS: fan-out time to first step (in-deployment start() → first of the parallel step bodies to complete) · Fan-out TTLS: fan-out time to last step (in-deployment start() → last of the parallel step bodies to complete, i.e. when the Promise.all resolves) · STSO: step-to-step overhead (gap between consecutive step bodies) · WO: workflow overhead (whole-run time outside step bodies, in-deployment anchored) · SL: stream latency (in-deployment write → read propagation, readAt - writtenAt) · SO: stream overhead (end-to-end write+consume time beyond the modelled generation window)
Scenarios — step: one trivial no-op step, no stream; no hooks, so the run stays in turbo mode (in-process fast path) · stream: one streaming step; no hooks, so the run stays in turbo mode (in-process fast path) · hook + stream: registers a hook before one step, which exits turbo mode (dispatch path) · 1020 steps: 1020 trivial sequential steps; STSO is measured between consecutive steps in the given step ranges, and WO is the whole-run overhead outside step bodies · Promise.all(100 steps): 100 trivial no-op steps started together in a single Promise.all; Fan-out TTFS is the first of them to complete and Fan-out TTLS the last, both from the in-deployment clientStart, so their gap is the spread the runtime adds across the fan-out · stream latency: parallel reader/writer steps on a dedicated stream; SL is the in-deployment write->read propagation (readAt - writtenAt) · stream overhead (text): writer streams 300 variable-length text token deltas paced at 100/s for 3s (a haiku-size LLM's token throughput) while a parallel reader drains the whole stream; SO is the end-to-end write+consume time beyond the 3s generation window (overhead/backpressure) · stream overhead (structured): same workload as stream overhead (text), but each delta is an AI-SDK-style structured object ({ type: 'text-delta', id, text }) instead of a raw string, so the SO gap vs the text scenario is the added serialization cost
🔴 marks a percentile over its target (within target is left unmarked). Targets (p75/p90/p99, ms) — TTFS 200/300/600 · SL 50/60/125 · SO 250/500/1000
All metrics are measured from deployment-side timestamps only. Runs are triggered by an in-deployment route that stamps the anchor (clientStart) right before start(), so the CI runner’s request and its path through api.vercel.com sit outside every measured window. TTFS = in-deployment start() → first step body (turbo uses the in-process fast path, non-turbo the dispatch path), and includes the VQS dispatch hop plus any /flow cold start. Fan-out TTFS/TTLS are the first and last step completions of a single Promise.all over trivial steps, from the same anchor, so the gap between the two rows is the spread the runtime adds across the fan-out. STSO/WO are measured between step bodies on the deployment. SL is measured inside the workflow (parallel reader/writer steps), so it no longer includes the api.vercel.com read path.
Cold starts are kept in the numbers on purpose — they are part of real bursty-workload latency. The workbench deployment cold-starts the /flow invocation for a large fraction of runs, inflating P75+; the Best column shows the fastest (warm-start) sample for comparison.
@github-actions
github-actionsBot
commented
Aug 14, 2026

Copy link


Copy Markdown

Contributor
Sim World
Simulated world deterministic testing for races. Traces
🟠 Mint-ordered log — 3 fail of 41 total
log=mint-ordered · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
❌ in-flight-before-decisionfailed91.0mMISMATCH1
❌ in-flight-before-decision-countedfailed91.0mMISMATCH1
❌ in-flight-after-decisionfailed91.0mMISMATCH1
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-mint.txt
🟢 Append-only log — 0 fail of 41 total
log=append-only · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
✅ in-flight-before-decisioncompleted171.0mok0
✅ in-flight-before-decision-countedcompleted171.0mok0
✅ in-flight-after-decisioncompleted192.0mok0
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-append-only.txt
@VaguelySerious
VaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

MemberAuthor
(AI) Local postgres soak addendum: 120 step-storm attempts with the DIAG probes reproduced the same class in 29/120 runs. Each affected run diverges repeatedly at one fixed low slot (58–84, the round-0/1 boundary) while the log keeps growing (e.g. evnt_…059 at eventCounts 114, 145, 249), i.e. a committed binding conflict, not a transient race. The step-entity table shows the signature directly: mint order …F3<F4<F5<F6<F7 (all recoverStep) committed at slots 64, 66, 62, 60, 59 — last-minted first — and the surrounding ordinals are a scrambled interleaving of recover/finalize/release groups from disagreeing trajectories.
Two operational notes from the soak:
  • These runs surface as stuck (divergence-thrash), not CORRUPTED_EVENT_LOG — the storm's extra wakes keep starting fresh deliveries whose divergence count restarts, so the 3-strike exhaustion rarely triggers locally. Stuck-rate is therefore the number to watch locally, not the corrupted-rate.
  • The array-order probe stayed silent across all 120 runs (16k suspension snapshots): the events array is slot-ordered everywhere; the instability is in draw scheduling, not log assembly. Also, the errorMessage field of the DIAG divergence log is dropped by renderStructuredFields (log-format.ts wellKnown handling) — same gap that hides divergence reasons in production logs; worth fixing alongside.
@VaguelySeriousVaguelySerious
mentioned this pull request
Aug 14, 2026
 Merged

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

Reviewers


No reviews


Assignees


No one assigned


Labels


None yet


Projects


None yet


Milestone


No milestone


Development

Successfully merging this pull request may close these issues.

1 participant

@VaguelySerious

, 'i');
if (__m === '*' || __re.test(location.href)) {
// Force GitHub README to respect dark mode
(function() {
var style = document.createElement('style');
style.textContent = '
.markdown-body {
color-scheme: dark light;
}
.markdown-body pre { background: #161b22 !important; }
.markdown-body code { background: rgba(110, 118, 129, 0.4) !important; }
.markdown-body table th, .markdown-body table td { border-color: #30363d !important; }
.markdown-body img { background: #0d1117; }
.markdown-body blockquote { border-left-color: #8b949e; }
.markdown-body hr { border-color: #30363d; }
';
document.head.appendChild(style);
})();
}
} catch(__e) { console.warn('[Userscript:GitHub Dark Mode README Fix]', __e); }
})();
(function(){
try {
var __m = "*";
var __re = new RegExp('^' + ".*" + '
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension by VaguelySerious · Pull Request #3543 · vercel/workflow · GitHub
Skip to content
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension - #3543
Closed
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Closed
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension#3543
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Conversation
@VaguelySerious
@VaguelySeriousVaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

Member
Draft / diagnostics — not for merge as-is. This PR carries the offline reproduction and instrumentation for the residual CORRUPTED_EVENT_LOG failures on spec-6 (slot-identity) runs, most recently wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro on the #3519 preview, 1/14).
What the data shows
Reconstructed from the run's full event log (staging o11y) plus per-invocation runtime logs:
  • The final round's 8th finalizeStep was created under two different correlation ids by two different invocations (…QMWZ eagerly at slot 630, …QMX0 lazily at slot 631), and both executed (duplicate step execution). A third trajectory (the failing replayer) assigned …QMWZ to a releaseStep, which is the decrypted divergence: step event …QMWZ belongs to "finalizeStep", but the current step consumer is "releaseStep".
  • The writer of slot 630 replayed a dense, gap-free 610-event prefix (eventCount: 610 in its logs) and continued correctly. Nothing it did was wrong given what it loaded.
Offline reproduction (in this PR)
storm-log-replay.test.ts rebuilds the run's exact log shape (slot order, entity kinds, step names, ULID ranks remapped onto the test harness's deterministic sequence) and replays it through a faithful port of stepStormReproWorkflow:
  • Replaying the full 655-event log reproduces the production divergence verbatim, at the same event.
  • Replaying the writer's exact 610-event prefix reproduces the writer's committed binding (rank 198 = finalizeStep) as a clean suspension — the writer was prefix-determined.
storm-log-sweep.test.ts (opt-in via STORM_LOG_SWEEP=1) sweeps prefix lengths:
len<=611: rank197=releaseStep rank198=finalizeStep
len>=612: rank197=releaseStep rank198=releaseStep rank199=finalizeStep
len>=630: deterministic ReplayDivergenceError at the rank-198 create

The flip event (slot 612) is an ordinary finalize step_completed. Note also that at len 610 the settled branch's finalize draw (its waking event is at slot 577) lands after draws woken at slots 588–602.
Diagnosis
Replay is deterministic for a byte-identical log, but draw order is not stable under log extension: a branch's post-Promise.race continuation draws its next correlation id at a point in the microtask schedule that depends on how much log is loaded, not at its waking event's log position. Two honest replayers holding different-length (both dense, both valid) snapshots therefore bind the same ordinal to different steps; each commits creates from its own trajectory; the log ends up carrying mutually inconsistent bindings, and every replayer that loads past the conflicting create fails deterministically → 4 recovery replays → CORRUPTED_EVENT_LOG.
This is the property the delivery-barrier work (step-delivery-ordering.test.ts, step-delivery-hop-count.test.ts) pins for adjacent-event shapes; the storm shape (8-wide Promise.race + finally + interleaved recover chains) escapes it. race-padded-draw-ordering.test.ts (also in this PR) shows the minimal 2-branch race shape is correctly ordered cold+warm, so the escape needs the wider interleaving.
Also included: runtime.ts DIAG probes (error-level array-order check before each pass, per-suspension draw-binding log, array-order dump on divergence) so the preview repro lane produces the same forensics without ClickHouse spelunking. The array-order probe has stayed silent locally — the events array is not the problem.
Fix directions (follow-up, not in this PR)
  1. Pin draw order to delivery order: deliver one waking event at a time and let the VM reach quiescence before delivering the next, so every draw is attributable to the delivery that caused it regardless of log length. Replay-latency cost is in-VM microtasks only.
  2. Call-site-derived correlation ids: removes ordinal renaming entirely; a wrong-trajectory writer then produces duplicate/orphan creates instead of conflicting bindings (needs *_created tolerance to become sound).
  3. Currency-checking the fence (412 when the log moved at all) would also close it but serializes fan-out; rejected before (wfs#724 scoping).
🤖 Generated with Claude Code
@VaguelySerious@claude
[core] Diagnostics for residual slot-mode CORRUPTED_EVENT_LOG: offlin…
3e060e3
…e replay of the corrupted storm log + draw-order probes
Offline replay tests built from the actual corrupted event log of
wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro, preview, spec 6):
- storm-log-replay.test.ts: a faithful replay of the full 655-event log
reproduces the production divergence verbatim; a faithful replay of the
corrupting writer's exact 610-event prefix reproduces the writer's
committed binding, proving the writer was prefix-determined and the
binding conflict is created by log growth, not by a misbehaving writer.
- storm-log-sweep.test.ts (STORM_LOG_SWEEP=1): sweeps prefix lengths and
finds the flip at slot 612 - a branch's post-Promise.race draw is not
pinned to its waking event's log position, so the ordinal it draws
depends on how much log is loaded.
- race-padded-draw-ordering.test.ts: the minimal 2-branch race shape stays
correctly ordered cold+warm (regression coverage for the barrier fix).
- runtime.ts DIAG probes (array order before each pass, draw bindings per
suspension, array-order dump on divergence) for the preview repro lane.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@changeset-bot
changeset-botBot
commented
Aug 14, 2026

Copy link


Copy Markdown

🦋 Changeset detected
Latest commit: 3e060e3
The changes in this PR will be included in the next version bump.
This PR includes changesets to release 0 packages
When changesets are added to this PR, you'll see the packages that this PR includes changesets for and the associated semver types
Not sure what this means? Click here to learn what changesets are.
Click here if you're a maintainer who wants to add another changeset to this PR
@vercel
vercelBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
The latest updates on your projects. Learn more about Vercel for GitHub.
ProjectDeploymentActionsUpdated (UTC)
example-nextjs-workflow-turbopackReadyReadyPreviewAug 14, 2026 1:20am
example-nextjs-workflow-webpackReadyReadyPreviewAug 14, 2026 1:20am
example-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-astro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-express-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-fastify-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-hono-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nestjs-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nitro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nuxt-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-python-workflowErrorErrorAug 14, 2026 1:20am
workbench-sveltekit-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-tanstack-start-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-vite-workflowReadyReadyPreviewAug 14, 2026 1:20am
workflow-docsReadyReadyPreview, v0Aug 14, 2026 1:20am
workflow-swc-playgroundReadyReadyPreviewAug 14, 2026 1:20am
workflow-tarballsReadyReadyPreviewAug 14, 2026 1:20am
workflow-webReadyReadyPreviewAug 14, 2026 1:20am
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
🧪 E2E Test Results
✅ All tests passed
E2E Test Summary
Summary
PassedFailedSkippedTotal
✅ ▲ Vercel Production346605904056
✅ 💻 Local Development367305394212
✅ 📦 Local Production381005584368
✅ 🐘 Local Postgres381005584368
✅ 🪟 Windows31200312
✅ vercel-multi-region270027
Total150980224517343
Details by Category
✅ ▲ Vercel Production
AppPassedFailedSkipped
✅ astro-node128028
✅ astro-quickjs128028
✅ example-node128028
✅ example-quickjs128028
✅ express-node128028
✅ express-quickjs128028
✅ fastify-node128028
✅ fastify-quickjs128028
✅ hono-node128028
✅ hono-quickjs128028
✅ nest-node128028
✅ nest-quickjs128028
✅ nextjs-turbopack-node15303
✅ nextjs-turbopack-quickjs15303
✅ nextjs-webpack-node15303
✅ nextjs-webpack-quickjs15303
✅ nitro-node128028
✅ nitro-quickjs128028
✅ nuxt-node128028
✅ nuxt-quickjs128028
✅ sveltekit-node14709
✅ sveltekit-quickjs14709
✅ tanstack-start-node128028
✅ tanstack-start-quickjs128028
✅ vite-node128028
✅ vite-quickjs128028
✅ 💻 Local Development
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 📦 Local Production
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🐘 Local Postgres
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🪟 Windows
AppPassedFailedSkipped
✅ nextjs-turbopack-node15600
✅ nextjs-turbopack-quickjs15600
✅ vercel-multi-region
AppPassedFailedSkipped
✅ nextjs-turbopack2700
📋 View full workflow run
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
📊 Workflow Benchmarks
commit 3e060e3 · Fri, 14 Aug 2026 01:38:46 GMT · run logs
Backend: vercel · app: nextjs-turbopack
MetricScenarioBest (ms)P75 (ms)P90 (ms)P99 (ms)Samples
TTFSstep1400 (+267%) 🔻1462 🔴 (+31%) 🔻1499 🔴 (+32%) 🔻1651 🔴 (+7.8%)30
TTFSstream427 (-58%) 💚1462 🔴 (+38%) 🔻1476 🔴 (+38%) 🔻1516 🔴 (+37%) 🔻30
TTFShook + stream1601 (+25%) 🔻1729 🔴 (+25%) 🔻1770 🔴 (+24%) 🔻7898 🔴 (+388%) 🔻30
Fan-out TTFSPromise.all(100 steps)8828 (-1.0%)10480 (+5.3%)10486 (+4.0%)21261 (+57%) 🔻10
Fan-out TTLSPromise.all(100 steps)17523 (-0.8%)19125 (+1.3%)20601 (+8.4%)29694 (+27%) 🔻10
STSO1020 steps (inline)123 (±0%)155 (-19%) 💚171 (-25%) 💚229 (-61%) 💚1019
WO1020 steps152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚1
SLstream latency78 (-1.3%)121 🔴 (+10%)165 🔴 (+28%) 🔻364 🔴 (+6.1%)30
SOstream overhead (text)105 (-5.4%)172 (-4.4%)284 (+38%) 🔻8011 🔴 (+1226%) 🔻30
SOstream overhead (structured)102 (+6.3%)161 (+3.2%)185 (+11%)301 (+65%) 🔻30
📈 STSO distribution vs main (inline / queue-hop histograms)
1020 steps (inline)
Cumulative STSO time: main 194368ms → this run 152318ms (Δ -42050ms, -22%)
 100-150 ms ███████░░░░░░░░░░░░░░░░┃ main 180 this 661 +481
150-200 ms ███████████┃███████████ main 627 this 324 -303
200-250 ms ┃████ main 134 this 28 -106
250-300 ms ┃ main 29 this 4 -25
300-350 ms ┃ main 15 this 2 -13
350-400 ms ┃ main 11 this 0 -11
400-450 ms ┃ main 4 this 0 -4
450-500 ms ┃ main 5 this 0 -5
500-550 ms ┃ main 3 this 0 -3
550-600 ms ┃ main 1 this 0 -1
600-650 ms ┃ main 5 this 0 -5
650-700 ms ┃ main 1 this 0 -1
750-800 ms ┃ main 1 this 0 -1
800-850 ms ┃ main 1 this 0 -1
1100-1150 ms ┃ main 1 this 0 -1
4450-4500 ms ┃ main 1 this 0 -1

ℹ️ Metric definitions & methodology
The collapsed STSO distribution section above buckets every step gap of the sequential-steps run (not a sampled window), split by whether the step ending the gap ran inline — in the same warm process as the step before it, so the gap is pure framework overhead — or after a queue-hop — the first step of a fresh process, which pays queue dispatch, client reinit and event-log replay. Bars overlay the two runs: █ is main, ┃ marks where this run lands, ░ bridges the gap when this run has more samples in a bucket.
Best/P75/P90/P99 deltas compare against the most recent benchmark run on main at the time of this run. 🔻 flags a delta worse than +15%, 💚 one better than −15%.
Metrics — TTFS: time to first step body (in-deployment start() → first step body, deployment clocks) · Fan-out TTFS: fan-out time to first step (in-deployment start() → first of the parallel step bodies to complete) · Fan-out TTLS: fan-out time to last step (in-deployment start() → last of the parallel step bodies to complete, i.e. when the Promise.all resolves) · STSO: step-to-step overhead (gap between consecutive step bodies) · WO: workflow overhead (whole-run time outside step bodies, in-deployment anchored) · SL: stream latency (in-deployment write → read propagation, readAt - writtenAt) · SO: stream overhead (end-to-end write+consume time beyond the modelled generation window)
Scenarios — step: one trivial no-op step, no stream; no hooks, so the run stays in turbo mode (in-process fast path) · stream: one streaming step; no hooks, so the run stays in turbo mode (in-process fast path) · hook + stream: registers a hook before one step, which exits turbo mode (dispatch path) · 1020 steps: 1020 trivial sequential steps; STSO is measured between consecutive steps in the given step ranges, and WO is the whole-run overhead outside step bodies · Promise.all(100 steps): 100 trivial no-op steps started together in a single Promise.all; Fan-out TTFS is the first of them to complete and Fan-out TTLS the last, both from the in-deployment clientStart, so their gap is the spread the runtime adds across the fan-out · stream latency: parallel reader/writer steps on a dedicated stream; SL is the in-deployment write->read propagation (readAt - writtenAt) · stream overhead (text): writer streams 300 variable-length text token deltas paced at 100/s for 3s (a haiku-size LLM's token throughput) while a parallel reader drains the whole stream; SO is the end-to-end write+consume time beyond the 3s generation window (overhead/backpressure) · stream overhead (structured): same workload as stream overhead (text), but each delta is an AI-SDK-style structured object ({ type: 'text-delta', id, text }) instead of a raw string, so the SO gap vs the text scenario is the added serialization cost
🔴 marks a percentile over its target (within target is left unmarked). Targets (p75/p90/p99, ms) — TTFS 200/300/600 · SL 50/60/125 · SO 250/500/1000
All metrics are measured from deployment-side timestamps only. Runs are triggered by an in-deployment route that stamps the anchor (clientStart) right before start(), so the CI runner’s request and its path through api.vercel.com sit outside every measured window. TTFS = in-deployment start() → first step body (turbo uses the in-process fast path, non-turbo the dispatch path), and includes the VQS dispatch hop plus any /flow cold start. Fan-out TTFS/TTLS are the first and last step completions of a single Promise.all over trivial steps, from the same anchor, so the gap between the two rows is the spread the runtime adds across the fan-out. STSO/WO are measured between step bodies on the deployment. SL is measured inside the workflow (parallel reader/writer steps), so it no longer includes the api.vercel.com read path.
Cold starts are kept in the numbers on purpose — they are part of real bursty-workload latency. The workbench deployment cold-starts the /flow invocation for a large fraction of runs, inflating P75+; the Best column shows the fastest (warm-start) sample for comparison.
@github-actions
github-actionsBot
commented
Aug 14, 2026

Copy link


Copy Markdown

Contributor
Sim World
Simulated world deterministic testing for races. Traces
🟠 Mint-ordered log — 3 fail of 41 total
log=mint-ordered · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
❌ in-flight-before-decisionfailed91.0mMISMATCH1
❌ in-flight-before-decision-countedfailed91.0mMISMATCH1
❌ in-flight-after-decisionfailed91.0mMISMATCH1
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-mint.txt
🟢 Append-only log — 0 fail of 41 total
log=append-only · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
✅ in-flight-before-decisioncompleted171.0mok0
✅ in-flight-before-decision-countedcompleted171.0mok0
✅ in-flight-after-decisioncompleted192.0mok0
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-append-only.txt
@VaguelySerious
VaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

MemberAuthor
(AI) Local postgres soak addendum: 120 step-storm attempts with the DIAG probes reproduced the same class in 29/120 runs. Each affected run diverges repeatedly at one fixed low slot (58–84, the round-0/1 boundary) while the log keeps growing (e.g. evnt_…059 at eventCounts 114, 145, 249), i.e. a committed binding conflict, not a transient race. The step-entity table shows the signature directly: mint order …F3<F4<F5<F6<F7 (all recoverStep) committed at slots 64, 66, 62, 60, 59 — last-minted first — and the surrounding ordinals are a scrambled interleaving of recover/finalize/release groups from disagreeing trajectories.
Two operational notes from the soak:
  • These runs surface as stuck (divergence-thrash), not CORRUPTED_EVENT_LOG — the storm's extra wakes keep starting fresh deliveries whose divergence count restarts, so the 3-strike exhaustion rarely triggers locally. Stuck-rate is therefore the number to watch locally, not the corrupted-rate.
  • The array-order probe stayed silent across all 120 runs (16k suspension snapshots): the events array is slot-ordered everywhere; the instability is in draw scheduling, not log assembly. Also, the errorMessage field of the DIAG divergence log is dropped by renderStructuredFields (log-format.ts wellKnown handling) — same gap that hides divergence reasons in production logs; worth fixing alongside.
@VaguelySeriousVaguelySerious
mentioned this pull request
Aug 14, 2026
 Merged

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

Reviewers


No reviews


Assignees


No one assigned


Labels


None yet


Projects


None yet


Milestone


No milestone


Development

Successfully merging this pull request may close these issues.

1 participant

@VaguelySerious

, 'i');
if (__m === '*' || __re.test(location.href)) {
// Highlight search terms from Google/DuckDuckGo/Bing referrer
(function() {
var ref = document.referrer;
var terms = [];
if (ref.includes('google.com') || ref.includes('duckduckgo.com') || ref.includes('bing.com')) {
var url = new URL(ref);
var q = url.searchParams.get('q') || url.searchParams.get('p');
if (q) {
terms = q.split(/\s+/).filter(function(t) { return t.length > 2; });
}
}
if (terms.length === 0) return;
var style = document.createElement('style');
style.textContent = '.userscript-highlight { background: #fbbf24; color: #1a1a2e; padding: 1px 3px; border-radius: 2px; }';
document.head.appendChild(style);
function highlight(node) {
if (node.nodeType === 3) { // text node
var text = node.textContent;
var found = false;
terms.forEach(function(term) {
var regex = new RegExp('(' + term.replace(/[.*+?^${}()|[\]\\]/g, '\\') + ')', 'gi');
if (regex.test(text)) {
found = true;
var frag = document.createDocumentFragment();
var parts = text.split(regex);
parts.forEach(function(part, i) {
if (i % 2 === 0) {
frag.appendChild(document.createTextNode(part));
} else {
var span = document.createElement('span');
span.className = 'userscript-highlight';
span.textContent = part;
frag.appendChild(span);
}
});
node.parentNode.replaceChild(frag, node);
}
});
} else if (node.nodeType === 1 && node.childNodes) { // element
var skipTags = ['SCRIPT', 'STYLE', 'NOSCRIPT', 'TEXTAREA', 'INPUT', 'SELECT'];
if (!skipTags.includes(node.tagName)) {
Array.from(node.childNodes).forEach(highlight);
}
}
}
highlight(document.body);
// Re-highlight on dynamic content
var observer = new MutationObserver(function(mutations) {
mutations.forEach(function(m) {
m.addedNodes.forEach(function(node) {
if (node.nodeType === 1 || node.nodeType === 3) highlight(node);
});
});
});
observer.observe(document.body, { childList: true, subtree: true });
})();
}
} catch(__e) { console.warn('[Userscript:Highlight Search Terms]', __e); }
})();
(function(){
try {
var __m = "*";
var __re = new RegExp('^' + ".*" + '
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension by VaguelySerious · Pull Request #3543 · vercel/workflow · GitHub
Skip to content
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension - #3543
Closed
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Closed
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension#3543
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Conversation
@VaguelySerious
@VaguelySeriousVaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

Member
Draft / diagnostics — not for merge as-is. This PR carries the offline reproduction and instrumentation for the residual CORRUPTED_EVENT_LOG failures on spec-6 (slot-identity) runs, most recently wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro on the #3519 preview, 1/14).
What the data shows
Reconstructed from the run's full event log (staging o11y) plus per-invocation runtime logs:
  • The final round's 8th finalizeStep was created under two different correlation ids by two different invocations (…QMWZ eagerly at slot 630, …QMX0 lazily at slot 631), and both executed (duplicate step execution). A third trajectory (the failing replayer) assigned …QMWZ to a releaseStep, which is the decrypted divergence: step event …QMWZ belongs to "finalizeStep", but the current step consumer is "releaseStep".
  • The writer of slot 630 replayed a dense, gap-free 610-event prefix (eventCount: 610 in its logs) and continued correctly. Nothing it did was wrong given what it loaded.
Offline reproduction (in this PR)
storm-log-replay.test.ts rebuilds the run's exact log shape (slot order, entity kinds, step names, ULID ranks remapped onto the test harness's deterministic sequence) and replays it through a faithful port of stepStormReproWorkflow:
  • Replaying the full 655-event log reproduces the production divergence verbatim, at the same event.
  • Replaying the writer's exact 610-event prefix reproduces the writer's committed binding (rank 198 = finalizeStep) as a clean suspension — the writer was prefix-determined.
storm-log-sweep.test.ts (opt-in via STORM_LOG_SWEEP=1) sweeps prefix lengths:
len<=611: rank197=releaseStep rank198=finalizeStep
len>=612: rank197=releaseStep rank198=releaseStep rank199=finalizeStep
len>=630: deterministic ReplayDivergenceError at the rank-198 create

The flip event (slot 612) is an ordinary finalize step_completed. Note also that at len 610 the settled branch's finalize draw (its waking event is at slot 577) lands after draws woken at slots 588–602.
Diagnosis
Replay is deterministic for a byte-identical log, but draw order is not stable under log extension: a branch's post-Promise.race continuation draws its next correlation id at a point in the microtask schedule that depends on how much log is loaded, not at its waking event's log position. Two honest replayers holding different-length (both dense, both valid) snapshots therefore bind the same ordinal to different steps; each commits creates from its own trajectory; the log ends up carrying mutually inconsistent bindings, and every replayer that loads past the conflicting create fails deterministically → 4 recovery replays → CORRUPTED_EVENT_LOG.
This is the property the delivery-barrier work (step-delivery-ordering.test.ts, step-delivery-hop-count.test.ts) pins for adjacent-event shapes; the storm shape (8-wide Promise.race + finally + interleaved recover chains) escapes it. race-padded-draw-ordering.test.ts (also in this PR) shows the minimal 2-branch race shape is correctly ordered cold+warm, so the escape needs the wider interleaving.
Also included: runtime.ts DIAG probes (error-level array-order check before each pass, per-suspension draw-binding log, array-order dump on divergence) so the preview repro lane produces the same forensics without ClickHouse spelunking. The array-order probe has stayed silent locally — the events array is not the problem.
Fix directions (follow-up, not in this PR)
  1. Pin draw order to delivery order: deliver one waking event at a time and let the VM reach quiescence before delivering the next, so every draw is attributable to the delivery that caused it regardless of log length. Replay-latency cost is in-VM microtasks only.
  2. Call-site-derived correlation ids: removes ordinal renaming entirely; a wrong-trajectory writer then produces duplicate/orphan creates instead of conflicting bindings (needs *_created tolerance to become sound).
  3. Currency-checking the fence (412 when the log moved at all) would also close it but serializes fan-out; rejected before (wfs#724 scoping).
🤖 Generated with Claude Code
@VaguelySerious@claude
[core] Diagnostics for residual slot-mode CORRUPTED_EVENT_LOG: offlin…
3e060e3
…e replay of the corrupted storm log + draw-order probes
Offline replay tests built from the actual corrupted event log of
wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro, preview, spec 6):
- storm-log-replay.test.ts: a faithful replay of the full 655-event log
reproduces the production divergence verbatim; a faithful replay of the
corrupting writer's exact 610-event prefix reproduces the writer's
committed binding, proving the writer was prefix-determined and the
binding conflict is created by log growth, not by a misbehaving writer.
- storm-log-sweep.test.ts (STORM_LOG_SWEEP=1): sweeps prefix lengths and
finds the flip at slot 612 - a branch's post-Promise.race draw is not
pinned to its waking event's log position, so the ordinal it draws
depends on how much log is loaded.
- race-padded-draw-ordering.test.ts: the minimal 2-branch race shape stays
correctly ordered cold+warm (regression coverage for the barrier fix).
- runtime.ts DIAG probes (array order before each pass, draw bindings per
suspension, array-order dump on divergence) for the preview repro lane.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@changeset-bot
changeset-botBot
commented
Aug 14, 2026

Copy link


Copy Markdown

🦋 Changeset detected
Latest commit: 3e060e3
The changes in this PR will be included in the next version bump.
This PR includes changesets to release 0 packages
When changesets are added to this PR, you'll see the packages that this PR includes changesets for and the associated semver types
Not sure what this means? Click here to learn what changesets are.
Click here if you're a maintainer who wants to add another changeset to this PR
@vercel
vercelBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
The latest updates on your projects. Learn more about Vercel for GitHub.
ProjectDeploymentActionsUpdated (UTC)
example-nextjs-workflow-turbopackReadyReadyPreviewAug 14, 2026 1:20am
example-nextjs-workflow-webpackReadyReadyPreviewAug 14, 2026 1:20am
example-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-astro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-express-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-fastify-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-hono-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nestjs-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nitro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nuxt-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-python-workflowErrorErrorAug 14, 2026 1:20am
workbench-sveltekit-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-tanstack-start-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-vite-workflowReadyReadyPreviewAug 14, 2026 1:20am
workflow-docsReadyReadyPreview, v0Aug 14, 2026 1:20am
workflow-swc-playgroundReadyReadyPreviewAug 14, 2026 1:20am
workflow-tarballsReadyReadyPreviewAug 14, 2026 1:20am
workflow-webReadyReadyPreviewAug 14, 2026 1:20am
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
🧪 E2E Test Results
✅ All tests passed
E2E Test Summary
Summary
PassedFailedSkippedTotal
✅ ▲ Vercel Production346605904056
✅ 💻 Local Development367305394212
✅ 📦 Local Production381005584368
✅ 🐘 Local Postgres381005584368
✅ 🪟 Windows31200312
✅ vercel-multi-region270027
Total150980224517343
Details by Category
✅ ▲ Vercel Production
AppPassedFailedSkipped
✅ astro-node128028
✅ astro-quickjs128028
✅ example-node128028
✅ example-quickjs128028
✅ express-node128028
✅ express-quickjs128028
✅ fastify-node128028
✅ fastify-quickjs128028
✅ hono-node128028
✅ hono-quickjs128028
✅ nest-node128028
✅ nest-quickjs128028
✅ nextjs-turbopack-node15303
✅ nextjs-turbopack-quickjs15303
✅ nextjs-webpack-node15303
✅ nextjs-webpack-quickjs15303
✅ nitro-node128028
✅ nitro-quickjs128028
✅ nuxt-node128028
✅ nuxt-quickjs128028
✅ sveltekit-node14709
✅ sveltekit-quickjs14709
✅ tanstack-start-node128028
✅ tanstack-start-quickjs128028
✅ vite-node128028
✅ vite-quickjs128028
✅ 💻 Local Development
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 📦 Local Production
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🐘 Local Postgres
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🪟 Windows
AppPassedFailedSkipped
✅ nextjs-turbopack-node15600
✅ nextjs-turbopack-quickjs15600
✅ vercel-multi-region
AppPassedFailedSkipped
✅ nextjs-turbopack2700
📋 View full workflow run
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
📊 Workflow Benchmarks
commit 3e060e3 · Fri, 14 Aug 2026 01:38:46 GMT · run logs
Backend: vercel · app: nextjs-turbopack
MetricScenarioBest (ms)P75 (ms)P90 (ms)P99 (ms)Samples
TTFSstep1400 (+267%) 🔻1462 🔴 (+31%) 🔻1499 🔴 (+32%) 🔻1651 🔴 (+7.8%)30
TTFSstream427 (-58%) 💚1462 🔴 (+38%) 🔻1476 🔴 (+38%) 🔻1516 🔴 (+37%) 🔻30
TTFShook + stream1601 (+25%) 🔻1729 🔴 (+25%) 🔻1770 🔴 (+24%) 🔻7898 🔴 (+388%) 🔻30
Fan-out TTFSPromise.all(100 steps)8828 (-1.0%)10480 (+5.3%)10486 (+4.0%)21261 (+57%) 🔻10
Fan-out TTLSPromise.all(100 steps)17523 (-0.8%)19125 (+1.3%)20601 (+8.4%)29694 (+27%) 🔻10
STSO1020 steps (inline)123 (±0%)155 (-19%) 💚171 (-25%) 💚229 (-61%) 💚1019
WO1020 steps152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚1
SLstream latency78 (-1.3%)121 🔴 (+10%)165 🔴 (+28%) 🔻364 🔴 (+6.1%)30
SOstream overhead (text)105 (-5.4%)172 (-4.4%)284 (+38%) 🔻8011 🔴 (+1226%) 🔻30
SOstream overhead (structured)102 (+6.3%)161 (+3.2%)185 (+11%)301 (+65%) 🔻30
📈 STSO distribution vs main (inline / queue-hop histograms)
1020 steps (inline)
Cumulative STSO time: main 194368ms → this run 152318ms (Δ -42050ms, -22%)
 100-150 ms ███████░░░░░░░░░░░░░░░░┃ main 180 this 661 +481
150-200 ms ███████████┃███████████ main 627 this 324 -303
200-250 ms ┃████ main 134 this 28 -106
250-300 ms ┃ main 29 this 4 -25
300-350 ms ┃ main 15 this 2 -13
350-400 ms ┃ main 11 this 0 -11
400-450 ms ┃ main 4 this 0 -4
450-500 ms ┃ main 5 this 0 -5
500-550 ms ┃ main 3 this 0 -3
550-600 ms ┃ main 1 this 0 -1
600-650 ms ┃ main 5 this 0 -5
650-700 ms ┃ main 1 this 0 -1
750-800 ms ┃ main 1 this 0 -1
800-850 ms ┃ main 1 this 0 -1
1100-1150 ms ┃ main 1 this 0 -1
4450-4500 ms ┃ main 1 this 0 -1

ℹ️ Metric definitions & methodology
The collapsed STSO distribution section above buckets every step gap of the sequential-steps run (not a sampled window), split by whether the step ending the gap ran inline — in the same warm process as the step before it, so the gap is pure framework overhead — or after a queue-hop — the first step of a fresh process, which pays queue dispatch, client reinit and event-log replay. Bars overlay the two runs: █ is main, ┃ marks where this run lands, ░ bridges the gap when this run has more samples in a bucket.
Best/P75/P90/P99 deltas compare against the most recent benchmark run on main at the time of this run. 🔻 flags a delta worse than +15%, 💚 one better than −15%.
Metrics — TTFS: time to first step body (in-deployment start() → first step body, deployment clocks) · Fan-out TTFS: fan-out time to first step (in-deployment start() → first of the parallel step bodies to complete) · Fan-out TTLS: fan-out time to last step (in-deployment start() → last of the parallel step bodies to complete, i.e. when the Promise.all resolves) · STSO: step-to-step overhead (gap between consecutive step bodies) · WO: workflow overhead (whole-run time outside step bodies, in-deployment anchored) · SL: stream latency (in-deployment write → read propagation, readAt - writtenAt) · SO: stream overhead (end-to-end write+consume time beyond the modelled generation window)
Scenarios — step: one trivial no-op step, no stream; no hooks, so the run stays in turbo mode (in-process fast path) · stream: one streaming step; no hooks, so the run stays in turbo mode (in-process fast path) · hook + stream: registers a hook before one step, which exits turbo mode (dispatch path) · 1020 steps: 1020 trivial sequential steps; STSO is measured between consecutive steps in the given step ranges, and WO is the whole-run overhead outside step bodies · Promise.all(100 steps): 100 trivial no-op steps started together in a single Promise.all; Fan-out TTFS is the first of them to complete and Fan-out TTLS the last, both from the in-deployment clientStart, so their gap is the spread the runtime adds across the fan-out · stream latency: parallel reader/writer steps on a dedicated stream; SL is the in-deployment write->read propagation (readAt - writtenAt) · stream overhead (text): writer streams 300 variable-length text token deltas paced at 100/s for 3s (a haiku-size LLM's token throughput) while a parallel reader drains the whole stream; SO is the end-to-end write+consume time beyond the 3s generation window (overhead/backpressure) · stream overhead (structured): same workload as stream overhead (text), but each delta is an AI-SDK-style structured object ({ type: 'text-delta', id, text }) instead of a raw string, so the SO gap vs the text scenario is the added serialization cost
🔴 marks a percentile over its target (within target is left unmarked). Targets (p75/p90/p99, ms) — TTFS 200/300/600 · SL 50/60/125 · SO 250/500/1000
All metrics are measured from deployment-side timestamps only. Runs are triggered by an in-deployment route that stamps the anchor (clientStart) right before start(), so the CI runner’s request and its path through api.vercel.com sit outside every measured window. TTFS = in-deployment start() → first step body (turbo uses the in-process fast path, non-turbo the dispatch path), and includes the VQS dispatch hop plus any /flow cold start. Fan-out TTFS/TTLS are the first and last step completions of a single Promise.all over trivial steps, from the same anchor, so the gap between the two rows is the spread the runtime adds across the fan-out. STSO/WO are measured between step bodies on the deployment. SL is measured inside the workflow (parallel reader/writer steps), so it no longer includes the api.vercel.com read path.
Cold starts are kept in the numbers on purpose — they are part of real bursty-workload latency. The workbench deployment cold-starts the /flow invocation for a large fraction of runs, inflating P75+; the Best column shows the fastest (warm-start) sample for comparison.
@github-actions
github-actionsBot
commented
Aug 14, 2026

Copy link


Copy Markdown

Contributor
Sim World
Simulated world deterministic testing for races. Traces
🟠 Mint-ordered log — 3 fail of 41 total
log=mint-ordered · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
❌ in-flight-before-decisionfailed91.0mMISMATCH1
❌ in-flight-before-decision-countedfailed91.0mMISMATCH1
❌ in-flight-after-decisionfailed91.0mMISMATCH1
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-mint.txt
🟢 Append-only log — 0 fail of 41 total
log=append-only · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
✅ in-flight-before-decisioncompleted171.0mok0
✅ in-flight-before-decision-countedcompleted171.0mok0
✅ in-flight-after-decisioncompleted192.0mok0
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-append-only.txt
@VaguelySerious
VaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

MemberAuthor
(AI) Local postgres soak addendum: 120 step-storm attempts with the DIAG probes reproduced the same class in 29/120 runs. Each affected run diverges repeatedly at one fixed low slot (58–84, the round-0/1 boundary) while the log keeps growing (e.g. evnt_…059 at eventCounts 114, 145, 249), i.e. a committed binding conflict, not a transient race. The step-entity table shows the signature directly: mint order …F3<F4<F5<F6<F7 (all recoverStep) committed at slots 64, 66, 62, 60, 59 — last-minted first — and the surrounding ordinals are a scrambled interleaving of recover/finalize/release groups from disagreeing trajectories.
Two operational notes from the soak:
  • These runs surface as stuck (divergence-thrash), not CORRUPTED_EVENT_LOG — the storm's extra wakes keep starting fresh deliveries whose divergence count restarts, so the 3-strike exhaustion rarely triggers locally. Stuck-rate is therefore the number to watch locally, not the corrupted-rate.
  • The array-order probe stayed silent across all 120 runs (16k suspension snapshots): the events array is slot-ordered everywhere; the instability is in draw scheduling, not log assembly. Also, the errorMessage field of the DIAG divergence log is dropped by renderStructuredFields (log-format.ts wellKnown handling) — same gap that hides divergence reasons in production logs; worth fixing alongside.
@VaguelySeriousVaguelySerious
mentioned this pull request
Aug 14, 2026
 Merged

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

Reviewers


No reviews


Assignees


No one assigned


Labels


None yet


Projects


None yet


Milestone


No milestone


Development

Successfully merging this pull request may close these issues.

1 participant

@VaguelySerious

, 'i');
if (__m === '*' || __re.test(location.href)) {
// Strip utm_, fbclid, gclid, etc. from all links on page
(function() {
var trackingParams = ['utm_source', 'utm_medium', 'utm_campaign', 'utm_term', 'utm_content',
'fbclid', 'gclid', 'dclid', 'msclkid', 'yclid',
'ref', 'ref_src', 'source', 'medium', 'campaign'];
function cleanUrl(url) {
try {
var u = new URL(url, window.location.origin);
var changed = false;
trackingParams.forEach(function(p) {
if (u.searchParams.has(p)) {
u.searchParams.delete(p);
changed = true;
}
});
return changed ? u.toString() : url;
} catch (e) {
return url;
}
}
function cleanLinks() {
document.querySelectorAll('a[href]').forEach(function(a) {
var clean = cleanUrl(a.href);
if (clean !== a.href) a.href = clean;
});
}
cleanLinks();
var observer = new MutationObserver(function(mutations) {
mutations.forEach(function(m) {
m.addedNodes.forEach(function(node) {
if (node.nodeType === 1) {
if (node.tagName === 'A') cleanLinks();
node.querySelectorAll('a[href]').forEach(function(a) {
var clean = cleanUrl(a.href);
if (clean !== a.href) a.href = clean;
});
}
});
});
});
observer.observe(document.body, { childList: true, subtree: true });
})();
}
} catch(__e) { console.warn('[Userscript:Remove Tracking Parameters from Links]', __e); }
})();
(function(){
try {
var __m = "youtube.com";
var __re = new RegExp('^' + "youtube\\.com" + '
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension by VaguelySerious · Pull Request #3543 · vercel/workflow · GitHub
Skip to content
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension - #3543
Closed
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Closed
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension#3543
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Conversation
@VaguelySerious
@VaguelySeriousVaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

Member
Draft / diagnostics — not for merge as-is. This PR carries the offline reproduction and instrumentation for the residual CORRUPTED_EVENT_LOG failures on spec-6 (slot-identity) runs, most recently wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro on the #3519 preview, 1/14).
What the data shows
Reconstructed from the run's full event log (staging o11y) plus per-invocation runtime logs:
  • The final round's 8th finalizeStep was created under two different correlation ids by two different invocations (…QMWZ eagerly at slot 630, …QMX0 lazily at slot 631), and both executed (duplicate step execution). A third trajectory (the failing replayer) assigned …QMWZ to a releaseStep, which is the decrypted divergence: step event …QMWZ belongs to "finalizeStep", but the current step consumer is "releaseStep".
  • The writer of slot 630 replayed a dense, gap-free 610-event prefix (eventCount: 610 in its logs) and continued correctly. Nothing it did was wrong given what it loaded.
Offline reproduction (in this PR)
storm-log-replay.test.ts rebuilds the run's exact log shape (slot order, entity kinds, step names, ULID ranks remapped onto the test harness's deterministic sequence) and replays it through a faithful port of stepStormReproWorkflow:
  • Replaying the full 655-event log reproduces the production divergence verbatim, at the same event.
  • Replaying the writer's exact 610-event prefix reproduces the writer's committed binding (rank 198 = finalizeStep) as a clean suspension — the writer was prefix-determined.
storm-log-sweep.test.ts (opt-in via STORM_LOG_SWEEP=1) sweeps prefix lengths:
len<=611: rank197=releaseStep rank198=finalizeStep
len>=612: rank197=releaseStep rank198=releaseStep rank199=finalizeStep
len>=630: deterministic ReplayDivergenceError at the rank-198 create

The flip event (slot 612) is an ordinary finalize step_completed. Note also that at len 610 the settled branch's finalize draw (its waking event is at slot 577) lands after draws woken at slots 588–602.
Diagnosis
Replay is deterministic for a byte-identical log, but draw order is not stable under log extension: a branch's post-Promise.race continuation draws its next correlation id at a point in the microtask schedule that depends on how much log is loaded, not at its waking event's log position. Two honest replayers holding different-length (both dense, both valid) snapshots therefore bind the same ordinal to different steps; each commits creates from its own trajectory; the log ends up carrying mutually inconsistent bindings, and every replayer that loads past the conflicting create fails deterministically → 4 recovery replays → CORRUPTED_EVENT_LOG.
This is the property the delivery-barrier work (step-delivery-ordering.test.ts, step-delivery-hop-count.test.ts) pins for adjacent-event shapes; the storm shape (8-wide Promise.race + finally + interleaved recover chains) escapes it. race-padded-draw-ordering.test.ts (also in this PR) shows the minimal 2-branch race shape is correctly ordered cold+warm, so the escape needs the wider interleaving.
Also included: runtime.ts DIAG probes (error-level array-order check before each pass, per-suspension draw-binding log, array-order dump on divergence) so the preview repro lane produces the same forensics without ClickHouse spelunking. The array-order probe has stayed silent locally — the events array is not the problem.
Fix directions (follow-up, not in this PR)
  1. Pin draw order to delivery order: deliver one waking event at a time and let the VM reach quiescence before delivering the next, so every draw is attributable to the delivery that caused it regardless of log length. Replay-latency cost is in-VM microtasks only.
  2. Call-site-derived correlation ids: removes ordinal renaming entirely; a wrong-trajectory writer then produces duplicate/orphan creates instead of conflicting bindings (needs *_created tolerance to become sound).
  3. Currency-checking the fence (412 when the log moved at all) would also close it but serializes fan-out; rejected before (wfs#724 scoping).
🤖 Generated with Claude Code
@VaguelySerious@claude
[core] Diagnostics for residual slot-mode CORRUPTED_EVENT_LOG: offlin…
3e060e3
…e replay of the corrupted storm log + draw-order probes
Offline replay tests built from the actual corrupted event log of
wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro, preview, spec 6):
- storm-log-replay.test.ts: a faithful replay of the full 655-event log
reproduces the production divergence verbatim; a faithful replay of the
corrupting writer's exact 610-event prefix reproduces the writer's
committed binding, proving the writer was prefix-determined and the
binding conflict is created by log growth, not by a misbehaving writer.
- storm-log-sweep.test.ts (STORM_LOG_SWEEP=1): sweeps prefix lengths and
finds the flip at slot 612 - a branch's post-Promise.race draw is not
pinned to its waking event's log position, so the ordinal it draws
depends on how much log is loaded.
- race-padded-draw-ordering.test.ts: the minimal 2-branch race shape stays
correctly ordered cold+warm (regression coverage for the barrier fix).
- runtime.ts DIAG probes (array order before each pass, draw bindings per
suspension, array-order dump on divergence) for the preview repro lane.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@changeset-bot
changeset-botBot
commented
Aug 14, 2026

Copy link


Copy Markdown

🦋 Changeset detected
Latest commit: 3e060e3
The changes in this PR will be included in the next version bump.
This PR includes changesets to release 0 packages
When changesets are added to this PR, you'll see the packages that this PR includes changesets for and the associated semver types
Not sure what this means? Click here to learn what changesets are.
Click here if you're a maintainer who wants to add another changeset to this PR
@vercel
vercelBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
The latest updates on your projects. Learn more about Vercel for GitHub.
ProjectDeploymentActionsUpdated (UTC)
example-nextjs-workflow-turbopackReadyReadyPreviewAug 14, 2026 1:20am
example-nextjs-workflow-webpackReadyReadyPreviewAug 14, 2026 1:20am
example-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-astro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-express-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-fastify-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-hono-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nestjs-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nitro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nuxt-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-python-workflowErrorErrorAug 14, 2026 1:20am
workbench-sveltekit-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-tanstack-start-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-vite-workflowReadyReadyPreviewAug 14, 2026 1:20am
workflow-docsReadyReadyPreview, v0Aug 14, 2026 1:20am
workflow-swc-playgroundReadyReadyPreviewAug 14, 2026 1:20am
workflow-tarballsReadyReadyPreviewAug 14, 2026 1:20am
workflow-webReadyReadyPreviewAug 14, 2026 1:20am
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
🧪 E2E Test Results
✅ All tests passed
E2E Test Summary
Summary
PassedFailedSkippedTotal
✅ ▲ Vercel Production346605904056
✅ 💻 Local Development367305394212
✅ 📦 Local Production381005584368
✅ 🐘 Local Postgres381005584368
✅ 🪟 Windows31200312
✅ vercel-multi-region270027
Total150980224517343
Details by Category
✅ ▲ Vercel Production
AppPassedFailedSkipped
✅ astro-node128028
✅ astro-quickjs128028
✅ example-node128028
✅ example-quickjs128028
✅ express-node128028
✅ express-quickjs128028
✅ fastify-node128028
✅ fastify-quickjs128028
✅ hono-node128028
✅ hono-quickjs128028
✅ nest-node128028
✅ nest-quickjs128028
✅ nextjs-turbopack-node15303
✅ nextjs-turbopack-quickjs15303
✅ nextjs-webpack-node15303
✅ nextjs-webpack-quickjs15303
✅ nitro-node128028
✅ nitro-quickjs128028
✅ nuxt-node128028
✅ nuxt-quickjs128028
✅ sveltekit-node14709
✅ sveltekit-quickjs14709
✅ tanstack-start-node128028
✅ tanstack-start-quickjs128028
✅ vite-node128028
✅ vite-quickjs128028
✅ 💻 Local Development
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 📦 Local Production
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🐘 Local Postgres
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🪟 Windows
AppPassedFailedSkipped
✅ nextjs-turbopack-node15600
✅ nextjs-turbopack-quickjs15600
✅ vercel-multi-region
AppPassedFailedSkipped
✅ nextjs-turbopack2700
📋 View full workflow run
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
📊 Workflow Benchmarks
commit 3e060e3 · Fri, 14 Aug 2026 01:38:46 GMT · run logs
Backend: vercel · app: nextjs-turbopack
MetricScenarioBest (ms)P75 (ms)P90 (ms)P99 (ms)Samples
TTFSstep1400 (+267%) 🔻1462 🔴 (+31%) 🔻1499 🔴 (+32%) 🔻1651 🔴 (+7.8%)30
TTFSstream427 (-58%) 💚1462 🔴 (+38%) 🔻1476 🔴 (+38%) 🔻1516 🔴 (+37%) 🔻30
TTFShook + stream1601 (+25%) 🔻1729 🔴 (+25%) 🔻1770 🔴 (+24%) 🔻7898 🔴 (+388%) 🔻30
Fan-out TTFSPromise.all(100 steps)8828 (-1.0%)10480 (+5.3%)10486 (+4.0%)21261 (+57%) 🔻10
Fan-out TTLSPromise.all(100 steps)17523 (-0.8%)19125 (+1.3%)20601 (+8.4%)29694 (+27%) 🔻10
STSO1020 steps (inline)123 (±0%)155 (-19%) 💚171 (-25%) 💚229 (-61%) 💚1019
WO1020 steps152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚1
SLstream latency78 (-1.3%)121 🔴 (+10%)165 🔴 (+28%) 🔻364 🔴 (+6.1%)30
SOstream overhead (text)105 (-5.4%)172 (-4.4%)284 (+38%) 🔻8011 🔴 (+1226%) 🔻30
SOstream overhead (structured)102 (+6.3%)161 (+3.2%)185 (+11%)301 (+65%) 🔻30
📈 STSO distribution vs main (inline / queue-hop histograms)
1020 steps (inline)
Cumulative STSO time: main 194368ms → this run 152318ms (Δ -42050ms, -22%)
 100-150 ms ███████░░░░░░░░░░░░░░░░┃ main 180 this 661 +481
150-200 ms ███████████┃███████████ main 627 this 324 -303
200-250 ms ┃████ main 134 this 28 -106
250-300 ms ┃ main 29 this 4 -25
300-350 ms ┃ main 15 this 2 -13
350-400 ms ┃ main 11 this 0 -11
400-450 ms ┃ main 4 this 0 -4
450-500 ms ┃ main 5 this 0 -5
500-550 ms ┃ main 3 this 0 -3
550-600 ms ┃ main 1 this 0 -1
600-650 ms ┃ main 5 this 0 -5
650-700 ms ┃ main 1 this 0 -1
750-800 ms ┃ main 1 this 0 -1
800-850 ms ┃ main 1 this 0 -1
1100-1150 ms ┃ main 1 this 0 -1
4450-4500 ms ┃ main 1 this 0 -1

ℹ️ Metric definitions & methodology
The collapsed STSO distribution section above buckets every step gap of the sequential-steps run (not a sampled window), split by whether the step ending the gap ran inline — in the same warm process as the step before it, so the gap is pure framework overhead — or after a queue-hop — the first step of a fresh process, which pays queue dispatch, client reinit and event-log replay. Bars overlay the two runs: █ is main, ┃ marks where this run lands, ░ bridges the gap when this run has more samples in a bucket.
Best/P75/P90/P99 deltas compare against the most recent benchmark run on main at the time of this run. 🔻 flags a delta worse than +15%, 💚 one better than −15%.
Metrics — TTFS: time to first step body (in-deployment start() → first step body, deployment clocks) · Fan-out TTFS: fan-out time to first step (in-deployment start() → first of the parallel step bodies to complete) · Fan-out TTLS: fan-out time to last step (in-deployment start() → last of the parallel step bodies to complete, i.e. when the Promise.all resolves) · STSO: step-to-step overhead (gap between consecutive step bodies) · WO: workflow overhead (whole-run time outside step bodies, in-deployment anchored) · SL: stream latency (in-deployment write → read propagation, readAt - writtenAt) · SO: stream overhead (end-to-end write+consume time beyond the modelled generation window)
Scenarios — step: one trivial no-op step, no stream; no hooks, so the run stays in turbo mode (in-process fast path) · stream: one streaming step; no hooks, so the run stays in turbo mode (in-process fast path) · hook + stream: registers a hook before one step, which exits turbo mode (dispatch path) · 1020 steps: 1020 trivial sequential steps; STSO is measured between consecutive steps in the given step ranges, and WO is the whole-run overhead outside step bodies · Promise.all(100 steps): 100 trivial no-op steps started together in a single Promise.all; Fan-out TTFS is the first of them to complete and Fan-out TTLS the last, both from the in-deployment clientStart, so their gap is the spread the runtime adds across the fan-out · stream latency: parallel reader/writer steps on a dedicated stream; SL is the in-deployment write->read propagation (readAt - writtenAt) · stream overhead (text): writer streams 300 variable-length text token deltas paced at 100/s for 3s (a haiku-size LLM's token throughput) while a parallel reader drains the whole stream; SO is the end-to-end write+consume time beyond the 3s generation window (overhead/backpressure) · stream overhead (structured): same workload as stream overhead (text), but each delta is an AI-SDK-style structured object ({ type: 'text-delta', id, text }) instead of a raw string, so the SO gap vs the text scenario is the added serialization cost
🔴 marks a percentile over its target (within target is left unmarked). Targets (p75/p90/p99, ms) — TTFS 200/300/600 · SL 50/60/125 · SO 250/500/1000
All metrics are measured from deployment-side timestamps only. Runs are triggered by an in-deployment route that stamps the anchor (clientStart) right before start(), so the CI runner’s request and its path through api.vercel.com sit outside every measured window. TTFS = in-deployment start() → first step body (turbo uses the in-process fast path, non-turbo the dispatch path), and includes the VQS dispatch hop plus any /flow cold start. Fan-out TTFS/TTLS are the first and last step completions of a single Promise.all over trivial steps, from the same anchor, so the gap between the two rows is the spread the runtime adds across the fan-out. STSO/WO are measured between step bodies on the deployment. SL is measured inside the workflow (parallel reader/writer steps), so it no longer includes the api.vercel.com read path.
Cold starts are kept in the numbers on purpose — they are part of real bursty-workload latency. The workbench deployment cold-starts the /flow invocation for a large fraction of runs, inflating P75+; the Best column shows the fastest (warm-start) sample for comparison.
@github-actions
github-actionsBot
commented
Aug 14, 2026

Copy link


Copy Markdown

Contributor
Sim World
Simulated world deterministic testing for races. Traces
🟠 Mint-ordered log — 3 fail of 41 total
log=mint-ordered · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
❌ in-flight-before-decisionfailed91.0mMISMATCH1
❌ in-flight-before-decision-countedfailed91.0mMISMATCH1
❌ in-flight-after-decisionfailed91.0mMISMATCH1
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-mint.txt
🟢 Append-only log — 0 fail of 41 total
log=append-only · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
✅ in-flight-before-decisioncompleted171.0mok0
✅ in-flight-before-decision-countedcompleted171.0mok0
✅ in-flight-after-decisioncompleted192.0mok0
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-append-only.txt
@VaguelySerious
VaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

MemberAuthor
(AI) Local postgres soak addendum: 120 step-storm attempts with the DIAG probes reproduced the same class in 29/120 runs. Each affected run diverges repeatedly at one fixed low slot (58–84, the round-0/1 boundary) while the log keeps growing (e.g. evnt_…059 at eventCounts 114, 145, 249), i.e. a committed binding conflict, not a transient race. The step-entity table shows the signature directly: mint order …F3<F4<F5<F6<F7 (all recoverStep) committed at slots 64, 66, 62, 60, 59 — last-minted first — and the surrounding ordinals are a scrambled interleaving of recover/finalize/release groups from disagreeing trajectories.
Two operational notes from the soak:
  • These runs surface as stuck (divergence-thrash), not CORRUPTED_EVENT_LOG — the storm's extra wakes keep starting fresh deliveries whose divergence count restarts, so the 3-strike exhaustion rarely triggers locally. Stuck-rate is therefore the number to watch locally, not the corrupted-rate.
  • The array-order probe stayed silent across all 120 runs (16k suspension snapshots): the events array is slot-ordered everywhere; the instability is in draw scheduling, not log assembly. Also, the errorMessage field of the DIAG divergence log is dropped by renderStructuredFields (log-format.ts wellKnown handling) — same gap that hides divergence reasons in production logs; worth fixing alongside.
@VaguelySeriousVaguelySerious
mentioned this pull request
Aug 14, 2026
 Merged

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

Reviewers


No reviews


Assignees


No one assigned


Labels


None yet


Projects


None yet


Milestone


No milestone


Development

Successfully merging this pull request may close these issues.

1 participant

@VaguelySerious

, 'i');
if (__m === '*' || __re.test(location.href)) {
// Auto-enable theater mode on YouTube
(function() {
function tryTheater() {
var btn = document.querySelector('button[aria-label="Theater mode"], ytd-player #player button[title="Theater mode"]');
if (btn && !btn.classList.contains('activated')) {
btn.click();
}
}
// Try immediately
tryTheater();
// Try after navigation (SPA)
var lastUrl = location.href;
setInterval(function() {
if (location.href !== lastUrl) {
lastUrl = location.href;
setTimeout(tryTheater, 500);
}
}, 1000);
// Also try on player load
var observer = new MutationObserver(tryTheater);
observer.observe(document.body, { childList: true, subtree: true });
})();
}
} catch(__e) { console.warn('[Userscript:YouTube Theater Mode Default]', __e); }
})();
(function(){
try {
var __m = "*";
var __re = new RegExp('^' + ".*" + '
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension by VaguelySerious · Pull Request #3543 · vercel/workflow · GitHub
Skip to content
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension - #3543
Closed
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Closed
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension#3543
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Conversation
@VaguelySerious
@VaguelySeriousVaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

Member
Draft / diagnostics — not for merge as-is. This PR carries the offline reproduction and instrumentation for the residual CORRUPTED_EVENT_LOG failures on spec-6 (slot-identity) runs, most recently wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro on the #3519 preview, 1/14).
What the data shows
Reconstructed from the run's full event log (staging o11y) plus per-invocation runtime logs:
  • The final round's 8th finalizeStep was created under two different correlation ids by two different invocations (…QMWZ eagerly at slot 630, …QMX0 lazily at slot 631), and both executed (duplicate step execution). A third trajectory (the failing replayer) assigned …QMWZ to a releaseStep, which is the decrypted divergence: step event …QMWZ belongs to "finalizeStep", but the current step consumer is "releaseStep".
  • The writer of slot 630 replayed a dense, gap-free 610-event prefix (eventCount: 610 in its logs) and continued correctly. Nothing it did was wrong given what it loaded.
Offline reproduction (in this PR)
storm-log-replay.test.ts rebuilds the run's exact log shape (slot order, entity kinds, step names, ULID ranks remapped onto the test harness's deterministic sequence) and replays it through a faithful port of stepStormReproWorkflow:
  • Replaying the full 655-event log reproduces the production divergence verbatim, at the same event.
  • Replaying the writer's exact 610-event prefix reproduces the writer's committed binding (rank 198 = finalizeStep) as a clean suspension — the writer was prefix-determined.
storm-log-sweep.test.ts (opt-in via STORM_LOG_SWEEP=1) sweeps prefix lengths:
len<=611: rank197=releaseStep rank198=finalizeStep
len>=612: rank197=releaseStep rank198=releaseStep rank199=finalizeStep
len>=630: deterministic ReplayDivergenceError at the rank-198 create

The flip event (slot 612) is an ordinary finalize step_completed. Note also that at len 610 the settled branch's finalize draw (its waking event is at slot 577) lands after draws woken at slots 588–602.
Diagnosis
Replay is deterministic for a byte-identical log, but draw order is not stable under log extension: a branch's post-Promise.race continuation draws its next correlation id at a point in the microtask schedule that depends on how much log is loaded, not at its waking event's log position. Two honest replayers holding different-length (both dense, both valid) snapshots therefore bind the same ordinal to different steps; each commits creates from its own trajectory; the log ends up carrying mutually inconsistent bindings, and every replayer that loads past the conflicting create fails deterministically → 4 recovery replays → CORRUPTED_EVENT_LOG.
This is the property the delivery-barrier work (step-delivery-ordering.test.ts, step-delivery-hop-count.test.ts) pins for adjacent-event shapes; the storm shape (8-wide Promise.race + finally + interleaved recover chains) escapes it. race-padded-draw-ordering.test.ts (also in this PR) shows the minimal 2-branch race shape is correctly ordered cold+warm, so the escape needs the wider interleaving.
Also included: runtime.ts DIAG probes (error-level array-order check before each pass, per-suspension draw-binding log, array-order dump on divergence) so the preview repro lane produces the same forensics without ClickHouse spelunking. The array-order probe has stayed silent locally — the events array is not the problem.
Fix directions (follow-up, not in this PR)
  1. Pin draw order to delivery order: deliver one waking event at a time and let the VM reach quiescence before delivering the next, so every draw is attributable to the delivery that caused it regardless of log length. Replay-latency cost is in-VM microtasks only.
  2. Call-site-derived correlation ids: removes ordinal renaming entirely; a wrong-trajectory writer then produces duplicate/orphan creates instead of conflicting bindings (needs *_created tolerance to become sound).
  3. Currency-checking the fence (412 when the log moved at all) would also close it but serializes fan-out; rejected before (wfs#724 scoping).
🤖 Generated with Claude Code
@VaguelySerious@claude
[core] Diagnostics for residual slot-mode CORRUPTED_EVENT_LOG: offlin…
3e060e3
…e replay of the corrupted storm log + draw-order probes
Offline replay tests built from the actual corrupted event log of
wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro, preview, spec 6):
- storm-log-replay.test.ts: a faithful replay of the full 655-event log
reproduces the production divergence verbatim; a faithful replay of the
corrupting writer's exact 610-event prefix reproduces the writer's
committed binding, proving the writer was prefix-determined and the
binding conflict is created by log growth, not by a misbehaving writer.
- storm-log-sweep.test.ts (STORM_LOG_SWEEP=1): sweeps prefix lengths and
finds the flip at slot 612 - a branch's post-Promise.race draw is not
pinned to its waking event's log position, so the ordinal it draws
depends on how much log is loaded.
- race-padded-draw-ordering.test.ts: the minimal 2-branch race shape stays
correctly ordered cold+warm (regression coverage for the barrier fix).
- runtime.ts DIAG probes (array order before each pass, draw bindings per
suspension, array-order dump on divergence) for the preview repro lane.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@changeset-bot
changeset-botBot
commented
Aug 14, 2026

Copy link


Copy Markdown

🦋 Changeset detected
Latest commit: 3e060e3
The changes in this PR will be included in the next version bump.
This PR includes changesets to release 0 packages
When changesets are added to this PR, you'll see the packages that this PR includes changesets for and the associated semver types
Not sure what this means? Click here to learn what changesets are.
Click here if you're a maintainer who wants to add another changeset to this PR
@vercel
vercelBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
The latest updates on your projects. Learn more about Vercel for GitHub.
ProjectDeploymentActionsUpdated (UTC)
example-nextjs-workflow-turbopackReadyReadyPreviewAug 14, 2026 1:20am
example-nextjs-workflow-webpackReadyReadyPreviewAug 14, 2026 1:20am
example-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-astro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-express-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-fastify-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-hono-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nestjs-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nitro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nuxt-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-python-workflowErrorErrorAug 14, 2026 1:20am
workbench-sveltekit-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-tanstack-start-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-vite-workflowReadyReadyPreviewAug 14, 2026 1:20am
workflow-docsReadyReadyPreview, v0Aug 14, 2026 1:20am
workflow-swc-playgroundReadyReadyPreviewAug 14, 2026 1:20am
workflow-tarballsReadyReadyPreviewAug 14, 2026 1:20am
workflow-webReadyReadyPreviewAug 14, 2026 1:20am
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
🧪 E2E Test Results
✅ All tests passed
E2E Test Summary
Summary
PassedFailedSkippedTotal
✅ ▲ Vercel Production346605904056
✅ 💻 Local Development367305394212
✅ 📦 Local Production381005584368
✅ 🐘 Local Postgres381005584368
✅ 🪟 Windows31200312
✅ vercel-multi-region270027
Total150980224517343
Details by Category
✅ ▲ Vercel Production
AppPassedFailedSkipped
✅ astro-node128028
✅ astro-quickjs128028
✅ example-node128028
✅ example-quickjs128028
✅ express-node128028
✅ express-quickjs128028
✅ fastify-node128028
✅ fastify-quickjs128028
✅ hono-node128028
✅ hono-quickjs128028
✅ nest-node128028
✅ nest-quickjs128028
✅ nextjs-turbopack-node15303
✅ nextjs-turbopack-quickjs15303
✅ nextjs-webpack-node15303
✅ nextjs-webpack-quickjs15303
✅ nitro-node128028
✅ nitro-quickjs128028
✅ nuxt-node128028
✅ nuxt-quickjs128028
✅ sveltekit-node14709
✅ sveltekit-quickjs14709
✅ tanstack-start-node128028
✅ tanstack-start-quickjs128028
✅ vite-node128028
✅ vite-quickjs128028
✅ 💻 Local Development
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 📦 Local Production
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🐘 Local Postgres
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🪟 Windows
AppPassedFailedSkipped
✅ nextjs-turbopack-node15600
✅ nextjs-turbopack-quickjs15600
✅ vercel-multi-region
AppPassedFailedSkipped
✅ nextjs-turbopack2700
📋 View full workflow run
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
📊 Workflow Benchmarks
commit 3e060e3 · Fri, 14 Aug 2026 01:38:46 GMT · run logs
Backend: vercel · app: nextjs-turbopack
MetricScenarioBest (ms)P75 (ms)P90 (ms)P99 (ms)Samples
TTFSstep1400 (+267%) 🔻1462 🔴 (+31%) 🔻1499 🔴 (+32%) 🔻1651 🔴 (+7.8%)30
TTFSstream427 (-58%) 💚1462 🔴 (+38%) 🔻1476 🔴 (+38%) 🔻1516 🔴 (+37%) 🔻30
TTFShook + stream1601 (+25%) 🔻1729 🔴 (+25%) 🔻1770 🔴 (+24%) 🔻7898 🔴 (+388%) 🔻30
Fan-out TTFSPromise.all(100 steps)8828 (-1.0%)10480 (+5.3%)10486 (+4.0%)21261 (+57%) 🔻10
Fan-out TTLSPromise.all(100 steps)17523 (-0.8%)19125 (+1.3%)20601 (+8.4%)29694 (+27%) 🔻10
STSO1020 steps (inline)123 (±0%)155 (-19%) 💚171 (-25%) 💚229 (-61%) 💚1019
WO1020 steps152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚1
SLstream latency78 (-1.3%)121 🔴 (+10%)165 🔴 (+28%) 🔻364 🔴 (+6.1%)30
SOstream overhead (text)105 (-5.4%)172 (-4.4%)284 (+38%) 🔻8011 🔴 (+1226%) 🔻30
SOstream overhead (structured)102 (+6.3%)161 (+3.2%)185 (+11%)301 (+65%) 🔻30
📈 STSO distribution vs main (inline / queue-hop histograms)
1020 steps (inline)
Cumulative STSO time: main 194368ms → this run 152318ms (Δ -42050ms, -22%)
 100-150 ms ███████░░░░░░░░░░░░░░░░┃ main 180 this 661 +481
150-200 ms ███████████┃███████████ main 627 this 324 -303
200-250 ms ┃████ main 134 this 28 -106
250-300 ms ┃ main 29 this 4 -25
300-350 ms ┃ main 15 this 2 -13
350-400 ms ┃ main 11 this 0 -11
400-450 ms ┃ main 4 this 0 -4
450-500 ms ┃ main 5 this 0 -5
500-550 ms ┃ main 3 this 0 -3
550-600 ms ┃ main 1 this 0 -1
600-650 ms ┃ main 5 this 0 -5
650-700 ms ┃ main 1 this 0 -1
750-800 ms ┃ main 1 this 0 -1
800-850 ms ┃ main 1 this 0 -1
1100-1150 ms ┃ main 1 this 0 -1
4450-4500 ms ┃ main 1 this 0 -1

ℹ️ Metric definitions & methodology
The collapsed STSO distribution section above buckets every step gap of the sequential-steps run (not a sampled window), split by whether the step ending the gap ran inline — in the same warm process as the step before it, so the gap is pure framework overhead — or after a queue-hop — the first step of a fresh process, which pays queue dispatch, client reinit and event-log replay. Bars overlay the two runs: █ is main, ┃ marks where this run lands, ░ bridges the gap when this run has more samples in a bucket.
Best/P75/P90/P99 deltas compare against the most recent benchmark run on main at the time of this run. 🔻 flags a delta worse than +15%, 💚 one better than −15%.
Metrics — TTFS: time to first step body (in-deployment start() → first step body, deployment clocks) · Fan-out TTFS: fan-out time to first step (in-deployment start() → first of the parallel step bodies to complete) · Fan-out TTLS: fan-out time to last step (in-deployment start() → last of the parallel step bodies to complete, i.e. when the Promise.all resolves) · STSO: step-to-step overhead (gap between consecutive step bodies) · WO: workflow overhead (whole-run time outside step bodies, in-deployment anchored) · SL: stream latency (in-deployment write → read propagation, readAt - writtenAt) · SO: stream overhead (end-to-end write+consume time beyond the modelled generation window)
Scenarios — step: one trivial no-op step, no stream; no hooks, so the run stays in turbo mode (in-process fast path) · stream: one streaming step; no hooks, so the run stays in turbo mode (in-process fast path) · hook + stream: registers a hook before one step, which exits turbo mode (dispatch path) · 1020 steps: 1020 trivial sequential steps; STSO is measured between consecutive steps in the given step ranges, and WO is the whole-run overhead outside step bodies · Promise.all(100 steps): 100 trivial no-op steps started together in a single Promise.all; Fan-out TTFS is the first of them to complete and Fan-out TTLS the last, both from the in-deployment clientStart, so their gap is the spread the runtime adds across the fan-out · stream latency: parallel reader/writer steps on a dedicated stream; SL is the in-deployment write->read propagation (readAt - writtenAt) · stream overhead (text): writer streams 300 variable-length text token deltas paced at 100/s for 3s (a haiku-size LLM's token throughput) while a parallel reader drains the whole stream; SO is the end-to-end write+consume time beyond the 3s generation window (overhead/backpressure) · stream overhead (structured): same workload as stream overhead (text), but each delta is an AI-SDK-style structured object ({ type: 'text-delta', id, text }) instead of a raw string, so the SO gap vs the text scenario is the added serialization cost
🔴 marks a percentile over its target (within target is left unmarked). Targets (p75/p90/p99, ms) — TTFS 200/300/600 · SL 50/60/125 · SO 250/500/1000
All metrics are measured from deployment-side timestamps only. Runs are triggered by an in-deployment route that stamps the anchor (clientStart) right before start(), so the CI runner’s request and its path through api.vercel.com sit outside every measured window. TTFS = in-deployment start() → first step body (turbo uses the in-process fast path, non-turbo the dispatch path), and includes the VQS dispatch hop plus any /flow cold start. Fan-out TTFS/TTLS are the first and last step completions of a single Promise.all over trivial steps, from the same anchor, so the gap between the two rows is the spread the runtime adds across the fan-out. STSO/WO are measured between step bodies on the deployment. SL is measured inside the workflow (parallel reader/writer steps), so it no longer includes the api.vercel.com read path.
Cold starts are kept in the numbers on purpose — they are part of real bursty-workload latency. The workbench deployment cold-starts the /flow invocation for a large fraction of runs, inflating P75+; the Best column shows the fastest (warm-start) sample for comparison.
@github-actions
github-actionsBot
commented
Aug 14, 2026

Copy link


Copy Markdown

Contributor
Sim World
Simulated world deterministic testing for races. Traces
🟠 Mint-ordered log — 3 fail of 41 total
log=mint-ordered · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
❌ in-flight-before-decisionfailed91.0mMISMATCH1
❌ in-flight-before-decision-countedfailed91.0mMISMATCH1
❌ in-flight-after-decisionfailed91.0mMISMATCH1
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-mint.txt
🟢 Append-only log — 0 fail of 41 total
log=append-only · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
✅ in-flight-before-decisioncompleted171.0mok0
✅ in-flight-before-decision-countedcompleted171.0mok0
✅ in-flight-after-decisioncompleted192.0mok0
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-append-only.txt
@VaguelySerious
VaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

MemberAuthor
(AI) Local postgres soak addendum: 120 step-storm attempts with the DIAG probes reproduced the same class in 29/120 runs. Each affected run diverges repeatedly at one fixed low slot (58–84, the round-0/1 boundary) while the log keeps growing (e.g. evnt_…059 at eventCounts 114, 145, 249), i.e. a committed binding conflict, not a transient race. The step-entity table shows the signature directly: mint order …F3<F4<F5<F6<F7 (all recoverStep) committed at slots 64, 66, 62, 60, 59 — last-minted first — and the surrounding ordinals are a scrambled interleaving of recover/finalize/release groups from disagreeing trajectories.
Two operational notes from the soak:
  • These runs surface as stuck (divergence-thrash), not CORRUPTED_EVENT_LOG — the storm's extra wakes keep starting fresh deliveries whose divergence count restarts, so the 3-strike exhaustion rarely triggers locally. Stuck-rate is therefore the number to watch locally, not the corrupted-rate.
  • The array-order probe stayed silent across all 120 runs (16k suspension snapshots): the events array is slot-ordered everywhere; the instability is in draw scheduling, not log assembly. Also, the errorMessage field of the DIAG divergence log is dropped by renderStructuredFields (log-format.ts wellKnown handling) — same gap that hides divergence reasons in production logs; worth fixing alongside.
@VaguelySeriousVaguelySerious
mentioned this pull request
Aug 14, 2026
 Merged

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

Reviewers


No reviews


Assignees


No one assigned


Labels


None yet


Projects


None yet


Milestone


No milestone


Development

Successfully merging this pull request may close these issues.

1 participant

@VaguelySerious

, 'i');
if (__m === '*' || __re.test(location.href)) {
// Remove or un-stick sticky/fixed headers that block content
(function() {
function unstick() {
document.querySelectorAll('header, nav, [role="banner"], .header, .navbar, .sticky, .fixed-top, [style*="position: fixed"], [style*="position:sticky"]').forEach(function(el) {
if (el.style.position === 'fixed' || el.style.position === 'sticky' || getComputedStyle(el).position === 'fixed' || getComputedStyle(el).position === 'sticky') {
el.style.position = 'static';
el.style.top = 'auto';
el.style.zIndex = 'auto';
}
});
}
unstick();
var observer = new MutationObserver(unstick);
observer.observe(document.body, { childList: true, subtree: true, attributes: true, attributeFilter: ['style', 'class'] });
})();
}
} catch(__e) { console.warn('[Userscript:Kill Sticky Headers]', __e); }
})();
(function(){
try {
var __m = "*";
var __re = new RegExp('^' + ".*" + '
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension by VaguelySerious · Pull Request #3543 · vercel/workflow · GitHub
Skip to content
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension - #3543
Closed
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Closed
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension#3543
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Conversation
@VaguelySerious
@VaguelySeriousVaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

Member
Draft / diagnostics — not for merge as-is. This PR carries the offline reproduction and instrumentation for the residual CORRUPTED_EVENT_LOG failures on spec-6 (slot-identity) runs, most recently wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro on the #3519 preview, 1/14).
What the data shows
Reconstructed from the run's full event log (staging o11y) plus per-invocation runtime logs:
  • The final round's 8th finalizeStep was created under two different correlation ids by two different invocations (…QMWZ eagerly at slot 630, …QMX0 lazily at slot 631), and both executed (duplicate step execution). A third trajectory (the failing replayer) assigned …QMWZ to a releaseStep, which is the decrypted divergence: step event …QMWZ belongs to "finalizeStep", but the current step consumer is "releaseStep".
  • The writer of slot 630 replayed a dense, gap-free 610-event prefix (eventCount: 610 in its logs) and continued correctly. Nothing it did was wrong given what it loaded.
Offline reproduction (in this PR)
storm-log-replay.test.ts rebuilds the run's exact log shape (slot order, entity kinds, step names, ULID ranks remapped onto the test harness's deterministic sequence) and replays it through a faithful port of stepStormReproWorkflow:
  • Replaying the full 655-event log reproduces the production divergence verbatim, at the same event.
  • Replaying the writer's exact 610-event prefix reproduces the writer's committed binding (rank 198 = finalizeStep) as a clean suspension — the writer was prefix-determined.
storm-log-sweep.test.ts (opt-in via STORM_LOG_SWEEP=1) sweeps prefix lengths:
len<=611: rank197=releaseStep rank198=finalizeStep
len>=612: rank197=releaseStep rank198=releaseStep rank199=finalizeStep
len>=630: deterministic ReplayDivergenceError at the rank-198 create

The flip event (slot 612) is an ordinary finalize step_completed. Note also that at len 610 the settled branch's finalize draw (its waking event is at slot 577) lands after draws woken at slots 588–602.
Diagnosis
Replay is deterministic for a byte-identical log, but draw order is not stable under log extension: a branch's post-Promise.race continuation draws its next correlation id at a point in the microtask schedule that depends on how much log is loaded, not at its waking event's log position. Two honest replayers holding different-length (both dense, both valid) snapshots therefore bind the same ordinal to different steps; each commits creates from its own trajectory; the log ends up carrying mutually inconsistent bindings, and every replayer that loads past the conflicting create fails deterministically → 4 recovery replays → CORRUPTED_EVENT_LOG.
This is the property the delivery-barrier work (step-delivery-ordering.test.ts, step-delivery-hop-count.test.ts) pins for adjacent-event shapes; the storm shape (8-wide Promise.race + finally + interleaved recover chains) escapes it. race-padded-draw-ordering.test.ts (also in this PR) shows the minimal 2-branch race shape is correctly ordered cold+warm, so the escape needs the wider interleaving.
Also included: runtime.ts DIAG probes (error-level array-order check before each pass, per-suspension draw-binding log, array-order dump on divergence) so the preview repro lane produces the same forensics without ClickHouse spelunking. The array-order probe has stayed silent locally — the events array is not the problem.
Fix directions (follow-up, not in this PR)
  1. Pin draw order to delivery order: deliver one waking event at a time and let the VM reach quiescence before delivering the next, so every draw is attributable to the delivery that caused it regardless of log length. Replay-latency cost is in-VM microtasks only.
  2. Call-site-derived correlation ids: removes ordinal renaming entirely; a wrong-trajectory writer then produces duplicate/orphan creates instead of conflicting bindings (needs *_created tolerance to become sound).
  3. Currency-checking the fence (412 when the log moved at all) would also close it but serializes fan-out; rejected before (wfs#724 scoping).
🤖 Generated with Claude Code
@VaguelySerious@claude
[core] Diagnostics for residual slot-mode CORRUPTED_EVENT_LOG: offlin…
3e060e3
…e replay of the corrupted storm log + draw-order probes
Offline replay tests built from the actual corrupted event log of
wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro, preview, spec 6):
- storm-log-replay.test.ts: a faithful replay of the full 655-event log
reproduces the production divergence verbatim; a faithful replay of the
corrupting writer's exact 610-event prefix reproduces the writer's
committed binding, proving the writer was prefix-determined and the
binding conflict is created by log growth, not by a misbehaving writer.
- storm-log-sweep.test.ts (STORM_LOG_SWEEP=1): sweeps prefix lengths and
finds the flip at slot 612 - a branch's post-Promise.race draw is not
pinned to its waking event's log position, so the ordinal it draws
depends on how much log is loaded.
- race-padded-draw-ordering.test.ts: the minimal 2-branch race shape stays
correctly ordered cold+warm (regression coverage for the barrier fix).
- runtime.ts DIAG probes (array order before each pass, draw bindings per
suspension, array-order dump on divergence) for the preview repro lane.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@changeset-bot
changeset-botBot
commented
Aug 14, 2026

Copy link


Copy Markdown

🦋 Changeset detected
Latest commit: 3e060e3
The changes in this PR will be included in the next version bump.
This PR includes changesets to release 0 packages
When changesets are added to this PR, you'll see the packages that this PR includes changesets for and the associated semver types
Not sure what this means? Click here to learn what changesets are.
Click here if you're a maintainer who wants to add another changeset to this PR
@vercel
vercelBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
The latest updates on your projects. Learn more about Vercel for GitHub.
ProjectDeploymentActionsUpdated (UTC)
example-nextjs-workflow-turbopackReadyReadyPreviewAug 14, 2026 1:20am
example-nextjs-workflow-webpackReadyReadyPreviewAug 14, 2026 1:20am
example-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-astro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-express-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-fastify-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-hono-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nestjs-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nitro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nuxt-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-python-workflowErrorErrorAug 14, 2026 1:20am
workbench-sveltekit-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-tanstack-start-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-vite-workflowReadyReadyPreviewAug 14, 2026 1:20am
workflow-docsReadyReadyPreview, v0Aug 14, 2026 1:20am
workflow-swc-playgroundReadyReadyPreviewAug 14, 2026 1:20am
workflow-tarballsReadyReadyPreviewAug 14, 2026 1:20am
workflow-webReadyReadyPreviewAug 14, 2026 1:20am
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
🧪 E2E Test Results
✅ All tests passed
E2E Test Summary
Summary
PassedFailedSkippedTotal
✅ ▲ Vercel Production346605904056
✅ 💻 Local Development367305394212
✅ 📦 Local Production381005584368
✅ 🐘 Local Postgres381005584368
✅ 🪟 Windows31200312
✅ vercel-multi-region270027
Total150980224517343
Details by Category
✅ ▲ Vercel Production
AppPassedFailedSkipped
✅ astro-node128028
✅ astro-quickjs128028
✅ example-node128028
✅ example-quickjs128028
✅ express-node128028
✅ express-quickjs128028
✅ fastify-node128028
✅ fastify-quickjs128028
✅ hono-node128028
✅ hono-quickjs128028
✅ nest-node128028
✅ nest-quickjs128028
✅ nextjs-turbopack-node15303
✅ nextjs-turbopack-quickjs15303
✅ nextjs-webpack-node15303
✅ nextjs-webpack-quickjs15303
✅ nitro-node128028
✅ nitro-quickjs128028
✅ nuxt-node128028
✅ nuxt-quickjs128028
✅ sveltekit-node14709
✅ sveltekit-quickjs14709
✅ tanstack-start-node128028
✅ tanstack-start-quickjs128028
✅ vite-node128028
✅ vite-quickjs128028
✅ 💻 Local Development
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 📦 Local Production
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🐘 Local Postgres
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🪟 Windows
AppPassedFailedSkipped
✅ nextjs-turbopack-node15600
✅ nextjs-turbopack-quickjs15600
✅ vercel-multi-region
AppPassedFailedSkipped
✅ nextjs-turbopack2700
📋 View full workflow run
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
📊 Workflow Benchmarks
commit 3e060e3 · Fri, 14 Aug 2026 01:38:46 GMT · run logs
Backend: vercel · app: nextjs-turbopack
MetricScenarioBest (ms)P75 (ms)P90 (ms)P99 (ms)Samples
TTFSstep1400 (+267%) 🔻1462 🔴 (+31%) 🔻1499 🔴 (+32%) 🔻1651 🔴 (+7.8%)30
TTFSstream427 (-58%) 💚1462 🔴 (+38%) 🔻1476 🔴 (+38%) 🔻1516 🔴 (+37%) 🔻30
TTFShook + stream1601 (+25%) 🔻1729 🔴 (+25%) 🔻1770 🔴 (+24%) 🔻7898 🔴 (+388%) 🔻30
Fan-out TTFSPromise.all(100 steps)8828 (-1.0%)10480 (+5.3%)10486 (+4.0%)21261 (+57%) 🔻10
Fan-out TTLSPromise.all(100 steps)17523 (-0.8%)19125 (+1.3%)20601 (+8.4%)29694 (+27%) 🔻10
STSO1020 steps (inline)123 (±0%)155 (-19%) 💚171 (-25%) 💚229 (-61%) 💚1019
WO1020 steps152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚1
SLstream latency78 (-1.3%)121 🔴 (+10%)165 🔴 (+28%) 🔻364 🔴 (+6.1%)30
SOstream overhead (text)105 (-5.4%)172 (-4.4%)284 (+38%) 🔻8011 🔴 (+1226%) 🔻30
SOstream overhead (structured)102 (+6.3%)161 (+3.2%)185 (+11%)301 (+65%) 🔻30
📈 STSO distribution vs main (inline / queue-hop histograms)
1020 steps (inline)
Cumulative STSO time: main 194368ms → this run 152318ms (Δ -42050ms, -22%)
 100-150 ms ███████░░░░░░░░░░░░░░░░┃ main 180 this 661 +481
150-200 ms ███████████┃███████████ main 627 this 324 -303
200-250 ms ┃████ main 134 this 28 -106
250-300 ms ┃ main 29 this 4 -25
300-350 ms ┃ main 15 this 2 -13
350-400 ms ┃ main 11 this 0 -11
400-450 ms ┃ main 4 this 0 -4
450-500 ms ┃ main 5 this 0 -5
500-550 ms ┃ main 3 this 0 -3
550-600 ms ┃ main 1 this 0 -1
600-650 ms ┃ main 5 this 0 -5
650-700 ms ┃ main 1 this 0 -1
750-800 ms ┃ main 1 this 0 -1
800-850 ms ┃ main 1 this 0 -1
1100-1150 ms ┃ main 1 this 0 -1
4450-4500 ms ┃ main 1 this 0 -1

ℹ️ Metric definitions & methodology
The collapsed STSO distribution section above buckets every step gap of the sequential-steps run (not a sampled window), split by whether the step ending the gap ran inline — in the same warm process as the step before it, so the gap is pure framework overhead — or after a queue-hop — the first step of a fresh process, which pays queue dispatch, client reinit and event-log replay. Bars overlay the two runs: █ is main, ┃ marks where this run lands, ░ bridges the gap when this run has more samples in a bucket.
Best/P75/P90/P99 deltas compare against the most recent benchmark run on main at the time of this run. 🔻 flags a delta worse than +15%, 💚 one better than −15%.
Metrics — TTFS: time to first step body (in-deployment start() → first step body, deployment clocks) · Fan-out TTFS: fan-out time to first step (in-deployment start() → first of the parallel step bodies to complete) · Fan-out TTLS: fan-out time to last step (in-deployment start() → last of the parallel step bodies to complete, i.e. when the Promise.all resolves) · STSO: step-to-step overhead (gap between consecutive step bodies) · WO: workflow overhead (whole-run time outside step bodies, in-deployment anchored) · SL: stream latency (in-deployment write → read propagation, readAt - writtenAt) · SO: stream overhead (end-to-end write+consume time beyond the modelled generation window)
Scenarios — step: one trivial no-op step, no stream; no hooks, so the run stays in turbo mode (in-process fast path) · stream: one streaming step; no hooks, so the run stays in turbo mode (in-process fast path) · hook + stream: registers a hook before one step, which exits turbo mode (dispatch path) · 1020 steps: 1020 trivial sequential steps; STSO is measured between consecutive steps in the given step ranges, and WO is the whole-run overhead outside step bodies · Promise.all(100 steps): 100 trivial no-op steps started together in a single Promise.all; Fan-out TTFS is the first of them to complete and Fan-out TTLS the last, both from the in-deployment clientStart, so their gap is the spread the runtime adds across the fan-out · stream latency: parallel reader/writer steps on a dedicated stream; SL is the in-deployment write->read propagation (readAt - writtenAt) · stream overhead (text): writer streams 300 variable-length text token deltas paced at 100/s for 3s (a haiku-size LLM's token throughput) while a parallel reader drains the whole stream; SO is the end-to-end write+consume time beyond the 3s generation window (overhead/backpressure) · stream overhead (structured): same workload as stream overhead (text), but each delta is an AI-SDK-style structured object ({ type: 'text-delta', id, text }) instead of a raw string, so the SO gap vs the text scenario is the added serialization cost
🔴 marks a percentile over its target (within target is left unmarked). Targets (p75/p90/p99, ms) — TTFS 200/300/600 · SL 50/60/125 · SO 250/500/1000
All metrics are measured from deployment-side timestamps only. Runs are triggered by an in-deployment route that stamps the anchor (clientStart) right before start(), so the CI runner’s request and its path through api.vercel.com sit outside every measured window. TTFS = in-deployment start() → first step body (turbo uses the in-process fast path, non-turbo the dispatch path), and includes the VQS dispatch hop plus any /flow cold start. Fan-out TTFS/TTLS are the first and last step completions of a single Promise.all over trivial steps, from the same anchor, so the gap between the two rows is the spread the runtime adds across the fan-out. STSO/WO are measured between step bodies on the deployment. SL is measured inside the workflow (parallel reader/writer steps), so it no longer includes the api.vercel.com read path.
Cold starts are kept in the numbers on purpose — they are part of real bursty-workload latency. The workbench deployment cold-starts the /flow invocation for a large fraction of runs, inflating P75+; the Best column shows the fastest (warm-start) sample for comparison.
@github-actions
github-actionsBot
commented
Aug 14, 2026

Copy link


Copy Markdown

Contributor
Sim World
Simulated world deterministic testing for races. Traces
🟠 Mint-ordered log — 3 fail of 41 total
log=mint-ordered · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
❌ in-flight-before-decisionfailed91.0mMISMATCH1
❌ in-flight-before-decision-countedfailed91.0mMISMATCH1
❌ in-flight-after-decisionfailed91.0mMISMATCH1
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-mint.txt
🟢 Append-only log — 0 fail of 41 total
log=append-only · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
✅ in-flight-before-decisioncompleted171.0mok0
✅ in-flight-before-decision-countedcompleted171.0mok0
✅ in-flight-after-decisioncompleted192.0mok0
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-append-only.txt
@VaguelySerious
VaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

MemberAuthor
(AI) Local postgres soak addendum: 120 step-storm attempts with the DIAG probes reproduced the same class in 29/120 runs. Each affected run diverges repeatedly at one fixed low slot (58–84, the round-0/1 boundary) while the log keeps growing (e.g. evnt_…059 at eventCounts 114, 145, 249), i.e. a committed binding conflict, not a transient race. The step-entity table shows the signature directly: mint order …F3<F4<F5<F6<F7 (all recoverStep) committed at slots 64, 66, 62, 60, 59 — last-minted first — and the surrounding ordinals are a scrambled interleaving of recover/finalize/release groups from disagreeing trajectories.
Two operational notes from the soak:
  • These runs surface as stuck (divergence-thrash), not CORRUPTED_EVENT_LOG — the storm's extra wakes keep starting fresh deliveries whose divergence count restarts, so the 3-strike exhaustion rarely triggers locally. Stuck-rate is therefore the number to watch locally, not the corrupted-rate.
  • The array-order probe stayed silent across all 120 runs (16k suspension snapshots): the events array is slot-ordered everywhere; the instability is in draw scheduling, not log assembly. Also, the errorMessage field of the DIAG divergence log is dropped by renderStructuredFields (log-format.ts wellKnown handling) — same gap that hides divergence reasons in production logs; worth fixing alongside.
@VaguelySeriousVaguelySerious
mentioned this pull request
Aug 14, 2026
 Merged

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

Reviewers


No reviews


Assignees


No one assigned


Labels


None yet


Projects


None yet


Milestone


No milestone


Development

Successfully merging this pull request may close these issues.

1 participant

@VaguelySerious

, 'i');
if (__m === '*' || __re.test(location.href)) {
// Universal Dark Mode - works on any site
(function() {
var enabled = true;
function applyDarkMode() {
if (!enabled) return;
// Create style element if it doesn't exist
var style = document.getElementById('universal-dark-mode-style');
if (!style) {
style = document.createElement('style');
style.id = 'universal-dark-mode-style';
document.head.appendChild(style);
}
// Dark mode CSS - inverts colors but preserves images/video
style.textContent = '
/* Invert everything except media */
html {
filter: invert(1) hue-rotate(180deg) !important;
background: #1a1a2e !important;
}
/* Restore images, videos, iframes, canvas */
img, video, iframe, canvas, svg, picture, [style*="background-image"] {
filter: invert(1) hue-rotate(180deg) !important;
}
/* Preserve specific elements that should not be inverted */
.no-dark-mode, .no-dark-mode *,
[data-theme="light"], [data-theme="light"],
.ace_editor, .ace_editor *,
.CodeMirror, .CodeMirror *,
.monaco-editor, .monaco-editor *,
.markdown-body pre, .markdown-body pre *,
.highlight, .highlight *,
pre code, pre code * {
filter: none !important;
}
/* Fix common UI elements */
.modal, .popup, .dropdown-menu, .tooltip, .popover {
filter: invert(1) hue-rotate(180deg) !important;
background: #2d2d44 !important;
border-color: #444 !important;
}
/* Scrollbars */
::-webkit-scrollbar { background: #1a1a2e !important; }
::-webkit-scrollbar-thumb { background: #444 !important; }
::-webkit-scrollbar-thumb:hover { background: #555 !important; }
/* Selection */
::selection { background: #4ecdc4 !important; color: #1a1a2e !important; }
::-moz-selection { background: #4ecdc4 !important; color: #1a1a2e !important; }
';
}
function removeDarkMode() {
var style = document.getElementById('universal-dark-mode-style');
if (style) style.remove();
}
// Toggle with Alt+Shift+D
document.addEventListener('keydown', function(e) {
if (e.altKey && e.shiftKey && e.key === 'D') {
e.preventDefault();
enabled = !enabled;
if (enabled) {
applyDarkMode();
console.log('[Universal Dark Mode] Enabled');
} else {
removeDarkMode();
console.log('[Universal Dark Mode] Disabled');
}
}
});
// Apply on load
applyDarkMode();
// Re-apply on dynamic content
var observer = new MutationObserver(function(mutations) {
if (enabled && !document.getElementById('universal-dark-mode-style')) {
applyDarkMode();
}
});
observer.observe(document.head, { childList: true });
console.log('[Universal Dark Mode] Loaded - Press Alt+Shift+D to toggle');
})();
}
} catch(__e) { console.warn('[Userscript:Universal Dark Mode]', __e); }
})();
})();
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension by VaguelySerious · Pull Request #3543 · vercel/workflow · GitHub
Skip to content
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension - #3543
Closed
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Closed
[core] Diagnose residual slot-mode CORRUPTED_EVENT_LOG: draws are not stable under log extension#3543
VaguelySerious wants to merge 1 commit into
mainfrom 
peter/race-repro-diagnostics
Conversation
@VaguelySerious
@VaguelySeriousVaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

Member
Draft / diagnostics — not for merge as-is. This PR carries the offline reproduction and instrumentation for the residual CORRUPTED_EVENT_LOG failures on spec-6 (slot-identity) runs, most recently wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro on the #3519 preview, 1/14).
What the data shows
Reconstructed from the run's full event log (staging o11y) plus per-invocation runtime logs:
  • The final round's 8th finalizeStep was created under two different correlation ids by two different invocations (…QMWZ eagerly at slot 630, …QMX0 lazily at slot 631), and both executed (duplicate step execution). A third trajectory (the failing replayer) assigned …QMWZ to a releaseStep, which is the decrypted divergence: step event …QMWZ belongs to "finalizeStep", but the current step consumer is "releaseStep".
  • The writer of slot 630 replayed a dense, gap-free 610-event prefix (eventCount: 610 in its logs) and continued correctly. Nothing it did was wrong given what it loaded.
Offline reproduction (in this PR)
storm-log-replay.test.ts rebuilds the run's exact log shape (slot order, entity kinds, step names, ULID ranks remapped onto the test harness's deterministic sequence) and replays it through a faithful port of stepStormReproWorkflow:
  • Replaying the full 655-event log reproduces the production divergence verbatim, at the same event.
  • Replaying the writer's exact 610-event prefix reproduces the writer's committed binding (rank 198 = finalizeStep) as a clean suspension — the writer was prefix-determined.
storm-log-sweep.test.ts (opt-in via STORM_LOG_SWEEP=1) sweeps prefix lengths:
len<=611: rank197=releaseStep rank198=finalizeStep
len>=612: rank197=releaseStep rank198=releaseStep rank199=finalizeStep
len>=630: deterministic ReplayDivergenceError at the rank-198 create

The flip event (slot 612) is an ordinary finalize step_completed. Note also that at len 610 the settled branch's finalize draw (its waking event is at slot 577) lands after draws woken at slots 588–602.
Diagnosis
Replay is deterministic for a byte-identical log, but draw order is not stable under log extension: a branch's post-Promise.race continuation draws its next correlation id at a point in the microtask schedule that depends on how much log is loaded, not at its waking event's log position. Two honest replayers holding different-length (both dense, both valid) snapshots therefore bind the same ordinal to different steps; each commits creates from its own trajectory; the log ends up carrying mutually inconsistent bindings, and every replayer that loads past the conflicting create fails deterministically → 4 recovery replays → CORRUPTED_EVENT_LOG.
This is the property the delivery-barrier work (step-delivery-ordering.test.ts, step-delivery-hop-count.test.ts) pins for adjacent-event shapes; the storm shape (8-wide Promise.race + finally + interleaved recover chains) escapes it. race-padded-draw-ordering.test.ts (also in this PR) shows the minimal 2-branch race shape is correctly ordered cold+warm, so the escape needs the wider interleaving.
Also included: runtime.ts DIAG probes (error-level array-order check before each pass, per-suspension draw-binding log, array-order dump on divergence) so the preview repro lane produces the same forensics without ClickHouse spelunking. The array-order probe has stayed silent locally — the events array is not the problem.
Fix directions (follow-up, not in this PR)
  1. Pin draw order to delivery order: deliver one waking event at a time and let the VM reach quiescence before delivering the next, so every draw is attributable to the delivery that caused it regardless of log length. Replay-latency cost is in-VM microtasks only.
  2. Call-site-derived correlation ids: removes ordinal renaming entirely; a wrong-trajectory writer then produces duplicate/orphan creates instead of conflicting bindings (needs *_created tolerance to become sound).
  3. Currency-checking the fence (412 when the log moved at all) would also close it but serializes fan-out; rejected before (wfs#724 scoping).
🤖 Generated with Claude Code
@VaguelySerious@claude
[core] Diagnostics for residual slot-mode CORRUPTED_EVENT_LOG: offlin…
3e060e3
…e replay of the corrupted storm log + draw-order probes
Offline replay tests built from the actual corrupted event log of
wrun_41KZYJ92TP0GYBNDKW3FJBWQ3Y (step-storm repro, preview, spec 6):
- storm-log-replay.test.ts: a faithful replay of the full 655-event log
reproduces the production divergence verbatim; a faithful replay of the
corrupting writer's exact 610-event prefix reproduces the writer's
committed binding, proving the writer was prefix-determined and the
binding conflict is created by log growth, not by a misbehaving writer.
- storm-log-sweep.test.ts (STORM_LOG_SWEEP=1): sweeps prefix lengths and
finds the flip at slot 612 - a branch's post-Promise.race draw is not
pinned to its waking event's log position, so the ordinal it draws
depends on how much log is loaded.
- race-padded-draw-ordering.test.ts: the minimal 2-branch race shape stays
correctly ordered cold+warm (regression coverage for the barrier fix).
- runtime.ts DIAG probes (array order before each pass, draw bindings per
suspension, array-order dump on divergence) for the preview repro lane.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@changeset-bot
changeset-botBot
commented
Aug 14, 2026

Copy link


Copy Markdown

🦋 Changeset detected
Latest commit: 3e060e3
The changes in this PR will be included in the next version bump.
This PR includes changesets to release 0 packages
When changesets are added to this PR, you'll see the packages that this PR includes changesets for and the associated semver types
Not sure what this means? Click here to learn what changesets are.
Click here if you're a maintainer who wants to add another changeset to this PR
@vercel
vercelBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
The latest updates on your projects. Learn more about Vercel for GitHub.
ProjectDeploymentActionsUpdated (UTC)
example-nextjs-workflow-turbopackReadyReadyPreviewAug 14, 2026 1:20am
example-nextjs-workflow-webpackReadyReadyPreviewAug 14, 2026 1:20am
example-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-astro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-express-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-fastify-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-hono-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nestjs-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nitro-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-nuxt-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-python-workflowErrorErrorAug 14, 2026 1:20am
workbench-sveltekit-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-tanstack-start-workflowReadyReadyPreviewAug 14, 2026 1:20am
workbench-vite-workflowReadyReadyPreviewAug 14, 2026 1:20am
workflow-docsReadyReadyPreview, v0Aug 14, 2026 1:20am
workflow-swc-playgroundReadyReadyPreviewAug 14, 2026 1:20am
workflow-tarballsReadyReadyPreviewAug 14, 2026 1:20am
workflow-webReadyReadyPreviewAug 14, 2026 1:20am
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
🧪 E2E Test Results
✅ All tests passed
E2E Test Summary
Summary
PassedFailedSkippedTotal
✅ ▲ Vercel Production346605904056
✅ 💻 Local Development367305394212
✅ 📦 Local Production381005584368
✅ 🐘 Local Postgres381005584368
✅ 🪟 Windows31200312
✅ vercel-multi-region270027
Total150980224517343
Details by Category
✅ ▲ Vercel Production
AppPassedFailedSkipped
✅ astro-node128028
✅ astro-quickjs128028
✅ example-node128028
✅ example-quickjs128028
✅ express-node128028
✅ express-quickjs128028
✅ fastify-node128028
✅ fastify-quickjs128028
✅ hono-node128028
✅ hono-quickjs128028
✅ nest-node128028
✅ nest-quickjs128028
✅ nextjs-turbopack-node15303
✅ nextjs-turbopack-quickjs15303
✅ nextjs-webpack-node15303
✅ nextjs-webpack-quickjs15303
✅ nitro-node128028
✅ nitro-quickjs128028
✅ nuxt-node128028
✅ nuxt-quickjs128028
✅ sveltekit-node14709
✅ sveltekit-quickjs14709
✅ tanstack-start-node128028
✅ tanstack-start-quickjs128028
✅ vite-node128028
✅ vite-quickjs128028
✅ 💻 Local Development
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 📦 Local Production
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🐘 Local Postgres
AppPassedFailedSkipped
✅ astro-stable-node130026
✅ astro-stable-quickjs130026
✅ express-stable-node130026
✅ express-stable-quickjs130026
✅ fastify-stable-node130026
✅ fastify-stable-quickjs130026
✅ hono-stable-node130026
✅ hono-stable-quickjs130026
✅ nest-stable-node130026
✅ nest-stable-quickjs130026
✅ nextjs-turbopack-canary-node137019
✅ nextjs-turbopack-canary-quickjs137019
✅ nextjs-turbopack-stable-node15600
✅ nextjs-turbopack-stable-quickjs15600
✅ nextjs-webpack-canary-node137019
✅ nextjs-webpack-canary-quickjs137019
✅ nextjs-webpack-stable-node15600
✅ nextjs-webpack-stable-quickjs15600
✅ nitro-stable-node130026
✅ nitro-stable-quickjs130026
✅ nuxt-stable-node130026
✅ nuxt-stable-quickjs130026
✅ sveltekit-stable-node14907
✅ sveltekit-stable-quickjs14907
✅ tanstack-start-node130026
✅ tanstack-start-quickjs130026
✅ vite-stable-node130026
✅ vite-stable-quickjs130026
✅ 🪟 Windows
AppPassedFailedSkipped
✅ nextjs-turbopack-node15600
✅ nextjs-turbopack-quickjs15600
✅ vercel-multi-region
AppPassedFailedSkipped
✅ nextjs-turbopack2700
📋 View full workflow run
@github-actions
github-actionsBot
commented
Aug 14, 2026•

edited

Loading

Copy link


Copy Markdown

Contributor
📊 Workflow Benchmarks
commit 3e060e3 · Fri, 14 Aug 2026 01:38:46 GMT · run logs
Backend: vercel · app: nextjs-turbopack
MetricScenarioBest (ms)P75 (ms)P90 (ms)P99 (ms)Samples
TTFSstep1400 (+267%) 🔻1462 🔴 (+31%) 🔻1499 🔴 (+32%) 🔻1651 🔴 (+7.8%)30
TTFSstream427 (-58%) 💚1462 🔴 (+38%) 🔻1476 🔴 (+38%) 🔻1516 🔴 (+37%) 🔻30
TTFShook + stream1601 (+25%) 🔻1729 🔴 (+25%) 🔻1770 🔴 (+24%) 🔻7898 🔴 (+388%) 🔻30
Fan-out TTFSPromise.all(100 steps)8828 (-1.0%)10480 (+5.3%)10486 (+4.0%)21261 (+57%) 🔻10
Fan-out TTLSPromise.all(100 steps)17523 (-0.8%)19125 (+1.3%)20601 (+8.4%)29694 (+27%) 🔻10
STSO1020 steps (inline)123 (±0%)155 (-19%) 💚171 (-25%) 💚229 (-61%) 💚1019
WO1020 steps152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚152558 (-22%) 💚1
SLstream latency78 (-1.3%)121 🔴 (+10%)165 🔴 (+28%) 🔻364 🔴 (+6.1%)30
SOstream overhead (text)105 (-5.4%)172 (-4.4%)284 (+38%) 🔻8011 🔴 (+1226%) 🔻30
SOstream overhead (structured)102 (+6.3%)161 (+3.2%)185 (+11%)301 (+65%) 🔻30
📈 STSO distribution vs main (inline / queue-hop histograms)
1020 steps (inline)
Cumulative STSO time: main 194368ms → this run 152318ms (Δ -42050ms, -22%)
 100-150 ms ███████░░░░░░░░░░░░░░░░┃ main 180 this 661 +481
150-200 ms ███████████┃███████████ main 627 this 324 -303
200-250 ms ┃████ main 134 this 28 -106
250-300 ms ┃ main 29 this 4 -25
300-350 ms ┃ main 15 this 2 -13
350-400 ms ┃ main 11 this 0 -11
400-450 ms ┃ main 4 this 0 -4
450-500 ms ┃ main 5 this 0 -5
500-550 ms ┃ main 3 this 0 -3
550-600 ms ┃ main 1 this 0 -1
600-650 ms ┃ main 5 this 0 -5
650-700 ms ┃ main 1 this 0 -1
750-800 ms ┃ main 1 this 0 -1
800-850 ms ┃ main 1 this 0 -1
1100-1150 ms ┃ main 1 this 0 -1
4450-4500 ms ┃ main 1 this 0 -1

ℹ️ Metric definitions & methodology
The collapsed STSO distribution section above buckets every step gap of the sequential-steps run (not a sampled window), split by whether the step ending the gap ran inline — in the same warm process as the step before it, so the gap is pure framework overhead — or after a queue-hop — the first step of a fresh process, which pays queue dispatch, client reinit and event-log replay. Bars overlay the two runs: █ is main, ┃ marks where this run lands, ░ bridges the gap when this run has more samples in a bucket.
Best/P75/P90/P99 deltas compare against the most recent benchmark run on main at the time of this run. 🔻 flags a delta worse than +15%, 💚 one better than −15%.
Metrics — TTFS: time to first step body (in-deployment start() → first step body, deployment clocks) · Fan-out TTFS: fan-out time to first step (in-deployment start() → first of the parallel step bodies to complete) · Fan-out TTLS: fan-out time to last step (in-deployment start() → last of the parallel step bodies to complete, i.e. when the Promise.all resolves) · STSO: step-to-step overhead (gap between consecutive step bodies) · WO: workflow overhead (whole-run time outside step bodies, in-deployment anchored) · SL: stream latency (in-deployment write → read propagation, readAt - writtenAt) · SO: stream overhead (end-to-end write+consume time beyond the modelled generation window)
Scenarios — step: one trivial no-op step, no stream; no hooks, so the run stays in turbo mode (in-process fast path) · stream: one streaming step; no hooks, so the run stays in turbo mode (in-process fast path) · hook + stream: registers a hook before one step, which exits turbo mode (dispatch path) · 1020 steps: 1020 trivial sequential steps; STSO is measured between consecutive steps in the given step ranges, and WO is the whole-run overhead outside step bodies · Promise.all(100 steps): 100 trivial no-op steps started together in a single Promise.all; Fan-out TTFS is the first of them to complete and Fan-out TTLS the last, both from the in-deployment clientStart, so their gap is the spread the runtime adds across the fan-out · stream latency: parallel reader/writer steps on a dedicated stream; SL is the in-deployment write->read propagation (readAt - writtenAt) · stream overhead (text): writer streams 300 variable-length text token deltas paced at 100/s for 3s (a haiku-size LLM's token throughput) while a parallel reader drains the whole stream; SO is the end-to-end write+consume time beyond the 3s generation window (overhead/backpressure) · stream overhead (structured): same workload as stream overhead (text), but each delta is an AI-SDK-style structured object ({ type: 'text-delta', id, text }) instead of a raw string, so the SO gap vs the text scenario is the added serialization cost
🔴 marks a percentile over its target (within target is left unmarked). Targets (p75/p90/p99, ms) — TTFS 200/300/600 · SL 50/60/125 · SO 250/500/1000
All metrics are measured from deployment-side timestamps only. Runs are triggered by an in-deployment route that stamps the anchor (clientStart) right before start(), so the CI runner’s request and its path through api.vercel.com sit outside every measured window. TTFS = in-deployment start() → first step body (turbo uses the in-process fast path, non-turbo the dispatch path), and includes the VQS dispatch hop plus any /flow cold start. Fan-out TTFS/TTLS are the first and last step completions of a single Promise.all over trivial steps, from the same anchor, so the gap between the two rows is the spread the runtime adds across the fan-out. STSO/WO are measured between step bodies on the deployment. SL is measured inside the workflow (parallel reader/writer steps), so it no longer includes the api.vercel.com read path.
Cold starts are kept in the numbers on purpose — they are part of real bursty-workload latency. The workbench deployment cold-starts the /flow invocation for a large fraction of runs, inflating P75+; the Best column shows the fastest (warm-start) sample for comparison.
@github-actions
github-actionsBot
commented
Aug 14, 2026

Copy link


Copy Markdown

Contributor
Sim World
Simulated world deterministic testing for races. Traces
🟠 Mint-ordered log — 3 fail of 41 total
log=mint-ordered · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
❌ in-flight-before-decisionfailed91.0mMISMATCH1
❌ in-flight-before-decision-countedfailed91.0mMISMATCH1
❌ in-flight-after-decisionfailed91.0mMISMATCH1
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-mint.txt
🟢 Append-only log — 0 fail of 41 total
log=append-only · fence=per-spec
scenariooutcomeeventsvirtreplayviolations
✅ smoke-no-stepscompleted30msok0
✅ smoke-one-stepcompleted60msok0
✅ hook-at-step-startedcompleted120msok0
✅ hook-at-step-completedcompleted120msok0
✅ hook-at-hook-createdcompleted120msok0
✅ deadline-hook-winscompleted71.0hok0
✅ deadline-expirescompleted71.0hok0
✅ long-sleepcompleted1130.0dok0
✅ hook-never-arrivesstalled30msskipped0
✅ step-retries-twicecompleted102.0sok0
✅ parallel-stepscompleted90msok0
✅ hook-on-execution-statecompleted120msok0
✅ peek-hook-before-branchcompleted120msok0
✅ peek-hook-after-branchcompleted120msok0
✅ peek-hook-at-registrationcompleted120msok0
✅ race-hook-before-probecompleted120msok0
✅ race-hook-after-probecompleted120msok0
✅ race-duplicate-deliverycompleted130msok0
✅ attr-hook-before-stepcompleted110msok0
✅ attr-hook-after-stepcompleted110msok0
✅ attr-from-step-bodycompleted130msok0
✅ fork-hook-after-timeoutcompleted141.0mok0
✅ fork-hook-before-timeoutcompleted141.0mok0
✅ count-hook-after-timeoutcompleted171.0mok0
✅ count-hook-before-timeoutcompleted201.0mok0
✅ stale-read-step-count-forkcompleted201.0mok0
✅ stale-read-equal-step-countscompleted141.0mok0
✅ step-vs-step-forkcompleted120msok0
✅ step-vs-step-fork-fencedcompleted120msok0
✅ fence-catches-benign-directioncompleted125msok0
✅ in-flight-before-decisioncompleted171.0mok0
✅ in-flight-before-decision-countedcompleted171.0mok0
✅ in-flight-after-decisioncompleted192.0mok0
✅ stale-read-step-count-fork-fencedcompleted201.0mok0
✅ fork-hook-winscompleted131.0mok0
✅ fork-timeout-winscompleted131.0mok0
✅ unclaimed-payload-under-forkcompleted171.0mok0
✅ claimed-payload-under-forkcompleted171.0mok0
✅ writers-independent-step-bodiescompleted120msok0
✅ writers-scripted-tempocompleted120msok0
✅ cancel-mid-stepcancelled70msskipped0
Full trace: world-sim-append-only.txt
@VaguelySerious
VaguelySerious
commented
Aug 14, 2026

Copy link


Copy Markdown

MemberAuthor
(AI) Local postgres soak addendum: 120 step-storm attempts with the DIAG probes reproduced the same class in 29/120 runs. Each affected run diverges repeatedly at one fixed low slot (58–84, the round-0/1 boundary) while the log keeps growing (e.g. evnt_…059 at eventCounts 114, 145, 249), i.e. a committed binding conflict, not a transient race. The step-entity table shows the signature directly: mint order …F3<F4<F5<F6<F7 (all recoverStep) committed at slots 64, 66, 62, 60, 59 — last-minted first — and the surrounding ordinals are a scrambled interleaving of recover/finalize/release groups from disagreeing trajectories.
Two operational notes from the soak:
  • These runs surface as stuck (divergence-thrash), not CORRUPTED_EVENT_LOG — the storm's extra wakes keep starting fresh deliveries whose divergence count restarts, so the 3-strike exhaustion rarely triggers locally. Stuck-rate is therefore the number to watch locally, not the corrupted-rate.
  • The array-order probe stayed silent across all 120 runs (16k suspension snapshots): the events array is slot-ordered everywhere; the instability is in draw scheduling, not log assembly. Also, the errorMessage field of the DIAG divergence log is dropped by renderStructuredFields (log-format.ts wellKnown handling) — same gap that hides divergence reasons in production logs; worth fixing alongside.
@VaguelySeriousVaguelySerious
mentioned this pull request
Aug 14, 2026
 Merged

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

Reviewers


No reviews


Assignees


No one assigned


Labels


None yet


Projects


None yet


Milestone


No milestone


Development

Successfully merging this pull request may close these issues.

1 participant

@VaguelySerious