Skip to content

[e2e] Add a cycle-hook scenario to the event-log race repro - #4110

Open
VaguelySerious wants to merge 1 commit into
mainfrom
peter/repro-open-wait-hook-wake
Open

[e2e] Add a cycle-hook scenario to the event-log race repro#4110
VaguelySerious wants to merge 1 commit into
mainfrom
peter/repro-open-wait-hook-wake

Conversation

@VaguelySerious

Copy link
Copy Markdown
Member

Why

wake-loop creates its hooks once, at the top, before any wait exists. It commits one hook_created and never another, which leaves a state it can never reach: a hook write landing while a wait is already open.

Two production runs died in exactly that state. githubUserMonitor on core 5.0.0-beta.48 mints a fresh hook inside every cycle, races it against a heartbeat sleep, and disposes it only when the sleep wins. So after any cycle the hook won, the next cycle's hook_created commits with that cycle's abandoned sleep still counting down — and an open wait is precisely what decides whether the runtime settles a hook's awaiter from the suspension's own writes or re-reads the log first.

Neither run exhausted the replay-divergence budget and neither hit a missing payload, so the corruption came from the third producer — the density check — rather than from a divergence. That is a different failure mode from the one wake-loop was built for, on the same family of workload.

What

cycle-hook: one sequential loop, a fresh hook per cycle, disposed only on a sleep win.

The 55-cycle production original is reproduced event for event:

Event Production run
hook_created 56
hook_disposed 54
wait_created 55
wait_completed 54
hook_received 18

with one wait still open at the moment it failed. Its sibling died the same way 26 minutes earlier at 29 events.

The driver walks the cycle index rather than holding one hook, resuming each cycle's own :c<n> token, and aims a configurable share (CYCLE_HOOK_WIN_RATIO, default 0.7) at the heartbeat deadline so a hook_received commits next to a wait_completed. The rest are deliberately left to the sleep, because a hook win is what sets up the next cycle's open-wait create.

pressure.cycleHook.createsUnderOpenWait reports how often the run actually reached that state, so a clean result can be distinguished from a run that never got there — the same reason wake-loop reports bursts/idles.

Knobs are EVENT_LOG_RACE_REPRO_CYCLE_HOOK_*, defaults alongside the other scenarios in the test file.

Validation

Against world-local, three runs, reduced scale:

cycle-hook attempt=1 outcome=completed cycleHook={cycles: 14, hookWins: 4, heartbeatWins: 10, createsUnderOpenWait: 3}
cycle-hook attempt=2 outcome=completed cycleHook={cycles: 10, hookWins: 4, heartbeatWins:  6, createsUnderOpenWait: 3}
cycle-hook attempt=3 outcome=completed cycleHook={cycles:  7, hookWins: 4, heartbeatWins:  3, createsUnderOpenWait: 3}

Every run reached the open-wait create, across a mix of both branches. That says the shape drives the intended interleaving, not that it reproduces the corruption. The production failures were on world-vercel, and three world-local runs resolve nothing about a rate — per the harness's own note, a clean run means "the storms did not trip it".

Empty changeset: nothing here is published (packages/core/e2e/, workbench/).

`wake-loop` creates its hooks once, at the top, before any wait exists, so it
commits one `hook_created` and never another. That leaves a state it can never
reach: a hook write landing while a wait is already open.

Two production runs died there. `githubUserMonitor` on core 5.0.0-beta.48 mints
a fresh hook inside every cycle, races it against a heartbeat sleep, and
disposes it only when the sleep wins — so after any cycle the hook won, the next
cycle's `hook_created` commits with that cycle's abandoned sleep still counting
down. An open wait is exactly what decides whether the runtime settles a hook's
awaiter from the suspension's own writes or re-reads the log first.

`cycle-hook` is that loop. Its 55-cycle production original is reproduced event
for event in the ledger the scenario asserts on: 56 `hook_created`, 54
`hook_disposed`, 55 `wait_created`, 54 `wait_completed`, 18 `hook_received`, and
one wait still open at the end.

