[core] Gate event creation on the loaded event count and restart replays in-process - #3145
[core] Gate event creation on the loaded event count and restart replays in-process#3145VaguelySerious wants to merge 6 commits into
Conversation
🦋 Changeset detectedLatest commit: e81e530 The changes in this PR will be included in the next version bump. This PR includes changesets to release 21 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 |
📊 Workflow Benchmarkscommit Backend:
📜 Previous results (7)55c3746Tue, 28 Jul 2026 20:20:51 GMT · run logs
f00518bTue, 28 Jul 2026 18:53:10 GMT · run logs
0dabdf8Tue, 28 Jul 2026 15:55:44 GMT · run logs
3003c5fTue, 28 Jul 2026 02:26:16 GMT · run logs
1b0a10cTue, 28 Jul 2026 01:38:01 GMT · run logs
5bbc400Mon, 27 Jul 2026 23:58:27 GMT · run logs
483a5c6Mon, 27 Jul 2026 23:12:42 GMT · run logs
ℹ️ Metric definitions & methodologyBest/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, deployment clocks) · 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 · 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 · STSO (1-20) 20/30/60 · STSO (101-120) 30/45/90 · STSO (1001-1020) 40/60/120 All metrics are measured from deployment-side timestamps only. Runs are triggered by an in-deployment route that stamps the anchor ( Cold starts are kept in the numbers on purpose — they are part of real bursty-workload latency. The workbench deployment cold-starts the |
🧪 E2E Test Results✅ All tests passed E2E Test SummarySummary
Details by Category✅ ▲ Vercel Production
✅ 💻 Local Development
✅ 📦 Local Production
✅ 🐘 Local Postgres
✅ 🪟 Windows
✅ 📋 Other
✅ vercel-multi-region
|
VaguelySerious
added
the
event-log-race-repro
5bbc400 to
1b0a10c
Compare
…process A replay-context event creation previously described its snapshot with a single watermark, which only proves no event landed above it. It cannot detect a *missing* event below it, so a replay working from a log with a hole still committed events derived from that hole — and because correlation IDs are positional ordinals of one seeded sequence, a one-event difference renames every downstream entity and corrupts the log. Creations now also send the snapshot's event count and its cursor, and a rejection restarts the replay inside the same invocation instead of re-posting the rejected payload (whose IDs the corrected log invalidates) or paying a queue round trip. A world may attach the missing events to its 412, in which case the first restart needs no event-log request. Also guards the suspension `attr_set` write, and re-sorts a merged event log by event ID when an append arrives out of order. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Also makes the v4 event tests derive their mock origin from the override like the rest of the file already does, so a non-empty override does not fail unit tests. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The matching world-vercel guard shipped and is live in production, so the e2e lanes exercise both halves against the default endpoint. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Resolves the overlap with #3110, which introduced the same event-log merge consolidation this branch had added as `mergeEvents`: `appendUniqueEvents` now carries the optional id set from main plus the out-of-order re-sort and warning, and `mergeEvents` is gone. Main's `withPreconditionRetry` edit drops out with the function itself. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The event-log merge no longer re-sorts by event id. A World's canonical order is its own: world-vercel orders by event id, but world-local orders by (createdAt, eventId) and deliberately re-mints keys (dominant-event and claim canonicalization) so the two diverge. Re-sorting by event id there produced an order no ordered load would ever return, reordering a terminal event ahead of an accepted hook and breaking concurrent hook-token arbitration. The merge was only sorting so the snapshot could read its watermark off the tail, so read the maximum ULID time across the log instead. That removes the ordering dependency entirely and is exact rather than merely safe: every loaded event is at or below the maximum, so stateEventCount is still events.length whatever order the World returned. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
TooTallNate
left a comment
TooTallNate
left a comment
There was a problem hiding this comment.
The analysis in this PR is the best root-cause writeup I've read in this repo, and the design that follows from it is right. I want to flag one CI signal before it merges, because it bears directly on the headline claim — and to own that the mechanism this replaces is one I approved.
First, the correction to my own review
I approved withPreconditionRetry on #2266/#2946 and backported it on #3079. Your diagnosis that it re-commits a payload whose correlation IDs were minted by the pre-reload replay is correct, and I missed it: I reasoned about wait_completed being a fact (safe to re-commit) and run_completed being excluded, but never followed the same logic through the handleSuspension creates, where the payload's correlation IDs are positional ordinals of the pre-reload seeded sequence. Retrying those in place writes events no correct replay would produce — the retry could manufacture the divergence it was meant to prevent. Deleting it in favour of an in-process replay restart is the right call, and the two-property framing of why a scalar watermark can't work ("a concurrent replay's writes carry no marker at all" + "a watermark cannot represent a hole below itself") is exactly the missing piece.
Blocking: the Event Log Race Repro is red, with the class this PR exists to eliminate
The Event Log Race Repro lane fails on the current head (e81e5305d, run 30397001409). The outcome distribution is what concerns me, measured against main's own most recent run of the same lane (fba26fd9b, ~90 minutes earlier):
| run | CORRUPTED_EVENT_LOG |
stuck |
total failures |
|---|---|---|---|
main fba26fd9b |
0 | 754 | 754 |
this PR e81e5305d |
375 | 66 | 441 |
Fewer failures overall, but the corruption class goes 0 → 375 on the branch whose stated purpose is to eliminate it.
I don't think that's necessarily a defect, and I can see at least two readings that would exonerate it:
- The lane can't exercise the fix. The description says the backend half is live in production; if the preview deployment this lane targets doesn't enforce the count, the guard is inert here and these 375 are the pre-existing corruption class — in which case the lane is currently unable to validate the central claim, and that's worth saying explicitly.
- Unmasking. main's 754
stuckruns may be failing before they can corrupt; this PR reducesstuck754 → 66, so runs that previously wedged now proceed far enough to hit corruption that was always latent.
Both are plausible, and distinguishing them needs facts I don't have. What I can rule out: the run isn't stale (it's the current head), and I couldn't find guard activity in the job output — but the runtime's restarting replay in-process warning goes to the deployment's logs, not the runner's, so that's inconclusive rather than negative.
So the ask is narrow: confirm whether the guard engages in that lane, and account for the 375. If it's the inert-backend reading, say so in the description and note that the repro can't gate this change (and ideally what does). If runs are being unmasked, that's fine too — but it should be stated, since "this PR eliminates CORRUPTED_EVENT_LOG" and "its repro shows 375 of them" can't both stand unexplained in the record.
What I verified and think is right
- Snapshot atomicity.
preconditionSnapshotParamsemits all three fields or none, and the three-way fail-open (guard off / watermark underivable →{}) means a partial snapshot can never reach a backend.stateEventCount = events.lengthis sound because the watermark is the max, and the last commit deriving it from the maximum rather than the tail is load-bearing, not cosmetic: with world-local ordering by(createdAt, eventId)the tail need not be the greatest id, and a tail-derived watermark would understate — safe, but it would silently break the "count = events at or below" identity the backend contract depends on. Good thatappendUniqueEventsnow documents "nothing downstream may assume the tail is the newest". - The backend contract doc is the most valuable artifact here. "Count every created event including replay-origin ones", "at or below, never strictly below, never against a total", and above all one-sided safety — anything incomplete/uncomputable/expired must allow the write — is precisely the rule that keeps a fence from becoming a corruption source in its own right, given the client responds to a rejection by discarding its whole replay.
- The restart. Bounded by
WORKFLOW_PRECONDITION_MAX_INPROCESS_RESTARTS(default 3) then falling back to a single immediate re-invocation rather than failing the run; full cursor-less reload with the lexicographic-vs-ULID-time reasoning spelled out; the attached-delta shortcut trusted only on the first restart, so a backend that under-counts costs one wasted restart rather than an unbounded loop. The tests cover each of those, including the bound and the override. attr_setfrom a suspension is now guarded,setAttributes()from a step body deliberately isn't, with the reason recorded at the call site (no replay snapshot exists to compare) — the right split, and previously a real bypass.- Clean removal: no orphaned references to
withPreconditionRetry/MutableEventLog/stateUpdatedAtForCreate/PRECONDITION_MAX_RELOAD_RETRIES. Local suites green — core 1632 (+3 pre-existing expected-fails), world-vercel 310. All other CI is green (100 pass).
One question and one follow-up
- Sibling creates under clock skew. Every create in a suspension shares one snapshot, and siblings are excluded from the count only because their event ids carry a ULID time above the watermark. If the id-minting clock runs behind a client watermark derived from previously-loaded events, a sibling could land at or below it and trip the fence. The failure direction is safe (reject → restart → re-invoke, never a bad commit), so this is a liveness question, not a correctness one — but is it bounded by anything other than the restart budget?
stablenow carries the design this PR corrects. #3079 backported the watermark guard andwithPreconditionRetry, so 4.x has both the hole and the retry that can re-commit stale correlation IDs. Whatever the plan is — backport this, or neuter just the retry there — it'd be good to capture it while the reasoning is fresh.
2 participants
Depends on the matching
world-vercelbackend change, which has landed and is live in production.Why
The
stateUpdatedAtprecondition guard was supposed to stopCORRUPTED_EVENT_LOGfailures caused by an event landing between a replay's event load and its event write. It does not fully. It compares two scalars — the client's watermark (the ULID time of its latest loaded event) against the latest recorded out-of-band event — which proves only "no outside event landed strictly above my watermark". Replay determinism needs "my loaded array is exactly the canonical log prefix."A run corrupted with the guard on, reconstructed from its full event log:
The writing replay's snapshot ended at the second
wait_completed, so its watermark was exactly equal to the marker stamped by thestep_completedit had never loaded. Equality is allowed by design (to avoid livelock), so the write was accepted 276 ms late. That replay emitted 2 of a step where the canonical log has 3, and since correlation IDs are positional ordinals of one seeded ULID sequence, every entity from that point on was renamed.Two properties of this failure matter: a concurrent replay's writes carry no marker at all, so the guard was blind to them; and a watermark cannot represent a hole below itself.
What changes
stateEventCount(how many events were loaded) andstateCursorjoinstateUpdatedAt, sent atomically by one helper so they can never diverge. A world rejects when it recorded more events at or below the watermark than the client loaded.withPreconditionRetryis deleted: it reloaded the log and then re-committed the same payload, whose correlation IDs were minted by the pre-reload replay — so its retry wrote events no correct replay would produce. A rejection now rebuilds the workflow from a corrected log within the same invocation (bounded byWORKFLOW_PRECONDITION_MAX_INPROCESS_RESTARTS, default 3), then falls back to today's re-invocation. This is what the existing comment on therun_completedpath already asked for.events.listat all. Trusted only on an invocation's first restart, since the completeness proof leans on the world's own bookkeeping. Optional for worlds — absent or unusable details fall back to a full, cursor-less reload.eid:cursor filters lexicographically while a hole is defined by ULID time: an event in the same millisecond sorts either side of the cursor by its random component, and one minted before the client's read but committed after always sorts below it. An incremental reload heals a hole only by luck.attr_setfrom a suspension is now guarded — it previously bypassed the guard entirely.setAttributes()called from a step body stays unguarded, and says why: it holds no replay snapshot, so there is nothing to compare.@workflow/world-localand@workflow/world-postgresignore the new params, as they dostateUpdatedAt, and do not declare the capability.Known residual
All creations in one suspension share a snapshot and a
Promise.all, so the fence rejects every sibling arriving after it engages — but a sibling that committed before it engaged is still unexplained by the corrected replay. Unchanged by this PR (a re-invocation has identical exposure today) and not closable by any optimistic-concurrency check; it needs a run-level append-tail fence or an atomic multi-event create.Test plan
packages/core/src/runtime/precondition-guard-replay.test.ts— restart instead of re-invocation; cursor-less reload; delta consumed with zeroevents.list; malformed delta falls back; delta ignored on the second restart; exactlyWORKFLOW_PRECONDITION_MAX_INPROCESS_RESTARTSrestarts then one re-invocation; the restarted create carries correlation IDs derived from the corrected log;attr_setcarries all three fields.packages/core/src/runtime/helpers.test.ts— the three fields are sent or withheld as a unit; out-of-order merge re-sorts, warns, and leaves the tail as the maximum; 412 delta decoding.packages/core/src/runtime.test.ts— an inline claim rejected mid-batch now completes the run inside the same delivery, with the step body running exactly once.packages/world-vercel— wire-format pairs for both new fields, absence on the legacy compat path, and a 412 body whose events arrive decoded on the error.🤖 Generated with Claude Code