Fix three crash-class defects behind this week's flaky CI and tighten the e2e harness - #4119
Fix three crash-class defects behind this week's flaky CI and tighten the e2e harness#4119pranaygp wants to merge 3 commits into
Conversation
🦋 Changeset detectedLatest commit: f707253 The changes in this PR will be included in the next version bump. This PR includes changesets to release 18 packages
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 |
🧪 E2E Test Results✅ All tests passed 🛠 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.
E2E Test SummarySummary
Details by Category✅ ▲ Vercel Production
✅ 💻 Local Development
✅ 📦 Local Production
✅ 🐘 Local Postgres
✅ 🪟 Windows
✅ 🌐 Cross-language Conformance
✅ vercel-http-transport
✅ vercel-multi-region
✅ vercel-ws-transport
|
📊 Workflow Benchmarkscommit Backend:
Streams
📈 STSO distribution vs main (inline / queue-hop histograms)1020 steps (inline) Cumulative STSO time: main 144758ms → this run 152813ms (Δ +8055ms, +6%) 📈 CRTT drill-down vs main (RTT distributions & profiles)RTT over stream progress (avg per tenth of stream, bars scaled min→max): RTT by chunk size (avg per log size bin, ~160B → ~12KB serialized, bars scaled min→max): Delivery jitter over stream progress (avg positive CDV per tenth of stream, bars scaled min→max): 📜 Previous results (2)f6dbd43Fri, 11 Sep 2026 23:31:45 GMT · run logs
Streams
3d9ca61Fri, 11 Sep 2026 20:11:16 GMT · run logs
Streams
ℹ️ Metric definitions & methodologyStreams: 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). The collapsed CRTT drill-down: per-variant RTT histograms (fixed log bins, Best/P75/P90/P99 deltas compare against the most recent benchmark run on 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 🔴 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 = Cold starts stay in the numbers (real bursty-workload latency, inflates P75+); Best is the warm floor. |
Sim WorldSimulated world deterministic testing for races. Traces 🟠 world-sim scenario book — 1 fail of 41 total
Full trace: |
About these numbersSizes are gzip; parentheses show the change against
|
|
CI status on the first run (
Generated by Claude Code |
|
Second run (
The Sim World row Generated by Claude Code |
|
3d9ca61 is green. Tests run 34640542518 passed end to end, including Two corrections to my earlier comments on 9f2b02f:
The one non-green check is DCO ( One thing the run also shows: with the backend now kept in the flaky list, this run's four retried-to-green entries were Generated by Claude Code |
3d9ca61 to
f6dbd43
Compare
… the e2e harness core: a run that fails before its body starts (an unregistered workflow name, a bundle that fails to evaluate, input that fails to hydrate) left the events consumer's deferred divergence check armed. When it fired it rejected an interruption promise nothing had awaited yet, which surfaced as an unhandledRejection and took the host process down about 100ms after the flow route had already reported the run as failed. Mark the promise handled up front and add the regression test. world-local: hold the Hook token claim lock through the hook_created publish. The claim records the writer's candidate slot; a second writer that read it before the first publish committed adopted that slot, published there first, and the claimer's collision-and-bump then published a second hook_created for the same hook. This is the Windows unit failure seen on three main pushes this week. world-postgres: the dedicated LISTEN clients and the World's own pool had no error handler, so a connection the server closed was an uncaught exception. Subscriptions now resubscribe after a backoff and the pool discards the dead client. e2e harness: a 40s CLI budget and WORKFLOW_VERCEL_PROJECT_NAME on the Vercel lanes, and a 90s budget for the two-round-trip hook cleanup test. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_012Rw5CkA3EvADg9hpVjS6RP
…ut wall-clock bounds `Unit Tests (windows-latest)` tripped two elapsed-time assertions on this PR's own runs: the straggler test measured 102ms against a 100ms deferred window, and the return-value wait measured 828ms against an 800ms bound. Both bounds were proxies for a property the runner's load has no business deciding. - events-consumer: `subscribe()` queues one synchronous `consume` pass on `process.nextTick`, and that pass steps over a straggler in place, while deferring one parks the walk until a timer fires. So the walk standing at the end of the log on the very next tick, with every straggler reported through `onDuplicateEvent` and none through `onUnconsumedEvent`, is the property itself rather than a clock reading of it. - run-return-value-real-world: raise the poll interval to 3s for the file and bound the wait path at half of it. A stall of over a second no longer pushes the wait path past its bound, and the interval path still cannot report before ~3s, so the kill switch stays observable. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_012Rw5CkA3EvADg9hpVjS6RP
`Unit Tests (windows-latest)` on this PR failed `fs.test.ts > paginatedFileSystemQuery > cursor optimization` with `Hook timed out in 10000ms` at a `beforeEach` that writes ten small JSON files. Nothing in that hook is slow: main's green run had the whole 78-test file at 6.7s. The Windows runner runs world-local's filesystem-heavy files in parallel against one slow temp volume, and in the same job a sibling file was pushing a thousand events through that disk (the `run_started` preload test alone took 101s here and 133s on main's green run). The root config already gives test bodies 60s for exactly this reason and left hooks at vitest's 10s default; the e2e utils work around the gap by passing 30s explicitly. Set `hookTimeout` to match `testTimeout`, so a fixture doing the same writes as the test it sets up has the same budget. No test is skipped or weakened by this. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_012Rw5CkA3EvADg9hpVjS6RP
2 participants
Summary & Motivation
A triage of the last two weeks of
tests.ymlruns onmainand the e2e results comments on 18 PRs (185 retried-to-green entries over 79 tests; 22 of 30 main pushes red since Sept 8) found that most of the "flaky" signal was the harness and the deployment pipeline, but three recurring failures were real defects, two of which crash a host process. This PR fixes those three and the harness defects that #4107, #4115 and #4120 do not already cover.Real bugs
core: a run that fails before its body starts crashed the host process ~100ms later.
runWorkflowcreates the session in staterunningwithinitialInterruptionand registers the structural consumer, which starts walking the event log immediately. The workflow function is only resolved afterwards, soWorkflowNotRegisteredError, a bundle that fails to evaluate, or input that fails to hydrate all throw beforewaitForExecutionattaches the only handler toinitialInterruption.promise. If the log holds an ordered event nobody claims (any replay), the consumer's deferred check firesonWorkflowError, whoserunningbranch rejects that un-awaited promise. That is anunhandledRejection, and it is what took down the world-postgres conformance server in Unit Tests (ubuntu) on Sept 10. The same path covers a workflow renamed or removed while runs are in flight on a local or Postgres World. Fix: mark the promise handled up front;Promise.raceinwaitForExecutionstill observes the rejection. The new test fails without the one-line fix and passes with it.world-local: two processes could publish two
hook_createdevents for one hook.storage.test.ts › converges same-hook creation across separate storage instances to one eventfailed on three main pushes on Windows (Sept 10, Sept 9, Sept 8) with 26 events for 25 creations. The claimer records its candidate slot in the token claim and stays unpinned; a second writer that reads the claim before the first publish commits adopts that slot, publishes there first, and the claimer's collision-and-bump publishes a second event. The token claim lock is now held through the create (released increateImpl'sfinally), so an adopter can only read a claim whose event is already in the log, or one whose writer crashed and left the lock stale.withHookTokenClaimLockis unchanged for its other callers and now sits on a newacquireHookTokenClaimLockhandle.world-postgres: the
LISTENclients and the owned pool had noerrorhandler. A connection the server closes (restart, failover, idle reaper, or a test container stopping, which is how it surfaced as two uncaught57P01errors in the same Sept 10 job) was an uncaught exception.listenChannelnow registers a handler, ends the client and reports to its owner; the run-status listener forgets the subscription and retries past its existing backoff, the streamer resubscribes after 5s, andcreateWorldattaches a no-operrorlistener to a pool it owns sopg.Pooldiscards the dead client instead of throwing.Harness
WORKFLOW_E2E_CLI_TIMEOUT_MS: 40000andWORKFLOW_VERCEL_PROJECT_NAMEon the Vercel lanes: CLI children were being killed at the 20s budget while still booting (inspect --withDatadying at "Inferring vercel project and team"), which is what putgetterStepWorkflow,Calculator.calculateand the other CLI-asserting tests in the flaky list.hookCleanupTestWorkflowgets the 90s budget its sibling multi-round-trip hook tests have: on green lanes it ran at 42–59s locally and 50–74s on Vercel against 60s, so its retries were budget exhaustion.Unit Tests (windows-latest)wall-clock assertions that tripped on this PR's own runs are restated as the property they approximated.events-consumer.test.ts › steps over a straggler without waiting out the deferred window(102ms measured against a 100ms window) now asserts the walk stands at the end of the log on the very next tick, with every straggler reported throughonDuplicateEvent; a deferred straggler would park the walk until a timer fires.run-return-value-real-world.test.ts(828ms measured against an 800ms bound at the 1s default interval) now runs at a 3s poll interval with the wait path bounded at half of it, so a stall of over a second no longer crosses the bound while the interval path still cannot report before ~3s.hookTimeoutin the rootvitest.config.ts).Unit Tests (windows-latest)on this PR failedfs.test.ts › cursor optimizationwithHook timed out in 10000msat abeforeEachthat writes ten small JSON files. Main's green run had the whole 78-test file at 6.7s; in the same job a sibling file was pushing a thousand events through the same disk (that preload test alone: 101s here, 133s on main's green run). The root config already gave test bodies 60s for exactly this reason and left hooks at vitest's default. No test is skipped or weakened.Not in this PR: H5 (the spec test's leaked run) landed in #4107; the
cliCancel10s override was removed by #4115, which is now on main (this branch's port of it was dropped on rebase); and #4120 labels every retried test with its lane, world and VM, which supersedes the backend label this PR originally added to the results comment.Test Plan
mainat fe8b27d. Two conflicts along the way, each resolved once:.github/scripts/aggregate-e2e-results.jstook main's version from test: persist E2E flake history #4120, andpackages/world-postgres/src/streamer.tsmerges this PR's LISTEN reconnect with [world-postgres] Fix stream reader listener leaks and skipped-chunk offset cursor #4125's reader lifecycle cleanup (one sharedclosedflag;close()clears the reconnect timer, aborts active readers, then closes the subscription).packages/core:vitest run src/workflow.test.ts src/events-consumer.test.ts src/runtime/run-return-value-real-world.test.ts(148 passed, 1 expected fail from main's suite);tsc --noEmitclean. The new testdoes not leave an unhandled rejection when the workflow is not registered and the log holds an unconsumed eventfails with the guard commented out and passes with it.packages/world-local: fullpnpm test(586 passed, 5 skipped), including the cross-instance convergence and lock-compromise tests.packages/world-postgres:tsc --noEmitclean; the docker-free unit tests pass, including [world-postgres] Fix stream reader listener leaks and skipped-chunk offset cursor #4125'sstreamer.test.tsagainst the merged file (thepgmock inreenqueue.test.tsgainedon). The container-backed suites run in CI.vitest.config.ts:hookTimeoutresolves to 60000 frompackages/world-local(confirmed viacreateVitest);fs.test.ts78 passed.scripts/check-changesets.mjs.🤖 Generated with Claude Code
https://claude.ai/code/session_012Rw5CkA3EvADg9hpVjS6RP