The driver walks the cycle index rather than holding one hook, resuming each
cycle's own token, and aims a configurable share of those resumes at the
heartbeat deadline so a `hook_received` commits next to a `wait_completed`. The
rest are left to the sleep, since a hook win is what sets up the next cycle's
open-wait create; `pressure.cycleHook.createsUnderOpenWait` reports how often the
run actually reached that state, so a clean result can be told apart from a run
that never got there.

Validated against world-local: three runs, all completed, each reporting
`createsUnderOpenWait: 3` across a mix of both branches. That says the shape
drives the intended interleaving, not that it reproduces the corruption — the
production failures were on world-vercel, and world-local at three runs
resolves nothing about a rate.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@VaguelySerious
VaguelySerious requested a review from a team as a code owner September 11, 2026 17:58
@changeset-bot

changeset-bot Bot commented Sep 11, 2026

Copy link
Copy Markdown

🦋 Changeset detected

Latest commit: 746de8b

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

vercel Bot commented Sep 11, 2026

Copy link
Copy Markdown
Contributor

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

Project Deployment Actions Updated
example-nextjs-workflow-turbopack Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
example-nextjs-workflow-webpack Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
example-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-astro-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-express-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-fastify-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-hono-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-nestjs-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-nitro-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-nuxt-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-python-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-sveltekit-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-tanstack-start-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workbench-vite-workflow Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workflow-docs Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workflow-swc-playground Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workflow-tarballs Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC
workflow-web Ready Ready Preview, v0 Sep 11, 2026 6:01pm UTC

@github-actions

github-actions Bot commented Sep 11, 2026

Copy link
Copy Markdown
Contributor

🧪 E2E Test Results

Some tests failed

❌ Failed E2E Tests

vercel-multi-region (2 failed)

nextjs-turbopack (2 failed):

  • multi-region (world-vercel) explicit region: start({ region }) in the test process every provisioned region executes and completes a tagged run
  • multi-region (world-vercel) implicit region: region-pinned routes without a region option /api/e2e-region-implicit/hnd1 mints a run tagged with its VERCEL_REGION

⚠️ Flaky E2E Tests (passed on retry)

These tests failed at least once and passed on a retry. A recurring entry here is a real race worth investigating.

10 flaky tests
  • cancelRun via CLI - cancelling a running workflow (example)
  • cancelRun via CLI - cancelling a running workflow (express)
  • cancelRun via CLI - cancelling a running workflow (fastify)
  • cancelRun via CLI - cancelling a running workflow (nextjs-turbopack)
  • cancelRun via CLI - cancelling a running workflow (nextjs-webpack)
  • cancelRun via CLI - cancelling a running workflow (nuxt)
  • cancelRun via CLI - cancelling a running workflow (tanstack-start)
  • cancelRun via CLI - cancelling a running workflow (vite)
  • fibonacciWorkflow - recursive workflow composition via start() (nextjs-webpack)
  • retainedInterleavingWorkflow (sveltekit)

🛠 Infra Events (absorbed by the harness)

Platform anomalies the e2e harness detected and worked around (e.g. a run the queue never picked up, replaced by a fresh run). Clustered timestamps indicate a backend blip; a steady drip indicates a platform issue worth escalating.

  • cold-start-warmup · suite warmup (tanstack-start) · at 18:03:47Z · abandoned wrun_01M28T6YHDJAYQDZVSB7BNMB0D
  • run-pickup-stall · basic step error preserves message and stack trace (nextjs-webpack) · at 18:10:58Z · abandoned wrun_01M28TMAZ6H8XCXRV1PWJW8GV8
  • run-pickup-stall · hookCleanupTestWorkflow - hook token reuse after workflow completion (nextjs-webpack) · at 18:11:07Z · abandoned wrun_01M28TMK9N0N5SKPHZ3344SP47

E2E Test Summary

Summary
Passed Failed Skipped Total
✅ ▲ Vercel Production 3662 0 685 4347
✅ 💻 Local Development 3922 0 586 4508
✅ 📦 Local Production 3922 0 586 4508
✅ 🐘 Local Postgres 3922 0 586 4508
✅ 🪟 Windows 320 0 2 322
✅ 🌐 Cross-language Conformance 68 0 74 142
✅ vercel-http-transport 823 0 143 966
❌ vercel-multi-region 25 2 0 27
✅ vercel-ws-transport 557 0 87 644
Total 17221 2 2749 19972
Details by Category

