[core] Slot event identity + main (race-repro run) - #3249
Draft
VaguelySerious wants to merge 41 commits into
Draft
[core] Slot event identity + main (race-repro run)#3249VaguelySerious wants to merge 41 commits into
VaguelySerious wants to merge 41 commits into
Conversation
… keys Adds the client half of slot-based event identity, dormant until a run is stamped at spec version 6. - `@workflow/world` gains `slot-identity.ts` (26-char zero-padded decimal bodies, so a slot is a valid ULID body everywhere a ULID is accepted), `SPEC_VERSION_SLOT_IDENTITY` and `usesSlotIdentity()`. - `nextCorrelationId(kind)` on the orchestrator context is now the only place step and wait correlation ids are minted. In slot mode each kind counts independently from 1; otherwise it delegates to the same seeded ULID generator as before, so existing runs are byte-identical. - Every queue idempotency key is scoped to the run. Queues dedupe per queue, which is per workflow, so slot-numbered correlation ids would otherwise collide across concurrent runs of one workflow — silently, because a deduped send is answered normally and never dispatched. A source-scan test asserts no site builds a key any other way. - `packages/world` had test files but no `test` script, so 10 files never ran in CI. Added one.
On a run that numbers its events by slot, the runtime names each event's own id, which is its claim on that position in the log. The backend inserts the id conditionally, so a 409 proves another writer got there first and that this replay ran against a log missing at least one event. Claims are reserved contiguously off the loaded log rather than all at maxSlot + 1: a suspension flushes its operations concurrently, so without reservation every operation in a flush would propose the same slot and all but one would conflict, on every flush. Operations are built in deterministic replay order, so each one's slot is replay-stable. `withEventCreateFence` picks the run's fence: the event slot for a slot-numbered run, the `stateUpdatedAt` watermark otherwise. The two retry loops stay separate — they differ in what a rejection proves and in what the client does about it, and both are live at once while runs on the older numbering drain, which is what keeps 409s and 412s separately countable during a rollout. Creates that must not retry in place (`run_completed`, the inline `step_started` claims) take a bare fence from `eventCreateFenceFor`, so a rejection escapes to a fresh replay: merged events can change what the workflow body decides, and only a replay from the top can act on them. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Slot identity is only useful if a World can actually keep it, so both first-party Worlds now allocate, honour, and defend dense per-run positions: - `SPEC_VERSION_MAX_SUPPORTED` separates the newest version a World can read from the version it stamps, so turning the flag on somewhere does not make the runs it creates unreadable elsewhere. - `mintedSpecVersion()` gives both Worlds one place to opt new runs in. - The Local World allocates under its storage lock and re-probes on a lost exclusive write; the Postgres World makes the events primary key run-scoped and treats a unique violation as "try the next free position", re-probing every round so contention always makes progress. - A caller-claimed position that is already taken is a 409 carrying the events the caller was missing, and nothing is materialized for it. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
…epro # Conflicts: # packages/core/src/runtime/helpers.test.ts # packages/core/src/runtime/step-executor.ts # packages/core/src/workflow.ts
🦋 Changeset detectedLatest commit: 61e7dc8 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 |
VaguelySerious
added
the
event-log-race-repro
Contributor
Contributor
🧪 E2E Test Results❌ Some tests failed ❌ Failed E2E Tests▲ Vercel Production (1 failed)express (1 failed):
E2E Test SummarySummary
Details by Category❌ ▲ Vercel Production
✅ 💻 Local Development
✅ 📦 Local Production
✅ 🐘 Local Postgres
✅ 🪟 Windows
✅ 📋 Other
✅ vercel-multi-region
|
Contributor
📊 Workflow Benchmarkscommit Backend:
📈 STSO distribution vs main (inline / queue-hop histograms)1020 steps (inline) Cumulative STSO time: main 486797ms → this run 457266ms (Δ -29531ms, -6%) 1020 steps (queue-hop) Cumulative STSO time: main 12497ms → this run 8151ms (Δ -4346ms, -35%) 📜 Previous results (4)bf289bbFri, 31 Jul 2026 20:23:03 GMT · run logs
b67828cFri, 31 Jul 2026 18:43:28 GMT · run logs
6b2ccdbFri, 31 Jul 2026 14:25:37 GMT · run logs
48084a7Fri, 31 Jul 2026 13:27:55 GMT · run logs
ℹ️ Metric definitions & methodologyThe 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: 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, 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 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 |
Contributor
Event Log Race Repro168 of 1400 latest repro runs hit event-log regressions. Run History
Latest Scenario Breakdown
Latest Non-Completed Runs
Showing 20 of 168 non-completed runs. |
…s its start The synthetic `step_created` a lazy step start materializes was written with a plain create-if-absent write, so losing its position surfaced as a duplicate- entity error - which the runtime reads as "another handler owns this step" and skips, leaving the step claimed but never run. It now takes the position the same way every other event does, and a loss is reported as a slot conflict the caller can merge and re-propose.
…s its start The synthetic `step_created` a lazy step start materializes was written with a plain create-if-absent write, so losing its position surfaced as a duplicate- entity error - which the runtime reads as "another handler owns this step" and skips, leaving the step claimed but never run. It now takes the position the same way every other event does, and a loss is reported as a slot conflict the caller can merge and re-propose.
An optimistic start runs against a locally synthesized run row, so the workflow start time this invocation reports comes from the client clock while every later replay reads the persisted run. Sending that instant as the run_started event's occurredAt lets a backend record it as the run's startedAt, so the two agree instead of differing by the round-trip. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
An optimistic start runs against a locally synthesized run row, so the workflow start time this invocation reports comes from the client clock while every later replay reads the persisted run. Sending that instant as the run_started event's occurredAt lets a backend record it as the run's startedAt, so the two agree instead of differing by the round-trip. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
![vercel[bot]](https://avatars.githubusercontent.com/in/8329?s=60&v=4){kind=small}
…e waited for Three diagnostic gaps that together made replay divergence unreadable: - `composeLogLine` dropped `errorMessage` whenever the message did not already contain it, so a warn carrying an error alongside its own summary line logged the symptom and none of the diagnosis. - An unconsumable event named only itself. It is almost always an event whose entity this replay never issued, so the pending invocation queue is what distinguishes "never issued" from "issued under another id". - An inline step batch abandoned on a fenced claim logged neither which member was fenced nor how the others settled. The fence is per-write, so a batch can split: the rejected claim writes nothing while a sibling on a different slot commits. Also read a failed run's error through `returnValue()` in the race-repro harness — `runs.get` returns the raw serialized payload, so every corruption in the report carried a code and no message. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
…atch An inline step's step_started claim is fenced per-write under slot identity, so a 409 only proves another writer took that write's number — routinely true, since the backend allocates outside events from the same next-free pointer the client reserves from. Abandoning the whole batch on it left the loser's events landing seconds later, after a whole later phase, in an order no single replay could consume. stepClaimFence keeps a watermark-guarded run on its single shared fence (a 412 does mean the view is stale, and the batch is meant to fail as a unit) and gives a slot-numbered run an in-place reclaim: merge the delta, reserve past it, re-claim. The reservation pointer is now absolute and only moves forward, so a merge cannot hand the retrying writer a slot a sibling is still in flight on.
…rt time `createdAt` is stamped when a write begins, before its final slot is known, so it disagrees with slot order in two ways: a writer that loses a slot re-proposes above the winner while keeping its earlier stamp, and a caller that reserves a range of slots for one flush commits them in whatever order the network returns. Replay consumes the log in list order and never sorts, so listing by `createdAt` hands it an order no execution produced. Slot events now report one shared order time and let the existing event-id tie-break do the ordering, matching the Postgres World's `orderBy(eventId)` and the Vercel World's sort key. ULID runs keep their wall-clock order, which their ids agree with anyway.
…rt time `createdAt` is stamped when a write begins, before its final slot is known, so it disagrees with slot order in two ways: a writer that loses a slot re-proposes above the winner while keeping its earlier stamp, and a caller that reserves a range of slots for one flush commits them in whatever order the network returns. Replay consumes the log in list order and never sorts, so listing by `createdAt` hands it an order no execution produced. Slot events now report one shared order time and let the existing event-id tie-break do the ordering, matching the Postgres World's `orderBy(eventId)` and the Vercel World's sort key. ULID runs keep their wall-clock order, which their ids agree with anyway.
Two independent sources of `CorruptedEventLogError` on well-formed event logs, both found by dumping the logs of runs that failed that way. A hook delivery is ordered by when its event row commits, not by when the payload arrived, so a delivery that races a disposal — arriving first, committing second — lands after its own `hook_disposed` in the log. The hook's consumer retired on the disposal, so nothing consumed that event on any replay: a divergence that recurs identically every attempt and escalates to a terminal error. The consumer now stays registered as a tombstone and discards the late delivery, which is what `disposeHook` already assumed when it settled every awaiter. Separately, the unconsumed-event check gave the VM a flat 100ms of wall clock to register the next event's consumer. Real logs routinely need more: a hook payload fanning out into steps measures 254-717ms between the delivery and the first `step_created` it causes. The check now re-arms while a delivery is still in flight — the condition `scheduleWhenIdle` already polls — bounded by `WORKFLOW_DEFERRED_CHECK_MAX_GRACE_MS` so an abandoned delivery cannot park it forever.
Two independent sources of `CorruptedEventLogError` on well-formed event logs, both found by dumping the logs of runs that failed that way. A hook delivery is ordered by when its event row commits, not by when the payload arrived, so a delivery that races a disposal — arriving first, committing second — lands after its own `hook_disposed` in the log. The hook's consumer retired on the disposal, so nothing consumed that event on any replay: a divergence that recurs identically every attempt and escalates to a terminal error. The consumer now stays registered as a tombstone and discards the late delivery, which is what `disposeHook` already assumed when it settled every awaiter. Separately, the unconsumed-event check gave the VM a flat 100ms of wall clock to register the next event's consumer. Real logs routinely need more: a hook payload fanning out into steps measures 254-717ms between the delivery and the first `step_created` it causes. The check now re-arms while a delivery is still in flight — the condition `scheduleWhenIdle` already polls — bounded by `WORKFLOW_DEFERRED_CHECK_MAX_GRACE_MS` so an abandoned delivery cannot park it forever.
Contiguous allocation is not the same thing as a gap-free published log: a slot claimed by an operation that then fails for a reason of its own is never filled, and once a later slot is published that gap is permanent. What the scheme actually buys is explicit contention and a log that reads in write order. Nothing consumed the proof, so this is a comment and docs correction.
…e waited for Three diagnostic gaps that together made replay divergence unreadable: - `composeLogLine` dropped `errorMessage` whenever the message did not already contain it, so a warn carrying an error alongside its own summary line logged the symptom and none of the diagnosis. - An unconsumable event named only itself. It is almost always an event whose entity this replay never issued, so the pending invocation queue is what distinguishes "never issued" from "issued under another id". - An inline step batch abandoned on a fenced claim logged neither which member was fenced nor how the others settled. The fence is per-write, so a batch can split: the rejected claim writes nothing while a sibling on a different slot commits. Also read a failed run's error through `returnValue()` in the race-repro harness — `runs.get` returns the raw serialized payload, so every corruption in the report carried a code and no message. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
…atch An inline step's step_started claim is fenced per-write under slot identity, so a 409 only proves another writer took that write's number — routinely true, since the backend allocates outside events from the same next-free pointer the client reserves from. Abandoning the whole batch on it left the loser's events landing seconds later, after a whole later phase, in an order no single replay could consume. stepClaimFence keeps a watermark-guarded run on its single shared fence (a 412 does mean the view is stale, and the batch is meant to fail as a unit) and gives a slot-numbered run an in-place reclaim: merge the delta, reserve past it, re-claim. The reservation pointer is now absolute and only moves forward, so a merge cannot hand the retrying writer a slot a sibling is still in flight on.
A slot names a position in the replay order, so allocation has to hand out a position no published event sits above. Handing out the lowest free position instead let a late `step_completed` drop into a hole beneath its own `step_created`/`step_started`, and every replay of that run then met a completion for a step it had not started. The book now keeps a monotonic ceiling: a reservation goes above every position the book has ever seen, and releasing one does not lower it. `run_created` takes the first slot outright rather than allocating it, since a `run_started` racing it can already have moved the book past that position. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
# Conflicts: # docs/content/docs/v5/configuration/runtime-tuning.mdx # packages/world-local/src/storage/events-storage.ts # packages/world-local/src/storage/slot-identity.test.ts # packages/world-local/src/storage/slots.test.ts # packages/world-local/src/storage/slots.ts # packages/world-postgres/src/slots.ts # packages/world-postgres/test/slot-identity.test.ts
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
1 participant
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Draft for CI only — combines the slot-identity stack (#3246 and its parents) with current
main, which now includes #3241. Not for merge; #3246 stays the review PR.Carries the
event-log-race-reprolabel so the event-log race reproduction job runs against the combined tree.Merge resolutions
Three conflicts, all in
@workflow/core:runtime/step-executor.ts—main'scomputeInstanceIdstamp and the stack'seventCreateFenceare bothCreateEventParamsfields, sostartEventParamsnow carries the stamp plus a spread of the fence. Keeps both mechanisms; neither clobbers the other.runtime/helpers.test.ts,workflow.ts— import unions.runtime/step-executor.test.ts—main's compute-instance test passedstateUpdatedAtdirectly; the stack moved that undereventCreateFence, so the test now passes the fence.@workflow/coretypechecks clean and its suite is green (1688 passed, 3 expected fail).Note: the stack still carries its temporary backend URL override commit; that is deliberate for this run.
🤖 Generated with Claude Code