Slot event identity (SDK 3/4): number events by slot in the Local and Postgres Worlds - #3246
Slot event identity (SDK 3/4): number events by slot in the Local and Postgres Worlds#3246VaguelySerious wants to merge 31 commits into
Conversation
🦋 Changeset detectedLatest commit: 2f9e3a1 The changes in this PR will be included in the next version bump. This PR includes changesets to release 20 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❌ Some tests failed ❌ Failed E2E Tests▲ Vercel Production (228 failed)astro (27 failed):
example (15 failed):
express (25 failed):
fastify (11 failed):
hono (35 failed):
nextjs-turbopack (9 failed):
nextjs-webpack (30 failed):
nitro (16 failed):
nuxt (25 failed):
sveltekit (17 failed):
vite (18 failed):
💻 Local Development (1 failed)nextjs-webpack-stable (1 failed):
📋 Other (59 failed)e2e-vercel-prod-nest (26 failed):
e2e-vercel-prod-tanstack-start (33 failed):
vercel-multi-region (9 failed)nextjs-turbopack (9 failed):
E2E Test SummarySummary
Details by Category❌ ▲ Vercel Production
❌ 💻 Local Development
✅ 📦 Local Production
✅ 🐘 Local Postgres
✅ 🪟 Windows
❌ 📋 Other
❌ vercel-multi-region
|
…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.
| * returns. A ULID-numbered run keeps its wall-clock order, which its ids agree | ||
| * with anyway. | ||
| */ | ||
| const eventOrderTime = (event: { eventId: string; createdAt: Date }): number => |
There was a problem hiding this comment.
| const eventOrderTime = (event: { eventId: string; createdAt: Date }): number => | |
| const eventOrderTime = <TEvent extends { eventId: string; createdAt: Date }>( | |
| event: TEvent | |
| ): number => |
Non-generic eventOrderTime parameter type collapses the generic T of paginatedFileSystemQuery, causing a TypeScript build break across event-typed call sites in @workflow/world-local.
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.
📊 Workflow Benchmarks❌ The benchmark run for Partial results from the failed run: commit Backend:
📈 STSO distribution vs main (inline / queue-hop histograms)1020 steps (inline) Cumulative STSO time: main 437759ms → this run 423041ms (Δ -14718ms, -3%) 1020 steps (queue-hop) Cumulative STSO time: main 8262ms → this run 8769ms (Δ +507ms, +6%) 📜 Previous results (5)2305e32Sat, 01 Aug 2026 23:43:18 GMT · run logs
351046fSat, 01 Aug 2026 22:04:40 GMT · run logs
f6fa8ecSat, 01 Aug 2026 20:54:41 GMT · run logs
44b20a1Fri, 31 Jul 2026 21:45:46 GMT · run logs
a67b345Fri, 31 Jul 2026 21:05:15 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 |
Event Log Race ReproNo event-log regressions in the latest repro job. 1400 runs hit harness-side Run History
Latest Scenario Breakdown
Latest Non-Completed Runs
Showing 20 of 1400 non-completed runs. The |
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>
…event A divergence is a disagreement between the order the log records and the order a replay reconstructs it in, so the log's own ordering is the only evidence that separates the candidate causes. The runs live on an ephemeral preview deployment, so the window has to be read while the job is still running. Sampled (6 runs) and kept out of the sticky comment, which has a size limit; the results artifact carries them.
A slot claim is an assertion that nothing has been published since the view the writer decided from. Numbering a concurrent batch up front can only assert that for the first of them: the rest sit above slots their own siblings have yet to fill, so a foreign event landing in that space clears their fences too and the batch commits decisions taken without it. Claims are now drawn one at a time off a per-log write chain, so every write names the position immediately after the tail its writer saw. A rejection stops the whole batch rather than only its own write — the log's tail stops advancing while the backend's moves on, so the claims behind it fall inside the occupied range and are rejected in turn. That is the intent: the batch was decided from a log missing an event, so none of it should land. Rejected claims no longer re-address the same write to a free slot by default. Re-sending commits the stale decision anyway, and the missing event may be the one that would have taken the workflow down another branch; WORKFLOW_SLOT_RETRY_BUDGET takes the other side of that trade. world-local and world-postgres check the claim against the log's tail rather than the slot being free. Allocation is append-only, so a position left unwritten by an abandoned reservation stays empty for good, and a caller numbering from a stale snapshot aims straight at it — landing an event below events another replay already consumed. Measured on the world-postgres race repro: 52 runs, 0 CORRUPTED_EVENT_LOG, against 8 of 18 step-storm attempts corrupted on main. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Collapses the slot recovery path onto main's in-process replay restart: `claimFenceFor` replaces `withSlotRetry`/`withEventCreateFence`/`stepClaimFence`, keeping the serialized tail-tight claim while a lost claim (409) and a stale watermark (412) share one recovery via `isStaleWriteRejection`.
A restarted replay reloaded its whole event log because a hole under ULID identity is defined by time while a cursor filters lexicographically, so an incremental load can miss it. Neither half of that holds once a run numbers its events by slot: slot ids sort in write order, so everything the replay was missing is strictly above the cursor, and a dense log holds exactly maxSlot events, so the count proves afterwards that the page closed the gap. A short count falls back to the authoritative load. Measured on the step-storm repro against world-postgres, where a never-read poke hook rejects nearly every claim: two attempts went from ~400s and scoring stuck to 85.7s and 87.7s, with restart and re-invocation counts unchanged.
A slot-numbered run recovers from a rejected write by reading the page after its cursor, not by reloading its log. The budget of 3 was priced for the reload: spending it buys a re-invocation, a queue hop plus the 2s re-invoke delay, in place of restarts that now cost a fraction of what the bound was protecting against. Measured on the step-storm repro against world-postgres at 6-way concurrency: the six runs went from 196-241s, two of them past the harness timeout and scored stuck, to 119-148s with none timing out.
On a run numbering its events by position the id is the position, so a gapped or out-of-order log is readable straight off the timeline. The correlation id already on the line cannot report it: attribute and hook correlation ids stay on ULIDs in both modes.
A slot rejection whose delta already contains a step_started for this exact step is the ordinary "another handler owns it" outcome wearing a slot rejection, so treat it the way an unfenced write's EntityConflictError is treated and skip, rather than restarting the replay to re-derive a claim that will lose again. The identity test is strict: correlation ids are positional under slot identity, so a diverged replay can reach the same step number naming a different call. Step name must match, and on the lazy path the inputs must be byte-identical.
Concurrent replays of one run contend for the same event slots, and the loser of a rejected write restarted immediately, putting every loser back in contention at once so none pulled ahead. Wait a full-jitter interval first, doubling per restart to a 400ms cap. Tunable with WORKFLOW_PRECONDITION_RESTART_BACKOFF_MS (0 disables) and WORKFLOW_PRECONDITION_RESTART_BACKOFF_MAX_MS.
|
(AI) Superseded by #3305, which combines this stack into a single PR. The correlation-id renumbering that this stack carried is dropped: it was separable from slot event identity, and it dragged in prerequisites of its own (run-scoped queue idempotency keys, run-scoped step keys). Correlation ids stay ULIDs. |
Stacked on #3234. Review that first — this PR only makes sense once the client can claim a slot.
What
Slot identity is only useful if a World can keep it, so both first-party Worlds now allocate, honour, and defend dense per-run positions.
evnt_…001is a run's first event,evnt_…002its second, with no gaps — so the highest number is the event count, and a reader can prove its copy of a log is complete.Behaviour is opt-in per run via
WORKFLOW_SLOT_IDENTITY, and a run keeps the scheme it was created with for life.How
SPEC_VERSION_MAX_SUPPORTEDseparates the newest version a World can read from the version it stamps. Without the split, the flag that turns slot identity on for new runs would make every World reject the runs it had just created. Worlds opt into minting individually, through thespecVersionthey declare —mintedSpecVersion()is the one place that reads the flag.(run_id, id), migration0018), because under slot identityevnt_…001exists once per run. That key is then the authority: a unique violation means "this position is taken", and the writer re-probes and tries the next free one. Step ids get the same treatment for the same reason. The run leads both keys, so the existing run-scoped range scans stay a single index seek — which also makes the standalonerun_idindexes redundant.max++, is what guarantees progress: each round at least one writer wins.SlotConflictError) carrying the events the caller was missing, and nothing is materialized for it — a step row left behind by a losing attempt would make the caller's re-post trip its own orphan and read that as "a concurrent handler won the create".assertWorldSupportsRuntimeProtocolaccepts a World declaring anything fromSPEC_VERSION_CURRENTup toSPEC_VERSION_MAX_SUPPORTED, and a turbo invocation seeds its slot floor from the backgroundedrun_startedit never sees in its snapshot.SPEC_VERSION_CURRENTstays 5 — nothing mints spec 6 unless the flag is set.Testing
packages/world-postgres/test/slot-identity.test.ts(19 tests, Postgres testcontainer) andpackages/world-local/src/storage/slot-identity.test.ts: dense numbering, both mode-pinning 400s, the conflict delta, and the no-orphan guarantee.1…6with no holes.world-postgres181,world-local522,world98,core1687.Claims are taken one at a time, tight against the tail
A slot claim is an assertion that nothing has been published since the view its writer decided from. Numbering a concurrent batch up front can only assert that for the first of them: the rest sit above positions their own siblings have yet to fill, so a foreign event landing in that space clears their fences too, and the batch commits decisions taken without it. That was still corrupting logs with slot identity on.
Claims are now drawn one at a time off a per-log write chain, so every write names the position immediately after the tail its writer saw. A rejection stops the whole batch rather than only its own write — the log's tail stops advancing while the backend's moves on, so the claims behind it fall inside the occupied range and are rejected in turn. The batch was decided from a log missing an event, so none of it should land.
Both Worlds check a claim against the log's tail, not against the position being free. Allocation is append-only and a position claimed by a write that then failed is never filled, so a log can carry holes below its tail; a caller numbering from a stale snapshot aims straight at one. Accepting that write lands an event below events another replay has already consumed — the log stays internally consistent while its order silently changes, which is enough to flip a race between a step and a sleep from one replay to the next.
A rejected claim is not re-addressed to a free position by default: re-sending commits the stale decision anyway, and the missing event may be the one that would have taken the workflow down another branch.
WORKFLOW_SLOT_RETRY_BUDGETtakes the other side of that trade.Measured
pnpm run test:e2e:event-log-race-repro:local, 52 runs (24 step-storm, 24 hook-storm, 4 hook-sleep):main51 of 52 completed; the one non-completion was a
stuckstep-storm run that was still writing events at the harness's 240s cutoff (379 events, dense to position 379, 17 conflicts all below position 118) under the heaviest poke pressure in the batch.Known cost: serializing claims turns an N-event suspension flush into N sequential round-trips. Per-run event throughput on this rig fell from ~13/s to ~6.4/s. The fence itself cannot be pipelined — each claim has to name the tail its writer actually saw — so the recovery is a batched create that allocates N contiguous positions server-side in one request. Tracked as a follow-up.
Follow-ups
events.listByCorrelationIdis not yet run-scoped; a correlation id is only unique within its run under slot identity. Needs arunIdonListEventsByCorrelationIdParams, so it is deliberately out of this PR.world-vercelis the remaining World; it lands with the backend stack.🤖 Generated with Claude Code
Stack: #3228 → #3234 → #3246 → #3247
Paired backend stack (world-vercel side): 6 PRs, all rebased on main and stacked;
WORKFLOW_SERVER_URL_OVERRIDEpoints at the top of it and must be reverted before merge.