✅ ▲ Vercel Production

App Passed Failed Skipped
✅ astro-node 133 0 28
✅ astro-quickjs 133 0 28
✅ example-node 133 0 28
✅ example-quickjs 133 0 28
✅ express-node 133 0 28
✅ express-quickjs 133 0 28
✅ fastify-node 133 0 28
✅ fastify-quickjs 133 0 28
✅ hono-node 133 0 28
✅ hono-quickjs 133 0 28
✅ nest-node 133 0 28
✅ nest-quickjs 133 0 28
✅ nextjs-turbopack-node 158 0 3
✅ nextjs-turbopack-quickjs 158 0 3
✅ nextjs-webpack-node 158 0 3
✅ nextjs-webpack-quickjs 158 0 3
✅ nitro-node 133 0 28
✅ nitro-quickjs 133 0 28
✅ nuxt-node 133 0 28
✅ nuxt-quickjs 133 0 28
✅ python-node 66 0 95
✅ sveltekit-node 152 0 9
✅ sveltekit-quickjs 152 0 9
✅ tanstack-start-node 133 0 28
✅ tanstack-start-quickjs 133 0 28
✅ vite-node 133 0 28
✅ vite-quickjs 133 0 28

✅ 💻 Local Development

App Passed Failed Skipped
✅ astro-stable-node 134 0 27
✅ astro-stable-quickjs 134 0 27
✅ express-stable-node 134 0 27
✅ express-stable-quickjs 134 0 27
✅ fastify-stable-node 134 0 27
✅ fastify-stable-quickjs 134 0 27
✅ hono-stable-node 134 0 27
✅ hono-stable-quickjs 134 0 27
✅ nest-stable-node 134 0 27
✅ nest-stable-quickjs 134 0 27
✅ nextjs-turbopack-canary-node 141 0 20
✅ nextjs-turbopack-canary-quickjs 141 0 20
✅ nextjs-turbopack-stable-node 160 0 1
✅ nextjs-turbopack-stable-quickjs 160 0 1
✅ nextjs-webpack-canary-node 141 0 20
✅ nextjs-webpack-canary-quickjs 141 0 20
✅ nextjs-webpack-stable-node 160 0 1
✅ nextjs-webpack-stable-quickjs 160 0 1
✅ nitro-stable-node 134 0 27
✅ nitro-stable-quickjs 134 0 27
✅ nuxt-stable-node 134 0 27
✅ nuxt-stable-quickjs 134 0 27
✅ sveltekit-stable-node 153 0 8
✅ sveltekit-stable-quickjs 153 0 8
✅ tanstack-start-node 134 0 27
✅ tanstack-start-quickjs 134 0 27
✅ vite-stable-node 134 0 27
✅ vite-stable-quickjs 134 0 27

✅ 📦 Local Production

App Passed Failed Skipped
✅ astro-stable-node 134 0 27
✅ astro-stable-quickjs 134 0 27
✅ express-stable-node 134 0 27
✅ express-stable-quickjs 134 0 27
✅ fastify-stable-node 134 0 27
✅ fastify-stable-quickjs 134 0 27
✅ hono-stable-node 134 0 27
✅ hono-stable-quickjs 134 0 27
✅ nest-stable-node 134 0 27
✅ nest-stable-quickjs 134 0 27
✅ nextjs-turbopack-canary-node 141 0 20
✅ nextjs-turbopack-canary-quickjs 141 0 20
✅ nextjs-turbopack-stable-node 160 0 1
✅ nextjs-turbopack-stable-quickjs 160 0 1
✅ nextjs-webpack-canary-node 141 0 20
✅ nextjs-webpack-canary-quickjs 141 0 20
✅ nextjs-webpack-stable-node 160 0 1
✅ nextjs-webpack-stable-quickjs 160 0 1
✅ nitro-stable-node 134 0 27
✅ nitro-stable-quickjs 134 0 27
✅ nuxt-stable-node 134 0 27
✅ nuxt-stable-quickjs 134 0 27
✅ sveltekit-stable-node 153 0 8
✅ sveltekit-stable-quickjs 153 0 8
✅ tanstack-start-node 134 0 27
✅ tanstack-start-quickjs 134 0 27
✅ vite-stable-node 134 0 27
✅ vite-stable-quickjs 134 0 27

✅ 🐘 Local Postgres

App Passed Failed Skipped
✅ astro-stable-node 134 0 27
✅ astro-stable-quickjs 134 0 27
✅ express-stable-node 134 0 27
✅ express-stable-quickjs 134 0 27
✅ fastify-stable-node 134 0 27
✅ fastify-stable-quickjs 134 0 27
✅ hono-stable-node 134 0 27
✅ hono-stable-quickjs 134 0 27
✅ nest-stable-node 134 0 27
✅ nest-stable-quickjs 134 0 27
✅ nextjs-turbopack-canary-node 141 0 20
✅ nextjs-turbopack-canary-quickjs 141 0 20
✅ nextjs-turbopack-stable-node 160 0 1
✅ nextjs-turbopack-stable-quickjs 160 0 1
✅ nextjs-webpack-canary-node 141 0 20
✅ nextjs-webpack-canary-quickjs 141 0 20
✅ nextjs-webpack-stable-node 160 0 1
✅ nextjs-webpack-stable-quickjs 160 0 1
✅ nitro-stable-node 134 0 27
✅ nitro-stable-quickjs 134 0 27
✅ nuxt-stable-node 134 0 27
✅ nuxt-stable-quickjs 134 0 27
✅ sveltekit-stable-node 153 0 8
✅ sveltekit-stable-quickjs 153 0 8
✅ tanstack-start-node 134 0 27
✅ tanstack-start-quickjs 134 0 27
✅ vite-stable-node 134 0 27
✅ vite-stable-quickjs 134 0 27

✅ 🪟 Windows

App Passed Failed Skipped
✅ nextjs-turbopack-node 160 0 1
✅ nextjs-turbopack-quickjs 160 0 1

✅ 🌐 Cross-language Conformance

App Passed Failed Skipped
✅ python 68 0 74

✅ vercel-http-transport

App Passed Failed Skipped
✅ example 133 0 28
✅ express 133 0 28
✅ hono 133 0 28
✅ nextjs-turbopack 158 0 3
✅ nitro 133 0 28
✅ vite 133 0 28

❌ vercel-multi-region

App Passed Failed Skipped
❌ nextjs-turbopack 25 2 0

✅ vercel-ws-transport

App Passed Failed Skipped
✅ example 133 0 28
✅ express 133 0 28
✅ nextjs-turbopack 158 0 3
✅ vite 133 0 28

📋 View full workflow run

@github-actions

github-actions Bot commented Sep 11, 2026

Copy link
Copy Markdown
Contributor

📊 Workflow Benchmarks

commit 746de8b · Fri, 11 Sep 2026 18:25:09 GMT · run logs

Backend: vercel · app: nextjs-turbopack

Metric Scenario Best (ms) P75 (ms) P90 (ms) P99 (ms) Samples
TTFS step 1592 (+704%) 🔻 1752 🔴 (+36%) 🔻 1836 🔴 (+40%) 🔻 2126 🔴 (+57%) 🔻 30
TTFS stream 170 (-85%) 💚 1684 🔴 (+30%) 🔻 1709 🔴 (+27%) 🔻 2079 🔴 (+35%) 🔻 30
TTFS hook + stream 517 (-64%) 💚 2098 🔴 (+24%) 🔻 2182 🔴 (+27%) 🔻 2235 🔴 (+22%) 🔻 30
Fan-out TTFS Promise.all(100 steps) 582 (-12%) 1221 (+47%) 🔻 2364 (+179%) 🔻 2644 (+3.7%) 10
Fan-out TTLS Promise.all(100 steps) 2182 (+22%) 🔻 5700 (+21%) 🔻 5875 (-25%) 💚 12114 (+27%) 🔻 10
STSO 1020 steps (inline) 134 (+49%) 🔻 169 (+19%) 🔻 187 (+17%) 🔻 259 (+2.4%) 1019
WO 1020 steps 167853 (+16%) 🔻 167853 (+16%) 🔻 167853 (+16%) 🔻 167853 (+16%) 🔻 1
CRTT first chunk (pooled) 63 (+31%) 🔻 110 (+29%) 🔻 232 (+158%) 🔻 3678 (+2336%) 🔻 28

Streams

Scenario CRTT 1st p75 p90 p99 CDV max iters
paced control (100/s, 60B) 77.5 (-4%) 318 (+137%) 570 (+156%) 3652 (+753%) 198 (+38%) 10
size sweep (100/s, 160B-12KB) 95.5 (+18%) 190 (+19%) 308 (-24%) 1296 (+94%) 185 (+35%) 10
replay gateway-gpt-5.4-nano-2000t (1x) 78 (+8%) 156 (+31%) 212 (+28%) 590 (+80%) 299 (+29%) 3
replay eve-gpt-5.6-sol-2000t (1x) 131 (+54%) 140 (+23%) 216 (+55%) 652 (+128%) 455 (+34%) 2
replay eve-gpt-5.6-sol-2000t (2x) 95 (+12%) 226 (+25%) 292 (+15%) 597 (+26%) 312 (+44%) 3
📈 STSO distribution vs main (inline / queue-hop histograms)

1020 steps (inline)

Cumulative STSO time: main 144355ms → this run 167695ms (Δ +23340ms, +16%)

 50-100 ms  ┃                         main   2  this   0    -2
100-150 ms  ███┃████████████████████  main 841  this 137  -704
150-200 ms  ████░░░░░░░░░░░░░░░░░░░┃  main 153  this 831  +678
200-250 ms  ┃                         main  12  this  39   +27
250-300 ms  ┃                         main   7  this   7    +0
300-350 ms  ┃                         main   2  this   3    +1
350-400 ms  ┃                         main   0  this   1    +1
400-450 ms  ┃                         main   1  this   0    -1
450-500 ms  ┃                         main   0  this   1    +1
900-950 ms  ┃                         main   1  this   0    -1
📈 CRTT drill-down vs main (RTT distributions & profiles)
variant  RTT 1ms→5s+              avg         p50          p90           p99     n
control  ······▃█▃▁▁▁·  381.9 (+234%)  134 (+30%)  570 (+156%)  3652 (+753%)  3000
sweep    ······▂█▂▁▁··   183.1 (+45%)  139 (+35%)   308 (-24%)   1296 (+94%)  3000
gw 1x    ·····▁▆█▂▁···   125.5 (+18%)  109 (+11%)   212 (+28%)    590 (+80%)  5295
eve 1x   ·····▁██▂▁···   122.4 (+22%)    94 (±0%)   216 (+55%)   652 (+128%)  5186
eve 2x   ·····▁▂█▄▁···   172.2 (+22%)  144 (+15%)   292 (+15%)    597 (+26%)  7779

RTT over stream progress (avg per tenth of stream, bars scaled min→max):

control  █▇▇█▆▆▄▃▂▁  239–476ms
sweep    ▃▂▁▁▂█▆▄▅▄  138–261ms
gw 1x    █▄▇▄▂▂▁▂█▁  104–158ms
eve 1x   ▅▆█▅▁▂▃▃▆▃  99–149ms
eve 2x   ▃▁▇▃▁▅▅▆█▃  134–216ms

RTT by chunk size (avg per log size bin, ~160B → ~12KB serialized, bars scaled min→max):

sweep  ▆██▆▃▁▄  179–186ms

Delivery jitter over stream progress (avg positive CDV per tenth of stream, bars scaled min→max):

control  ▁▁█▄▅▆▃▃▃▂  42–60ms
sweep    ▂▂▁▂▂█▁▂▃▂  51–101ms
gw 1x    █▄█▁▃▂▂▄▅▁  31–41ms
eve 1x   ▄█▆▂▂▃▃▄▁▅  18–34ms
eve 2x   █▃▅▃▂▇▃▁▅▇  21–30ms
ℹ️ Metric definitions & methodology

Streams: first-chunk RTT (the stream-open path, before any buffering/backpressure), CRTT percentiles, and worst delivery stall (CDV max). Cells are medians across iterations; per-run values in the artifacts. No 🔴/🟢 marks until targets attach.

The collapsed STSO distribution section above buckets every step gap, split inline (same warm process — pure framework overhead) vs queue-hop (fresh process — dispatch, reinit, replay). = main, = this run, = fill.

The collapsed CRTT drill-down: per-variant RTT histograms (fixed log bins, · = empty) and mean RTT/positive-CDV profile lines over stream progress and chunk size. Histograms, avgs, and profiles merge exactly across runs; p50–p99 are percentile-of-percentiles. Per-index rows live in the artifacts.

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) · 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) · CRTT: chunk round-trip time (per-chunk write → read latency, one clock domain: deployment → stream backend → same deployment) · CDV: chunk delay variation / delivery jitter (inter-arrival gap minus inter-write gap per seq-adjacent pair; skew-free; the row is each run's MAX positive value, so one stall moves it)

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 · paced control (100/s, 60B): the control: 300 tiny (~60B) deltas metronome-paced at 100/s — zero workload structure, so it reads the transport floor and flush cadence, and disambiguates transport-wide vs workload-specific when a replay row moves · size sweep (100/s, 160B-12KB): same pacing as the control with deltas padded in rotation across seven log-spaced sizes (~160B–12KB) — rotation decouples size from stream position, so it isolates whether chunk size causes latency · replay gateway-gpt-5.4-nano-2000t (1x): raw provider SSE cadence captured at the AI gateway boundary (gpt-5.4-nano, the most popular gateway model; per-token deltas p50 208B = the modal production chunk size), replayed exactly as measured — the typical customer's workload; its CDV is the typical customer's real delivery jitter · replay eve-gpt-5.6-sol-2000t (1x): a captured eve turn (gpt-5.6-sol, the most-used demanding eve model; ~2000 output tokens = production p50 turn length) replayed exactly as measured — eve's envelope protocol re-ships the cumulative message so sizes ramp 142B→13KB; the demanding outlier tenant's reality · replay eve-gpt-5.6-sol-2000t (2x): the same eve capture at 2x — the headroom/stress row; real fast-tier models emit the same chunk sizes at proportionally higher rate, so time compression is a faithful speed model · first chunk (pooled): every run's seq-0 RTT pooled across all stream scenarios — the first chunk precedes any workload differentiation, so pooling samples one shared stream-open path with exact percentiles

Replay cadences (semantic sha256) — eve-gpt-5.6-sol-2000t eaf22f5946e7c61f3c65c7006d550df180cfabd4e706254a09f22aec0cfb420d · gateway-gpt-5.4-nano-2000t 6f24ac518b6b83ff1d0e85a5fe78230db192716d66a7fc6b2fe022752001d041

🔴 marks a percentile over its target (within target is left unmarked). Targets (p75/p90/p99, ms) — TTFS 200/300/600

All timestamps are deployment-side; runs are triggered in-deployment, so the CI runner and api.vercel.com sit outside every measured window. TTFS = start() → first step body (includes dispatch + any cold start); Fan-out TTFS/TTLS = first/last step completion of one Promise.all from the same anchor (the gap is the runtime’s fan-out spread); STSO/WO between step bodies; CRTT inside the workflow (excludes the api.vercel.com read path).

Cold starts stay in the numbers (real bursty-workload latency, inflates P75+); Best is the warm floor.

@vercel vercel Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Additional Suggestion:

The "calibration control" doc comment describing a single-hook/single-sleep scenario was orphaned above runCycleHookAttempt, mislabeling it, while runHookSleepAttempt (the actual control) lost its documentation.

Fix on Vercel

@github-actions

Copy link
Copy Markdown
Contributor

Sim World

Simulated world deterministic testing for races. Traces

🟠 world-sim scenario book — 1 fail of 41 total

fence=per-spec

scenario outcome events virt replay violations
smoke-no-steps completed 3 0ms ok 0
smoke-one-step completed 6 0ms ok 0
hook-at-step-started completed 12 0ms ok 0
hook-at-step-completed completed 12 0ms ok 0
hook-at-hook-created completed 12 0ms ok 0
deadline-hook-wins completed 7 1.0h ok 0
deadline-expires completed 7 1.0h ok 0
long-sleep completed 11 30.0d ok 0
hook-never-arrives stalled 3 0ms skipped 0
step-retries-twice completed 10 2.0s ok 0
parallel-steps completed 9 0ms ok 0
hook-on-execution-state completed 12 0ms ok 0
peek-hook-before-branch completed 12 0ms ok 0
peek-hook-after-branch completed 12 0ms ok 0
peek-hook-at-registration completed 12 0ms ok 0
race-hook-before-probe completed 12 0ms ok 0
race-hook-after-probe completed 12 0ms ok 0
race-duplicate-delivery completed 13 0ms ok 0
attr-hook-before-step completed 11 0ms ok 0
attr-hook-after-step completed 11 0ms ok 0
attr-from-step-body completed 13 0ms ok 0
fork-hook-after-timeout completed 14 1.0m ok 0
fork-hook-before-timeout completed 14 1.0m ok 0
count-hook-after-timeout completed 17 1.0m ok 0
count-hook-before-timeout completed 20 1.0m ok 0
stale-read-step-count-fork completed 20 1.0m ok 0
stale-read-equal-step-counts completed 14 1.0m ok 0
step-vs-step-fork completed 12 0ms ok 0
step-vs-step-fork-fenced completed 12 0ms ok 0
fence-catches-benign-direction completed 12 5ms ok 0
in-flight-before-decision completed 17 1.0m ok 0
in-flight-before-decision-counted completed 17 1.0m ok 0
in-flight-after-decision completed 19 2.0m ok 0
stale-read-step-count-fork-fenced completed 20 1.0m ok 0
fork-hook-wins completed 13 1.0m ok 0
fork-timeout-wins completed 13 1.0m ok 0
unclaimed-payload-under-fork completed 17 1.0m ok 0
claimed-payload-under-fork completed 17 1.0m ok 0
writers-independent-step-bodies completed 12 0ms ok 0
writers-scripted-tempo completed 12 0ms ok 0
cancel-mid-step cancelled 7 0ms skipped 0

Full trace: world-sim.txt

@github-actions

Copy link
Copy Markdown
Contributor
Framework Flow route Step reg. Framework output
hono 236.0 KiB (±0) 42.3 KiB (±0) 1.80 MiB (±0)
nextjs-turbopack 242.6 KiB (+324 B) 439 B (±0) 836.8 KiB (+356 B)
About these numbers

Sizes are gzip; parentheses show the change against main.
Flow route and Step reg. gate this job, on raw bytes rather than the gzip shown, at max(2%, 50.0 KiB). Framework output is informational.

746de8b · run

@VaguelySerious VaguelySerious added the event-log-race-repro Run the event log race reproduction job label Sep 11, 2026
@github-actions

Copy link
Copy Markdown
Contributor

Event Log Race Repro

  • vercel clean, 30 runs — partial: 30 of 32 planned runs, launch budget spent
  • local clean, 32 runs
  • postgres clean, 32 runs

Run History

Run Lane Total Complete Corrupt Stuck Other
09-11 18:47 vercel 30 30 0 0 0
local 32 32 0 0 0
postgres 32 32 0 0 0
Config

vercel: 30 runs / step-storm 6, hook-storm 6, blocked-branch 6, wake-loop 6, hook-sleep 2 / c8 / 6x8 / watchdog 2500ms / step 2200±250ms / stagger 400ms / heartbeat 4000ms / burst 4000+1200ms / poke 750ms / poke budget 64 then /8 / timeout 240000ms

local, postgres: 32 runs / step-storm 6, hook-storm 6, blocked-branch 6, wake-loop 6, hook-sleep 2 / c8 / 6x8 / watchdog 2500ms / step 2200±250ms / stagger 400ms / heartbeat 4000ms / burst 4000+1200ms / poke 750ms / poke budget 64 then /8 / timeout 480000ms

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

Labels

event-log-race-repro Run the event log race reproduction job

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant