Skip to content

fix(core): order step-result deliveries against wait/hook deliveries by event-log position - #3139

Merged
TooTallNate merged 5 commits into
mainfrom
pgp/fix-step-delivery-ordering
Jul 28, 2026
Merged

fix(core): order step-result deliveries against wait/hook deliveries by event-log position#3139
TooTallNate merged 5 commits into
mainfrom
pgp/fix-step-delivery-ordering

Conversation

@pranaygp

@pranaygp pranaygp commented Jul 27, 2026

Copy link
Copy Markdown
Contributor

The bug

Two production runs on @workflow/core@5.0.0-beta.36 (o2flow) burned all three divergence-recovery replays at the same eventId and terminated with CORRUPTED_EVENT_LOG:

run shape error
wrun_41KYJENABV0GSF5YTE9EETV5DD step vs wait Replay divergence: step event step_created for step_X belongs to "A", but the current step consumer is "B"
wrun_41KYJEE01S0GPC9RWT5MEKVCX8 step vs hook same

Mechanism

useStep proxies draw deterministic ULIDs in invocation order (packages/core/src/step.ts:27), and replay pairs events to consumers by correlationId, erroring on a stepName mismatch (step.ts:88-100). So the ULID→stepName allocation is a pure function of the order in which promise resolutions are delivered to workflow code.

The delivery-barrier registry (ctx.pendingDeliveryBarriers, packages/core/src/private.ts) exists to pin that order to event-log position — its own docstring describes this exact failure class — but it only covered hook payloads and wait completions. Step results were outside it: step_completed resolved straight from its serial promiseQueue slot, and that slot's latency varies wildly between replays of the same invocation:

  • the first replay pays full hydration (decrypt → decompress → revive);
  • later replays share the invocation's ReplayPayloadCache and memo-hit small primitive results (replay-payload-cache.ts:125), resolving in one or two microtask hops.

Meanwhile a wait_completed resolves from a detached, fixed-hop chain (workflow/sleep.ts:100-116) that is about four hops off the queue tail. So a step completion adjacent in the log to a wait_completed is delivered wait-first on a cold replay and step-first on a warm one. Whichever order the invocation that wrote the follow-up step_created events happened to observe became law; every replay computing the other order diverged permanently, and since the divergence is deterministic given a warm cache, all three recovery replays hit it at the same event.

The fix

step_completed and step_failed now participate in the barrier registry, mirroring the hook-payload path exactly:

  • register a 'step' barrier at the event's log index, so later wait/hook deliveries are handed over only after it;
  • hydrate inside the serial promiseQueue slot (async deserialization stays in log order) but only capture the outcome, releasing pendingDeliveries in the slot's finally;
  • then, in a detached continuation, await the earlier deliveries before markDelivered() + resolve/reject.

Two details are what actually make the ordering hold. I found both by testing rather than by reading the code, and the first version of this PR had neither.

The deferral set is captured while consuming the event, not at the start of the hydration slot. Slot-start capture is not merely less deterministic — it is usually empty. An earlier delivery whose own slot runs first on the serial queue has typically already resolved and deregistered its barrier before the later slot begins, so the later delivery does not defer at all. Instrumenting the hook case showed exactly that: awaitEarlier kind=step idx=4 defers=0, with the hook's barrier already gone. Every event in one drain window is consumed before any slot runs, so consumption time sees all of them (defers=1).

A delivery that had to wait yields a macrotask before resolving. An earlier delivery being "delivered" only means its resolve() ran. The branch it woke may need arbitrarily many further microtask hops before it reaches its next useStep call and draws a ULID — a for await over a hook resumes the generator, settles the promise from next(), and only then runs the loop body; workflow code may await anything in between. Ordering the resolve() calls alone therefore buys a fixed hop or two of margin and leaves a hop-count race that holds only for the shortest consumers. Yielding a macrotask lets the earlier branch's whole microtask chain drain first, whatever its length. Only deliveries that actually deferred pay it, so the common single-delivery drain is unaffected.

wait_completed and hook_received deliveries symmetrically defer behind earlier step results. step_failed is included because a rejection is just as branch-deciding as a success — it decides whether a catch continuation runs, and therefore which ULIDs follow-up useStep calls draw. It also now holds pendingDeliveries across hydration, which it previously did not.

awaitEarlierDeliveries(ctx, index, kind) now takes the delivering kind instead of an explicit kind list, with a single DEFER_BEHIND table as the source of truth:

delivering defers behind earlier why not the rest
hook wait, step sequential same-entity payloads must not block one another
wait hook, step a wait never needs to queue behind another wait
step wait, hook step-vs-step order is already fixed by the serial promiseQueue

Deadlock / cycle analysis

  • No cycles. Every edge points from a later log index to a strictly earlier one, so the wait-for graph is a DAG by construction.
  • Never await a barrier inside a serial queue slot. Hydration stays in the slot; the barrier wait and the resolve run detached. Blocking a slot on a resolution the queue itself drives would deadlock the queue (the constraint sleep.ts already documents).
  • pendingDeliveries is released inside the slot, before the detached defer — otherwise scheduleWhenIdle could never reach idle, and the idle safety net that retires abandoned barriers (which this deferral may be waiting on) would never fire. This is the same shape as the hook path and the reason abort-controller.ts bumps the counter.
  • When no earlier barrier is pending — the overwhelmingly common case — awaitEarlierDeliveries resolves immediately with no macrotask, so the step's resolve is enqueued at the end of its own slot, before the next queue slot runs. Ordering against every other queue-slot-driven delivery (including abort-controller.ts's _setAborted, which is not a barrier participant) is therefore unchanged from before the fix, and no macrotask is paid.
  • The macrotask cannot strand a delivery. It is a setTimeout(0) awaited in the detached continuation, after pendingDeliveries has already been released in the slot, so it neither blocks the serial queue nor prevents scheduleWhenIdle from reaching idle.
  • A suspension cannot preempt the deferred resolve, even though scheduleWhenIdle also runs on setTimeout(0) and pendingDeliveries is already 0 by then. The deferred step's macrotask is registered the moment the earlier barrier is marked delivered — i.e. before the woken branch's continuation runs at all — whereas the suspension macrotask is only registered once some branch reaches a useStep past the end of the log, which happens within that continuation's microtask chain. Registration order therefore puts the step's resolve first, and its own continuation (a microtask) draws its ULID before the suspension macrotask fires. The 18 hop-count cases exercise exactly this: each ends in a suspension and asserts that both follow-up steps are pending, which only holds if the deferred delivery landed before the suspension took effect. This does assume workflow continuations are microtask chains, which holds because the sandbox has no real timers — sleep() is a wait event, not a setTimeout.
  • The idle safety net still covers abandoned step deliveries (workflow suspended before observing the resolution): registerDeliveryBarrierscheduleWhenIdle(finish) is unchanged.

One deviation from the obvious design, and it is load-bearing

Gating a step result behind every earlier hook barrier — the straightforward reading — is wrong, and the existing suite catches it. A buffered hook payload (no consumer awaiting when hook_received is consumed) is delivered by claim(), i.e. whenever the workflow next reads the hook — which is very commonly downstream of the step result itself (await setupStep() and only then iterator.next()). Gating the step on it stalls the run until the barrier's idle safety net fires, which then releases the step and every delivery queued behind that payload at once; the workflow installs its Promise.race against an already-resolved sleep and loses the very race the ordering exists to protect.

Implemented naively, that regressed 4 existing tests:

FAIL  src/hook-sleep-interaction.test.ts > … > should let a queued hook payload win when a reused wait completes after the step that installs the race
FAIL  src/hook-sleep-interaction.test.ts > … > should let a queued hook payload win without mapping the race promises
      (×2, once per sync/async deserialization mode)
ReplayDivergenceError: Replay divergence: step event step_created for step_01K11TFZ62YS0YYFDQ3E8B9YCY
  belongs to "drainStep", but the current step consumer is "syncNextStep"

So barrier entries carry an armed flag: wait and step are always armed, a hook payload with a waiting consumer is armed at registration, and a buffered payload is registered unarmed and armed by claim(). A step result skips any earlier delivery that will not resolve on its own — unarmed, or transitively blocked on something unarmed (resolvesOnItsOwn). Waits and hooks deliberately keep gating on unclaimed payloads: for them, waiting for the claim is the ordering guarantee (a wait_completed must not preempt a payload the log ordered first). Those 4 tests are now a real regression guard for this asymmetry.

Test evidence

packages/core/src/step-delivery-ordering.test.ts is byte-identical to the file in the repro-only companion PR #3137 apart from two it.fails markers there, which let a repro-only branch have green CI (sed 's/it\.fails(/it(/g' | cmp verifies it). So the tests demonstrably were not bent to fit the fix. Each case replays one committed event log twice through a shared ReplayPayloadCache (production shape: one cache per queue delivery, many replays), with hydrateStepReturnValue stubbed to cost 10ms so only the cold replay pays it.

Five cases, two of which fail on main:

case on main mirrors
wait vs step, cold replay passes
wait vs step, warm replay fails run wrun_41KYJENABV0GSF5YTE9EETV5DD
for await hook vs step, cold replay passes
for await hook vs step, warm replay fails run wrun_41KYJEE01S0GPC9RWT5MEKVCX8
direct await hook vs step, both replays passes control for the already-correct path

The hook flavour must use for await (… of hook) to reproduce, but not because the payload is buffered — I instrumented workflow/hook.ts to check, and all three hook cases consume hook_received with an awaiter already registered (promises.length === 1); claim() never runs in any of them. Entering for await calls next(), which reaches yield await this and subscribes well before the events consumer drains the log on process.nextTick.

What actually differs is how many microtask hops separate the payload resolving from the branch calling afterHook() and drawing its next ULID. for await resumes the async generator at yield await this, settles the promise returned by next(), and only then runs the loop body; a memo-warm step_completed — which on an unfixed runtime resolves inside its own queue slot with no detached chain at all — gets there first. A directly-awaited hook resumes its continuation in the first microtask and stays ahead even on a warm cache, which is why it makes a good control: same delivery path, same event log, opposite outcome on main, and this PR changes the code it runs through (the barrier is now registered armed there), so it must stay green.

So the hook flavour is the same hydration-latency race as the wait flavour; the consumer shape only sets how much of a head start the step result needs in order to win. (Buffered payloads are central to the armed design below, but they are exercised by hook-sleep-interaction.test.ts's queued-payload cases — verified by the same instrumentation: promises.length === 0, then claim()arm() — not by these new tests.)

Without the fix (fix sources reverted to the branch's base commit, converged test file kept):

❯ src/step-delivery-ordering.test.ts (5 tests | 2 failed) 147ms
  × delivers the wait before the step result on a later replay sharing the payload cache
  × delivers the hook payload before the step result on a later replay sharing the payload cache

ReplayDivergenceError: Replay divergence: step event step_created for
  step_01K11TFZ62YS0YYFDQ3E8B9YCX belongs to "afterSleep", but the current step consumer is "afterStep"
 ❯ src/step.ts:91:15

ReplayDivergenceError: Replay divergence: step event step_created for
  step_01K11TFZ62YS0YYFDQ3E8B9YCX belongs to "afterHook", but the current step consumer is "afterStep"
 ❯ src/step.ts:91:15

 Tests  2 failed | 3 passed (5)

This matches the repro PR's independently observed baseline on main exactly — same two cases, same ULID, same error text — and it reproduces the same way in CI, on both Linux and Windows: in #3137's run the two warm-replay cases satisfy their it.fails markers while the other three pass, i.e. the divergence is not an artifact of one machine's timing.

The second test file, and why these five cases are not sufficient

All five cases above are consumed by branches that reach their next useStep call in the fewest possible microtask hops. That makes them unable to distinguish two very different guarantees: (a) step results are delivered in event-log order relative to wait and hook deliveries, or (b) a step result merely resolves a hop or two later than it used to, which beats the shortest consumers and nothing else.

The distinction is not academic, and I only caught it by probing: the first version of this PR provided (b) and passed all five cases anyway. packages/core/src/step-delivery-hop-count.test.ts closes that hole. Each case replays a log a live run legitimately produced — the live invocation received the two events in separate deliveries, so the first branch ran to completion long before the second event existed — while the replay receives both in one drain window and must still allocate the ULIDs in the recorded order. The consumer is padded with 0, 1, 2, 4, 8, or 16 extra awaits so hop count is the only variable, across three groups: step result vs wait completion, step result vs hook payload, and step failure vs wait completion (a rejection decides whether a catch continuation runs, and so which ULID the useStep there draws — step_failed goes through the same registration and capture, so it needs the same guard).

version hop-count cases passing
main (no fix) 0 of 18
resolve-ordering only (this PR's first revision) 3 of 12 of the cases that predated the macrotask
this PR 18 of 18

The middle row is the point: without the event-consumption-time capture and the macrotask yield, a consumer with a single extra await after being resumed still diverges. These cases are the regression guard for the guarantee actually being (a).

With the fix: 5 passed (5) and 18 passed (18). The 15 ordering-sensitive files (both new files plus hook-sleep-interaction, async-deserialization-ordering, abort-replay-ordering, abort-consistency, step-hydration-memoization, workflow, runtime, events-consumer, step, workflow/sleep, workflow/hook, define-hook, runtime/resume-hook) were run 8× consecutively, stable at 321 passed | 3 expected fail every time.

Full core suite (74 files): 1565 passed | 3 expected fail — the 3 expected-fails are pre-existing it.fails cases. Under a colour TTY, log-format, logger, and context-errors additionally report ANSI inline-snapshot mismatches; those fail identically on the unmodified tree and pass under FORCE_COLOR=0, i.e. a local artifact, not a regression. pnpm --filter @workflow/core typecheck is clean, and biome check reports only the two noExcessiveCognitiveComplexity warnings that step.ts already carries on main (63 and 20 there, 63 and 21 here).

Full local e2e against a nextjs-turbopack dev server, re-run after the macrotask change since it shifts real timing: 135 passed (135) — the whole suite, including every AbortController case, cancelRun, hookWithSleepWorkflow, hookWithSleepFinalStepWorkflow, sleepWithSequentialStepsWorkflow, and setAttributes.

CI history. An earlier revision of this branch (3fe83a19, same barrier design, resolve-ordering only) went green across the whole matrix: all 13 E2E Vercel Prod Tests apps, E2E Local Dev, E2E Local Postgres and E2E Local Prod (three world backends, ~10 frameworks each), Unit Tests on Linux and Windows, Lint, Docs Checks, Tarballs Checks, Performance Benchmarks and DCO — tally SUCCESS: 80, SKIPPED: 6, FAILURE: 3. Revision d4f86aa4 (converged test file) likewise passed Unit Tests on both Linux and Windows, with the Linux core-suite line matching my local numbers exactly.

The 3 failures in that tally were E2E Local Prod Tests (nextjs-webpack - stable), (nuxt - stable), and the E2E Required Check gate aggregating them: all the same pre-existing flake, webhookWorkflow hitting its 120s timeout at 1 failed | 153 passed (154). main fails identically at commit 4ada27d3 (same test, same timeout, same counts), so it is unrelated to this change. For the record, the first run on this branch also tripped the documented rotating E2E Vercel Prod flake on 7 apps; main at this branch's exact base commit 4ba223a0 tripped it on 9, and the re-run came back fully green.

CI is re-running on the current revision, which adds the event-consumption-time capture, the macrotask yield, and the hop-count test file.

The companion repro-only PR is #3137 (branch pgp/repro-step-wait-divergence): it adds this same test file without the fix, and its CI confirms on Linux and Windows that the two warm-replay cases diverge on main while the other three hold. Merging that first, then this, gives a red-then-green history for the bug; whoever lands them should flip those two cases back from it.fails to plain assertions as part of merging this PR.

Follow-up: remaining barrier gaps (commit 2)

Review of the first commit turned up three more places the registry did not
reach. Each is fixed here, with a regression test in the new
packages/core/src/delivery-barrier-coverage.test.ts that reproduces the
production ReplayDivergenceError when — and only when — its own fix is
reverted. Verified one at a time.

1. A step must defer behind earlier STEP results

DEFER_BEHIND.step excluded 'step' on the grounds that the serial
promiseQueue already orders step results. That stopped being true in this
PR: a step captures its outcome in its queue slot but resolves from a detached
continuation once its barrier clears. Two steps agree on that ordering only
while they defer behind the same set — true within one drain window, false
across windows. A step consumed later can miss a wait/hook barrier an earlier
step is still parked on, because it retired in between; the earlier step is
then waiting out the macrotask yield while the later one resolves on
microtasks.

The test log is one a live run legitimately produces: stepA's worker writes
step_completed just before the invocation resuming from a sleep writes
step_created stepB, so that invocation's own replay never delivered stepA.
On replay stepB's consumer does not exist until the sleep lands, so the two
completions fall in separate drain windows.

Cost of the extra edge, measured on a parallel step fan-out (Promise.all of
N steps, all completing in one drain): +1.3 ms, flat, not O(N) — the idle
safety net retires the chain in one timer tick rather than serializing N of
them. N=10 3.1→4.4 ms, N=50 3.1→5.2 ms, N=100 6.6→7.8 ms.

2. sleep.ts and hook.ts must capture their deferral at consumption time

The "Coverage" argument the first commit documents for step.ts applies
symmetrically, and was not applied. sleep.ts read the registry after the
queue tail and hook.ts at the end of its hydration slot — by which point an
earlier step or hook has usually delivered and deregistered its barrier. The
later delivery then skips both the gate and awaitEarlierDeliveries'
macrotask yield, and overtakes the branch that earlier delivery just woke.

This is the exact mirror of step-delivery-hop-count.test.ts and fails the
same way: a wait completion diverges at 8 extra consumer hops, a hook payload
at 20. Both are covered at 0/1/3/8/20/50 hops in the new file.

The buffered hook payload path deliberately keeps evaluating at claim
time, and now says so. A buffered payload's delivery genuinely happens when
the workflow reads the hook, potentially many deliveries later; a
consumption-time snapshot makes the claim wait on barriers from a moment it
never participated in, which stalls the second payload in the e2e
hookWithSleepWorkflow long enough for the run to suspend before delivering
it. Caught by the full local e2e run, not by unit tests.

3. Abort deliveries participate in the registry

abort-controller.ts resolved _setAborted straight off its promiseQueue
slot and registered no barrier. That was sufficient only while every other
delivery also resolved from its slot. _setAborted fires the signal's
listeners, and a listener may invoke a step and draw a ULID, so an abort is as
branch-deciding as any other delivery — a log-earlier step sitting behind a
barrier is overtaken by any abort whose slot runs in the meantime. It now
registers as a 'hook' (which is exactly what the event is), always armed,
and resolves detached behind its deferral.

Also: resolvesOnItsOwn was exponential

Each armed entry re-walked every earlier entry of the opposite kind —
T(n) = Σ T(j) — with no memo, on the synchronous delivery path. The registry
is not bounded: EventsConsumer drains consecutively consumable events
synchronously while barriers only retire on microtask-driven deliveries, so a
fan-out of Promise.race([hook, sleep(watchdog)]) branches accumulates one
barrier per branch per kind (49 live barriers measured for 24 branches).

A single scan over 40 alternating armed hook/wait barriers took 92 seconds
of blocked event loop before the fix, and is instant after. Guarded by a test
in the new file that times the synchronous scan.

Verification (commit 2)

  • pnpm vitest run --root packages/core src/75 files, 1614 passed | 3 expected fail. Typecheck clean. Biome: same 8 pre-existing complexity/banned-type warnings as the unmodified tree, none new.
  • The 14 ordering-sensitive files 8x consecutively277 passed | 3 expected fail every time.
  • Full local e2e against a nextjs-turbopack dev server: 135 passed (135).
  • e2e/local-build, e2e/build-errors, e2e/route-bundle-isolation pass individually. Run as one vitest invocation, route-bundle-isolation fails — identically on the unmodified tree, so it is cross-suite build interference, not a regression.

Rollout caveat

In-flight runs whose logs were allocated under the old flipped (step-first) ordering will now deterministically diverge on replay. Those runs were already unrecoverable time bombs under the old runtime — any warm replay computed the other order, which is exactly how these two runs died — so this bounds the blast radius to windows that were already affected rather than creating a new one.

Not a concern for SDK version drift specifically: on Vercel a run is pinned to its originating immutable deployment, so a single run never replays across two different @workflow/core versions. The caveat above is only about logs already written under the old ordering, replayed by the same deployment.

What reviewers should scrutinise

  1. The armed asymmetry (private.ts, resolvesOnItsOwn + awaitEarlierDeliveries): is "a step never queues behind an unclaimed buffered payload" the right line, or should the wait/hook side eventually adopt it too? Today they must not, or the original hook-vs-sleep fix regresses.
  2. arm() timing — the thinnest part of the argument. A buffered payload is armed at claim(), and a step now reads armed-ness while consuming its event, which is exactly log position and cannot depend on hydration duration. The residual sharp edge is a shape where the claim is armed by a continuation of an earlier delivery, i.e. where the arming itself is latency-coupled one level up, so a step consuming its event might see the entry unarmed on one replay and armed on another. I could not construct a case that diverges, and none of the existing tests exhibit it — the new tests never buffer, and hook-sleep-interaction's queued-payload cases claim from a continuation downstream of a step but with only one step delivery in flight. So treat this as unproven rather than verified; it is where I would look first if a similar divergence resurfaces.
  3. Macrotask cost. The barrier's idle safety net contributes one setTimeout(0) per step delivery (cheap; the poll exits the first time pendingDeliveries hits 0), and the new yield adds another only when a delivery actually had to defer — i.e. only when two or more branch-deciding events land in the same drain window, which is rare and is precisely the case that was broken. A sequential single-step workflow pays neither. Still worth a look given the active inline-step perf work, and worth challenging if anyone sees a cheaper way to let a resumed branch quiesce than a macrotask.
  4. step_failed now holds pendingDeliveries across hydration (it did not before), so suspensions wait for a rejection to land. Intentional and consistent with step_completed, but it is a behaviour change beyond pure ordering.
  5. Whether the guarantee should be stated in the docs. What this establishes is: given a fixed delivery order, the userland interleaving that follows is deterministic, so pinning delivery order to log order is sufficient for replay determinism. The hop-count tests encode that. If reviewers agree it is the intended contract, it probably belongs somewhere more discoverable than a test file docstring.

🤖 Generated with Claude Code

Copilot AI review requested due to automatic review settings July 27, 2026 20:35
@pranaygp
pranaygp requested review from a team and ijjk as code owners July 27, 2026 20:35
@changeset-bot

changeset-bot Bot commented Jul 27, 2026

Copy link
Copy Markdown

🦋 Changeset detected

Latest commit: f9c1006

The changes in this PR will be included in the next version bump.

This PR includes changesets to release 16 packages
Name Type
@workflow/core Patch
@workflow/builders Patch
@workflow/cli Patch
@workflow/next Patch
@workflow/nitro Patch
@workflow/vitest Patch
@workflow/web-shared Patch
@workflow/web Patch
workflow Patch
@workflow/world-testing Patch
@workflow/astro Patch
@workflow/nest Patch
@workflow/nuxt Patch
@workflow/rollup Patch
@workflow/sveltekit Patch
@workflow/vite Patch

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 Jul 27, 2026

Copy link
Copy Markdown
Contributor

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

Project Deployment Actions Updated (UTC)
example-nextjs-workflow-turbopack Ready Ready Preview, Comment Jul 28, 2026 9:25pm
example-nextjs-workflow-webpack Ready Ready Preview, Comment Jul 28, 2026 9:25pm
example-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workbench-astro-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workbench-express-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workbench-fastify-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workbench-hono-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workbench-nestjs-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workbench-nitro-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workbench-nuxt-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workbench-sveltekit-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workbench-tanstack-start-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workbench-vite-workflow Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workflow-docs Ready Ready Preview, Comment, Open in v0 Jul 28, 2026 9:25pm
workflow-swc-playground Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workflow-tarballs Ready Ready Preview, Comment Jul 28, 2026 9:25pm
workflow-web Ready Ready Preview, Comment Jul 28, 2026 9:25pm

@github-actions

github-actions Bot commented Jul 27, 2026

Copy link
Copy Markdown
Contributor

📊 Workflow Benchmarks

commit f9c1006 · Tue, 28 Jul 2026 21:43:16 GMT · run logs

Backend: vercel · app: nextjs-turbopack

Metric Scenario Best (ms) P75 (ms) P90 (ms) P99 (ms) Samples
TTFS step 1099 (+55%) 🔻 1166 🔴 (+16%) 🔻 1174 🔴 (+16%) 🔻 1329 🔴 (-12%) 30
TTFS stream 1110 (+16%) 🔻 1162 🔴 (+18%) 🔻 1199 🔴 (+19%) 🔻 1423 🔴 (+35%) 🔻 30
TTFS hook + stream 602 (-50%) 💚 1598 🔴 (+24%) 🔻 1640 🔴 (+22%) 🔻 1734 🔴 (+7.7%) 30
STSO 1020 steps (1-20) 158 (-1.3%) 255 🔴 (-0.8%) 332 🔴 (+9.6%) 339 🔴 (-20%) 💚 19
STSO 1020 steps (101-120) 168 (-9.2%) 238 🔴 (-2.9%) 284 🔴 (+1.1%) 333 🔴 (-53%) 💚 19
STSO 1020 steps (1001-1020) 457 (-2.1%) 516 🔴 (-8.7%) 596 🔴 (-2.3%) 618 🔴 (-9.9%) 19
WO 1020 steps 406131 (+5.2%) 406131 (+5.2%) 406131 (+5.2%) 406131 (+5.2%) 1
SL stream latency 84 (+3.7%) 180 🔴 (+36%) 🔻 202 🔴 (+44%) 🔻 311 🔴 (+74%) 🔻 30
SO stream overhead (text) 89 (-12%) 146 (-19%) 💚 194 (-4.0%) 2193 🔴 (+777%) 🔻 30
SO stream overhead (structured) 85 (-14%) 144 (-11%) 180 (-7.7%) 360 (+66%) 🔻 30
📜 Previous results (5)

285f434

Tue, 28 Jul 2026 15:59:46 GMT · run logs

vercel / nextjs-turbopack

Metric Scenario Best (ms) P75 (ms) P90 (ms) P99 (ms) Samples
TTFS step 245 (-76%) 💚 969 🔴 (-18%) 💚 1320 🔴 (+9.4%) 1642 🔴 (+1.2%) 30
TTFS stream 236 (-76%) 💚 825 🔴 (-24%) 💚 1275 🔴 (+14%) 1405 🔴 (+22%) 🔻 30
TTFS hook + stream 334 (-68%) 💚 1153 🔴 (-17%) 💚 1463 🔴 (+3.2%) 1673 🔴 (+7.1%) 30
STSO 1020 steps (1-20) 194 (+11%) 393 🔴 (+18%) 🔻 720 🔴 (+74%) 🔻 1150 🔴 (+132%) 🔻 19
STSO 1020 steps (101-120) 199 (+21%) 🔻 261 🔴 (-17%) 💚 376 🔴 (±0%) 380 🔴 (-0.5%) 19
STSO 1020 steps (1001-1020) 533 (+6.4%) 596 🔴 (-3.7%) 629 🔴 (-7.8%) 632 🔴 (-33%) 💚 19
WO 1020 steps 415349 (-6.7%) 415349 (-6.7%) 415349 (-6.7%) 415349 (-6.7%) 1
SL stream latency 100 (-9.1%) 437 🔴 (+136%) 🔻 519 🔴 (+139%) 🔻 780 🔴 (+183%) 🔻 30
SO stream overhead (text) 161 (-8.0%) 351 🔴 (+13%) 1074 🔴 (+100%) 🔻 1875 🔴 (+9.1%) 30
SO stream overhead (structured) 186 (+66%) 🔻 1257 🔴 (+428%) 🔻 1607 🔴 (+439%) 🔻 2162 🔴 (+380%) 🔻 30

cc30335

Tue, 28 Jul 2026 01:35:15 GMT · run logs

vercel / nextjs-turbopack

Metric Scenario Best (ms) P75 (ms) P90 (ms) P99 (ms) Samples
TTFS step 256 (-73%) 💚 705 🔴 (-34%) 💚 1275 🔴 (-5.7%) 1395 🔴 (-5.5%) 30
TTFS stream 231 (-76%) 💚 836 🔴 (-20%) 💚 1237 🔴 (+16%) 🔻 1334 🔴 (+18%) 🔻 30
TTFS hook + stream 394 (-67%) 💚 1153 🔴 (-12%) 1491 🔴 (+10%) 1742 🔴 (+15%) 30
STSO 1020 steps (1-20) 174 (+32%) 🔻 326 🔴 (+28%) 🔻 562 🔴 (+107%) 🔻 645 🔴 (+122%) 🔻 19
STSO 1020 steps (101-120) 184 (+2.2%) 269 🔴 (+3.5%) 289 🔴 (-14%) 380 🔴 (-0.8%) 19
STSO 1020 steps (1001-1020) 519 (+13%) 598 🔴 (+9.3%) 656 🔴 (+6.3%) 668 🔴 (+7.2%) 19
WO 1020 steps 410369 (+8.6%) 410369 (+8.6%) 410369 (+8.6%) 410369 (+8.6%) 1
SL stream latency 136 (+72%) 🔻 303 🔴 (+121%) 🔻 392 🔴 (+161%) 🔻 488 🔴 (+92%) 🔻 30
SO stream overhead (text) 146 (+34%) 🔻 356 🔴 (+93%) 🔻 585 🔴 (+172%) 🔻 1445 🔴 (+337%) 🔻 30
SO stream overhead (structured) 111 (+0.9%) 365 🔴 (+98%) 🔻 643 🔴 (+104%) 🔻 2440 🔴 (+597%) 🔻 30

62f8c95

Tue, 28 Jul 2026 00:00:19 GMT · run logs

vercel / nextjs-turbopack

Metric Scenario Best (ms) P75 (ms) P90 (ms) P99 (ms) Samples
TTFS step 1271 (+72%) 🔻 1358 🔴 (+20%) 🔻 1384 🔴 (+14%) 1712 🔴 (+25%) 🔻 30
TTFS stream 345 (+9.9%) 1352 🔴 (+23%) 🔻 1376 🔴 (+20%) 🔻 1442 🔴 (+23%) 🔻 30
TTFS hook + stream 1505 (+19%) 🔻 1659 🔴 (+18%) 🔻 1678 🔴 (+15%) 1811 🔴 (+11%) 30
STSO 1020 steps (1-20) 192 (+13%) 282 🔴 (-6.6%) 332 🔴 (-5.7%) 441 🔴 (+16%) 🔻 19
STSO 1020 steps (101-120) 201 (+2.0%) 293 🔴 (-14%) 347 🔴 (-15%) 💚 388 🔴 (-22%) 💚 19
STSO 1020 steps (1001-1020) 487 (+0.8%) 566 🔴 (-1.4%) 670 🔴 (+3.7%) 936 🔴 (+42%) 🔻 19
WO 1020 steps 414344 (-5.6%) 414344 (-5.6%) 414344 (-5.6%) 414344 (-5.6%) 1
SL stream latency 108 (+16%) 🔻 165 🔴 (-1.8%) 206 🔴 (-12%) 651 🔴 (+157%) 🔻 30
SO stream overhead (text) 113 (-14%) 167 (-42%) 💚 189 (-47%) 💚 304 (-28%) 💚 30
SO stream overhead (structured) 110 (-19%) 💚 186 (-28%) 💚 218 (-22%) 💚 480 (+16%) 🔻 30

e7ae7b3

Mon, 27 Jul 2026 22:38:47 GMT · run logs

vercel / nextjs-turbopack

Metric Scenario Best (ms) P75 (ms) P90 (ms) P99 (ms) Samples
TTFS step 964 (+31%) 🔻 1275 🔴 (+13%) 1291 🔴 (+6.6%) 1312 🔴 (-4.0%) 30
TTFS stream 1207 (+284%) 🔻 1247 🔴 (+14%) 1254 🔴 (+9.6%) 1302 🔴 (+11%) 30
TTFS hook + stream 1437 (+13%) 1531 🔴 (+9.2%) 1569 🔴 (+7.4%) 1735 🔴 (+6.1%) 30
STSO 1020 steps (1-20) 171 (+0.6%) 258 🔴 (-15%) 274 🔴 (-22%) 💚 311 🔴 (-18%) 💚 19
STSO 1020 steps (101-120) 171 (-13%) 243 🔴 (-28%) 💚 297 🔴 (-27%) 💚 351 🔴 (-30%) 💚 19
STSO 1020 steps (1001-1020) 472 (-2.3%) 543 🔴 (-5.4%) 574 🔴 (-11%) 599 🔴 (-8.8%) 19
WO 1020 steps 379198 (-14%) 379198 (-14%) 379198 (-14%) 379198 (-14%) 1
SL stream latency 84 (-9.7%) 134 🔴 (-20%) 💚 148 🔴 (-37%) 💚 418 🔴 (+65%) 🔻 30
SO stream overhead (text) 107 (-18%) 💚 152 (-48%) 💚 162 (-54%) 💚 241 (-43%) 💚 30
SO stream overhead (structured) 99 (-27%) 💚 147 (-43%) 💚 176 (-37%) 💚 772 (+87%) 🔻 30

3fe83a1

Mon, 27 Jul 2026 21:13:57 GMT · run logs

vercel / nextjs-turbopack

Metric Scenario Best (ms) P75 (ms) P90 (ms) P99 (ms) Samples
TTFS step 1001 (+53%) 🔻 1348 🔴 (+14%) 1396 🔴 (-5.8%) 1472 🔴 (-5.4%) 30
TTFS stream 291 (+35%) 🔻 1393 🔴 (+22%) 🔻 1437 🔴 (+21%) 🔻 1534 🔴 (+10%) 30
TTFS hook + stream 1545 (+18%) 🔻 1634 🔴 (+12%) 1673 🔴 (+14%) 1694 🔴 (-5.5%) 30
STSO 1020 steps (1-20) 197 (-6.2%) 315 🔴 (+8.6%) 514 🔴 (+21%) 🔻 706 🔴 (+27%) 🔻 19
STSO 1020 steps (101-120) 219 (+4.8%) 283 🔴 (-4.1%) 312 🔴 (-7.7%) 559 🔴 (-9.8%) 19
STSO 1020 steps (1001-1020) 530 (+11%) 609 🔴 (+3.9%) 715 🔴 (+3.0%) 922 🔴 (+5.9%) 19
WO 1020 steps 439373 (-0.6%) 439373 (-0.6%) 439373 (-0.6%) 439373 (-0.6%) 1
SL stream latency 117 (+4.5%) 153 🔴 (-6.7%) 175 🔴 (-1.7%) 370 🔴 (+78%) 🔻 30
SO stream overhead (text) 127 (-20%) 💚 194 (-29%) 💚 228 (-30%) 💚 423 (-52%) 💚 30
SO stream overhead (structured) 136 (-6.8%) 188 (-53%) 💚 210 (-66%) 💚 405 (-86%) 💚 30
ℹ️ Metric definitions & methodology

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, 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 (clientStart) right before start(), so the CI runner’s request and its path through api.vercel.com sit outside every measured window. TTFS = in-deployment start() → first step body (turbo uses the in-process fast path, non-turbo the dispatch path), and includes the VQS dispatch hop plus any /flow cold start. STSO/WO are measured between step bodies on the deployment. SL is measured inside the workflow (parallel reader/writer steps), so it no longer includes the api.vercel.com read path.

Cold starts are kept in the numbers on purpose — they are part of real bursty-workload latency. The workbench deployment cold-starts the /flow invocation for a large fraction of runs, inflating P75+; the Best column shows the fastest (warm-start) sample for comparison.

@github-actions

github-actions Bot commented Jul 27, 2026

Copy link
Copy Markdown
Contributor

🧪 E2E Test Results

All tests passed

E2E Test Summary

Summary
Passed Failed Skipped Total
✅ ▲ Vercel Production 1455 0 239 1694
✅ 💻 Local Development 1621 0 227 1848
✅ 📦 Local Production 1621 0 227 1848
✅ 🐘 Local Postgres 1621 0 227 1848
✅ 🪟 Windows 154 0 0 154
✅ 📋 Other 1020 0 212 1232
✅ vercel-multi-region 27 0 0 27
Total 7519 0 1132 8651
Details by Category

✅ ▲ Vercel Production

App Passed Failed Skipped
✅ astro 126 0 28
✅ example 126 0 28
✅ express 126 0 28
✅ fastify 126 0 28
✅ hono 126 0 28
✅ nextjs-turbopack 151 0 3
✅ nextjs-webpack 151 0 3
✅ nitro 126 0 28
✅ nuxt 126 0 28
✅ sveltekit 145 0 9
✅ vite 126 0 28

✅ 💻 Local Development

App Passed Failed Skipped
✅ astro-stable 128 0 26
✅ express-stable 128 0 26
✅ fastify-stable 128 0 26
✅ hono-stable 128 0 26
✅ nextjs-turbopack-canary 135 0 19
✅ nextjs-turbopack-stable 154 0 0
✅ nextjs-webpack-canary 135 0 19
✅ nextjs-webpack-stable 154 0 0
✅ nitro-stable 128 0 26
✅ nuxt-stable 128 0 26
✅ sveltekit-stable 147 0 7
✅ vite-stable 128 0 26

✅ 📦 Local Production

App Passed Failed Skipped
✅ astro-stable 128 0 26
✅ express-stable 128 0 26
✅ fastify-stable 128 0 26
✅ hono-stable 128 0 26
✅ nextjs-turbopack-canary 135 0 19
✅ nextjs-turbopack-stable 154 0 0
✅ nextjs-webpack-canary 135 0 19
✅ nextjs-webpack-stable 154 0 0
✅ nitro-stable 128 0 26
✅ nuxt-stable 128 0 26
✅ sveltekit-stable 147 0 7
✅ vite-stable 128 0 26

✅ 🐘 Local Postgres

App Passed Failed Skipped
✅ astro-stable 128 0 26
✅ express-stable 128 0 26
✅ fastify-stable 128 0 26
✅ hono-stable 128 0 26
✅ nextjs-turbopack-canary 135 0 19
✅ nextjs-turbopack-stable 154 0 0
✅ nextjs-webpack-canary 135 0 19
✅ nextjs-webpack-stable 154 0 0
✅ nitro-stable 128 0 26
✅ nuxt-stable 128 0 26
✅ sveltekit-stable 147 0 7
✅ vite-stable 128 0 26

✅ 🪟 Windows

App Passed Failed Skipped
✅ nextjs-turbopack 154 0 0

✅ 📋 Other

App Passed Failed Skipped
✅ e2e-local-dev-nest-stable 128 0 26
✅ e2e-local-dev-tanstack-start- 128 0 26
✅ e2e-local-postgres-nest-stable 128 0 26
✅ e2e-local-postgres-tanstack-start- 128 0 26
✅ e2e-local-prod-nest-stable 128 0 26
✅ e2e-local-prod-tanstack-start- 128 0 26
✅ e2e-vercel-prod-nest 126 0 28
✅ e2e-vercel-prod-tanstack-start 126 0 28

✅ vercel-multi-region

App Passed Failed Skipped
✅ nextjs-turbopack 27 0 0

📋 View full workflow run

Copilot AI 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.

Pull request overview

Fixes a replay-divergence class in @workflow/core where step result delivery order could flip relative to wait completions / hook payloads across cold vs warm replays (due to hydration/memoization timing), leading to deterministic ULID allocation mismatches and CORRUPTED_EVENT_LOG.

Changes:

  • Extend the delivery-barrier registry to include step_completed / step_failed, and defer step/wait/hook deliveries behind relevant earlier-in-log deliveries via a centralized DEFER_BEHIND table.
  • Add an armed concept for hook barriers so buffered (unclaimed) hook payloads don’t incorrectly block step deliveries; arm them on claim().
  • Add a regression test that replays the same committed event log twice against a shared ReplayPayloadCache to reproduce cold/warm ordering skew.

Reviewed changes

Copilot reviewed 6 out of 6 changed files in this pull request and generated no comments.

Show a summary per file
File Description
packages/core/src/workflow/sleep.ts Update wait delivery deferral to include step deliveries via the new awaitEarlierDeliveries(ctx, idx, 'wait') behavior.
packages/core/src/workflow/hook.ts Register hook barriers armed/unarmed based on whether a consumer is already awaiting; arm buffered payloads on claim(); defer behind earlier waits/steps.
packages/core/src/step.ts Make step_completed and step_failed participate in delivery barriers, capturing hydrate outcome in-order but resolving/rejecting only after deferring behind earlier relevant deliveries.
packages/core/src/private.ts Add step as a delivery kind, introduce DEFER_BEHIND, armed barriers, and resolvesOnItsOwn to avoid ordering steps behind unclaimed buffered hook payloads.
packages/core/src/step-delivery-ordering.test.ts New cold/warm replay regression tests covering step-vs-wait and step-vs-hook ordering stability with a shared ReplayPayloadCache.
.changeset/step-delivery-ordering.md Patch changeset documenting the behavioral fix for deterministic delivery ordering and divergence prevention.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread packages/core/src/step.ts
Comment thread packages/core/src/private.ts
Comment thread packages/core/src/private.ts
@pranaygp

Copy link
Copy Markdown
Contributor Author

Heads-up for anyone who read an earlier revision of this branch: the fix changed materially after I tried to verify a claim I was about to make in the description, and found it false. Summarising so the diff isn't confusing.

The earlier revision was insufficient, and neither the repro tests nor the full suite could tell. I instrumented awaitEarlierDeliveries and in the hook case the step reported defers=0 — the hook's hydration slot runs first on the serial queue, and its detached resolve chain deregisters the barrier before the step's slot starts. The barrier was ordering nothing there. The test passed only because moving the step's resolve into a detached .then() adds one microtask hop, which happens to beat a minimal-hop consumer. Padding the consumer with a single extra await after it is resumed diverged again.

Two changes fix it properly:

  1. Capture the deferral set while consuming the event, not at the start of the hydration slot. Every event in a drain window is consumed before any slot runs, so all barriers are still visible (defers=1). Slot-start capture isn't just less deterministic, it's usually empty.
  2. Yield one macrotask after waiting. An earlier delivery being "delivered" only means its resolve() ran; the branch it woke may need arbitrarily many further hops before its next useStep call (a for await over a hook resumes the generator, settles the promise from next(), then runs the loop body). Only deliveries that actually deferred pay this, so the common single-delivery drain is unaffected.

And a mechanism correction to the shared test file's docstring, also from instrumentation: the for await hook case does not buffer its payload. All three hook cases consume hook_received with an awaiter already registered (promises.length === 1) and claim() never runs — entering for await calls next(), which reaches yield await this before the process.nextTick drain. The for await / await hook difference is purely consumer-side hop count. Buffering is real and load-bearing for the armed flag, but it is exercised by hook-sleep-interaction.test.ts's queued-payload cases, not by these.

step-delivery-hop-count.test.ts is the guard for all of this: consumers padded with 0/1/2/4/8/16 extra hops across step-vs-wait, step-vs-hook and step_failed-vs-wait. 0 of 18 pass on main; 3 of the 12 pre-macrotask cases pass on the earlier revision; 18 of 18 pass now.

@pranaygp

Copy link
Copy Markdown
Contributor Author

@TooTallNate handing this over to you — pausing the automated work here at a clean stopping point.

State of the branch (head e7ae7b374, single signed commit, CI running): the strengthened fix as described in the PR body — DEFER_BEHIND table with 'step' barriers, the armed asymmetry for unclaimed buffered hook payloads, deferral-set capture at event-consumption time, and the post-defer macrotask yield — plus the converged 5-test repro file (identical to #3137's modulo the two it.fails markers) and the hop-count guard suite (step-delivery-hop-count.test.ts: 0/12 on main, 3/12 with resolve-ordering only, 12/12 here).

Your review items are intentionally unaddressed and yours to take:

  1. BlockingDEFER_BEHIND.step omits 'step': agreed this needs a decision; the docblock's self-ordering argument predates the detached resolve.
  2. BlockingresolvesOnItsOwn exponential walk on the delivery hot path.
  3. Question — step-vs-abort ordering: abort-controller.ts resolves _setAborted in-slot with no barrier, so a deferred step result can be overtaken by a later-in-log abort.
  4. Non-blocking — no step_failed regression coverage (detached reject + newly holding pendingDeliveries across error hydration).

Companion repro #3137 is final and green (3 passed | 2 expected fail; the two markers are the live bug assertion). Merge-order options for the pair are written up in its description.

pranaygp and others added 2 commits July 27, 2026 16:35
…by event-log position

Two production runs on `@workflow/core@5.0.0-beta.36` burned all three
divergence-recovery replays at the same event and terminated with
CORRUPTED_EVENT_LOG:

  wrun_41KYJENABV0GSF5YTE9EETV5DD  (step vs wait)
  wrun_41KYJEE01S0GPC9RWT5MEKVCX8  (step vs hook)

  Replay divergence: step event step_created for step_X belongs to "A",
  but the current step consumer is "B"

`useStep` proxies draw deterministic ULIDs in invocation order, so the
ULID -> stepName allocation is a function of the order in which promise
resolutions are delivered to workflow code. The delivery-barrier registry
pinned that order to event-log position for hook payloads and wait
completions, but step results were delivered straight off the serial
`promiseQueue` — and their latency varies between replays of the SAME
invocation, because the first replay pays full hydration while later
replays memo-hit primitive results in the shared `ReplayPayloadCache`.
A step completion adjacent in the log to a `wait_completed` was therefore
delivered wait-first on a cold replay and step-first on a warm one;
whichever order the invocation that wrote the follow-up `step_created`
events happened to see became law, and every replay computing the other
order diverged permanently.

Step results and step failures now register a 'step' delivery barrier at
their event-log index and resolve from a detached continuation after every
relevant earlier-in-log delivery, mirroring the hook payload path:
hydration stays inside the serial queue slot (which also releases
`pendingDeliveries`), while the barrier wait and the resolve run off the
queue so a queue slot never blocks on a resolution the queue itself drives.
Waits and hook payloads likewise defer behind earlier step results.

Two details are what actually make the ordering hold, and both were found
by testing rather than by reading the code:

The deferral set is captured while CONSUMING the event, not at the start of
the hydration slot. Captured at slot start it is not merely less
deterministic, it is usually empty: an earlier delivery whose own slot runs
first on the serial queue has typically already resolved and deregistered
its barrier before the later slot begins, so the later delivery does not
defer at all. Every event in one drain window is consumed before any slot
runs, so consumption time sees all of them.

A delivery that had to wait then yields a macrotask before resolving. An
earlier delivery being "delivered" only means its `resolve()` ran; the
branch it woke may need arbitrarily many further microtask hops before it
reaches its next `useStep` call (a `for await` over a hook resumes the
generator, settles the promise from `next()`, and only then runs the loop
body). Ordering the `resolve()` calls alone therefore buys a fixed hop or
two of margin and leaves a hop-count race that holds only for the shortest
consumers; yielding a macrotask lets the earlier branch drain completely,
whatever its shape.

One asymmetry is load-bearing: a step result skips any earlier delivery
that will not resolve on its own, i.e. one blocked directly or
transitively on a buffered hook payload no consumer has claimed. Such a
payload is delivered only when the workflow next reads the hook, and
reaching that read commonly requires the step result itself, so gating the
step on it stalls the run until the barrier's idle safety net fires — which
then releases every delivery queued behind that payload at once and loses
the very race the ordering exists to protect. Waits and hooks keep gating
on unclaimed payloads, where waiting for the claim IS the guarantee.

Tests come in two files. `step-delivery-ordering.test.ts` is byte-identical
to the file in the repro-only companion PR #3137 apart from
two `it.fails` markers there (which let a repro-only branch have green CI);
`sed 's/it\.fails(/it(/g' | cmp` verifies it. Each of its five cases
replays one committed log twice through a shared `ReplayPayloadCache`, and
the two warm-replay cases fail on main with the production error text.

`step-delivery-hop-count.test.ts` exists because those five cases cannot
tell "delivered in log order" apart from "resolves a hop or two later than
before". It replays logs a live run legitimately produced — the live
invocation received the two events in separate deliveries, so the first
branch finished long before the second event existed — while the replay
receives both in one drain window, and pads the consumer with a varying
number of extra awaits so hop count is the only variable. It covers step
results against both wait completions and hook payloads, plus step
FAILURES against wait completions, since a rejection decides whether a
`catch` continuation runs and so which ULID the `useStep` there draws. All
18 cases fail on main; of the 12 that predate the macrotask, 9 still fail
with the resolve-ordering-only version of this fix; all 18 pass here.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Signed-off-by: Pranay Prakash <pranay.gp@gmail.com>
Follow-up on the step-delivery barrier work, addressing three cases the
registry did not yet cover. Each has a regression test in the new
`delivery-barrier-coverage.test.ts` that reproduces the production
`ReplayDivergenceError` when its fix is reverted.

- Step results now defer behind earlier STEP results. The old exclusion
  assumed the serial `promiseQueue` fixes step-vs-step order, which stopped
  holding once a step began resolving from a detached continuation instead
  of its queue slot: two steps consumed in different drain windows can
  disagree on their deferral set, and the earlier one — parked on the
  macrotask yield — gets overtaken.

- `sleep.ts` and `hook.ts` (waiting-consumer path) now capture their
  deferral at event-consumption time, as `step.ts` already does. Reading
  the registry after their queue work misses an earlier step or hook that
  delivered and retired its barrier in the meantime, skipping both the gate
  and the macrotask yield. The buffered hook payload path deliberately
  keeps evaluating at claim time; a consumption-time snapshot there stalls
  the e2e `hookWithSleepWorkflow`.

- Abort deliveries participate in the registry. `_setAborted` fires the
  signal's listeners, which may invoke a step and draw a ULID, so an abort
  is as branch-deciding as any other delivery.

Also memoizes `resolvesOnItsOwn`. The walk is exponential in the number of
live hook/wait barriers, and the registry is not bounded — a fan-out of
`Promise.race([hook, sleep])` branches accumulates one barrier per branch
per kind (49 measured for 24 branches). At 40 barriers a single scan took
92s before, and is instant after.
@TooTallNate

TooTallNate commented Jul 27, 2026

Copy link
Copy Markdown
Member

Picking this up per @pranaygp's handoff above — rebased onto latest main (d7553c4, picking up #3131 / #3094 / #3095) on top of @pranaygp's e7ae7b3, and pushed a second commit resolving my review. PR description has a new "Follow-up: remaining barrier gaps (commit 2)" section with the details; short version below.

All three review items addressed, plus one more the abort work surfaced. Everything is covered by packages/core/src/delivery-barrier-coverage.test.ts, and I verified each test fails when — and only when — its own fix is reverted, one at a time, so none of them is vacuous.

  1. DEFER_BEHIND.step now includes 'step'. The cross-drain window is real: I reproduced the production ReplayDivergenceError with a log a live run legitimately produces (stepA's worker writes step_completed just before the invocation resuming from a sleep writes step_created stepB, so the two completions land in separate drain windows on replay). The macrotask yield you added in e7ae7b3 actually sharpens this from a coin flip into a deterministic loss for the deferred step. Cost measured on a parallel fan-out: +1.3 ms flat, not O(N) — the idle safety net collapses the chain into one timer tick.

  2. resolvesOnItsOwn is memoized. A single scan over 40 alternating armed hook/wait barriers took 92 s of blocked event loop before; instant after. The registry isn't bounded — I measured 49 live barriers for a 24-branch Promise.race([hook, sleep(watchdog)]) fan-out, which is the o2flow shape.

  3. Aborts participate in the registry as a 'hook', always armed, resolving detached behind their deferral.

  4. New, found while doing 3: the "Coverage" argument you documented on step.ts — capture the deferral at event-consumption time, because a barrier that retires first makes the later delivery skip both the gate and the macrotask yield — applies symmetrically to sleep.ts and hook.ts, which were still reading the registry after their queue work. It's the exact mirror of step-delivery-hop-count.test.ts: a wait completion diverges at 8 extra consumer hops, a hook payload at 20. Fixed in both.

One thing worth flagging as a design note rather than a fix: I initially applied the same consumption-time capture to the buffered hook payload's claim() for consistency, and it broke the e2e hookWithSleepWorkflow — a buffered payload's delivery genuinely happens at claim time, so a consumption-time snapshot makes it wait on barriers from a moment it never participated in, stalling the second payload past the suspension. Reverted, and the reason is now a comment on claim(). The unit suite was green either way; only the full local e2e caught it. That's the second asymmetry in this file that only the buffered path needs, alongside the armed flag — worth keeping in mind for whoever extends this next.

On your scrutiny list: item 1 (the armed asymmetry) I think is right as written and the four hook-sleep-interaction tests are a good guard for it. Item 3 (the extra setTimeout(0)) I'd leave until the inline-step perf work has numbers — the fan-out measurement above suggests the timer count doesn't scale the way it looks like it should. Item 2 (arm() timing) I still couldn't break.

Verification: unit 75 files, 1614 passed | 3 expected fail; the 14 ordering-sensitive files 8x consecutively, identical every run; typecheck clean; Biome shows the same 8 pre-existing warnings as the unmodified tree. Full local e2e against a nextjs-turbopack dev server: 135/135. route-bundle-isolation fails when the three build-e2e suites share one vitest invocation, identically on the unmodified tree — cross-suite interference, not a regression.

Also dropped the SDK-drift reading of the Rollout caveat: runs are pinned to their originating immutable deployment on Vercel, so a run never replays across two @workflow/core versions.

@TooTallNate

TooTallNate commented Jul 27, 2026

Copy link
Copy Markdown
Member

Tarball soak test queued: vercel/o2flow#486 pins workflow to the preview tarball from this branch (immutable deployment, commit 62f8c95).

o2flow is currently throwing roughly one corrupted event log every 15–30 minutes, and its runFanoutTask uses exactly the Promise.race([hook, sleep(watchdog)]) fan-out shape this fix targets — so it's a far better signal than anything in our suites, which are green with or without large parts of this change.

On that branch: typecheck clean, 2248 tests pass, build succeeds, and DEFER_BEHIND.step is confirmed present in the installed tree rather than just the version string. Watching for corrupted-event-log faults stopping and resume_count dropping to 0 — and, on the other side, for any run that stalls instead, since a defect in delivery gating would show up that way rather than as corruption.

Correction on the plan: #486 has to merge to o2flow's main to prove anything. Vercel crons fire on production deployments only, so a preview never runs /api/scheduler/tick and produces zero workflow runs — the green preview only shows the tarball installs and the app builds. It's a time-boxed production experiment, reverted or replaced once we have an answer.

Runs are pinned to the deployment that started them, so it's a clean cutover: in-flight runs stay on beta.36, new runs get the fix. That also means this PR's "Rollout caveat" can't bite here — no run ever spans both versions.

If the soak holds, this merges and ships as a normal 5.0.0-beta.N, and o2flow swaps the tarball URL back to a version range.

Tracked in DPE-1721.

@github-actions

github-actions Bot commented Jul 28, 2026

Copy link
Copy Markdown
Contributor

Event Log Race Repro

851 of 1400 latest repro runs hit event-log regressions.

Run History

Metric 2026-07-28 02:23 UTC #1
logs
2026-07-28 03:53 UTC #2
logs / deploy
2026-07-28 16:47 UTC #1
logs / deploy
2026-07-28 21:56 UTC #1
logs / deploy
Result missing result file 728/1400 regressions 613/1224 regressions — partial (1224 of 1400 planned) 851/1400 regressions
Total 0 1400 1224 1400
completed 0 672 611 549
CORRUPTED_EVENT_LOG 0 169 214 851
USER_ERROR 0 0 0 0
RUNTIME_ERROR 0 0 0 0
stuck 0 559 399 0
other 0 0 0 0
infra 0 0 0 0
Config 1400 runs / step-storm 600, hook-storm 600, hook-sleep 200 / c40 / 6x8 1224 runs / step-storm 600, hook-storm 600, hook-sleep 200 / c40 / 6x8 1400 runs / step-storm 600, hook-storm 600, hook-sleep 200 / c40 / 6x8
Timing watchdog 2500ms / step 2200±250ms / stagger 400ms / poke 750ms / timeout 240000ms watchdog 2500ms / step 2200±250ms / stagger 400ms / poke 750ms / timeout 240000ms watchdog 2500ms / step 2200±250ms / stagger 400ms / poke 750ms / timeout 240000ms

Latest Scenario Breakdown

Scenario Total completed CORRUPTED_EVENT_LOG USER_ERROR RUNTIME_ERROR stuck other infra
step-storm 600 13 587 0 0 0 0 0
hook-storm 600 336 264 0 0 0 0 0
hook-sleep 200 200 0 0 0 0 0 0

Latest Non-Completed Runs

Scenario Attempt Outcome Status Error code Run
step-storm 1 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNAK0GWT62AT15TBB125
step-storm 13 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNF50GW2CZTQ22MAG00R
step-storm 17 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNGT0GNBRSQJ6AA01XQT
step-storm 25 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNHR0GRQPKEA55J6NQHG
step-storm 27 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNHZ0GM6DBAK1V1D28SX
step-storm 33 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNKV0GK4DP3FHPNWHZTT
step-storm 37 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNQY0GYZKHBTFVT252JW
step-storm 18 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNN10GW0ETR8695Q805P
step-storm 36 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNN90GHMYG24TR1NW3GE
step-storm 3 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNAK0GWT62AT15TBB127
step-storm 38 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNR20GMTVHHHNGXZJJVP
step-storm 35 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNN60GXRYTB3APZA3X3V
step-storm 2 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNAK0GWT62AT15TBB128
step-storm 7 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNDK0GG99KYM30SGX9FH
step-storm 11 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SND60GY5HVV09PJ82J0F
step-storm 14 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNFX0GTFTC0DQGA5H0JD
step-storm 12 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNBW0GVK9MPEVJR2G7ZA
step-storm 10 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNC10GWQ2KYT5XK7FMR8
step-storm 24 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNGY0GRTNDPWWVPP3V0H
step-storm 21 CORRUPTED_EVENT_LOG failed CORRUPTED_EVENT_LOG wrun_41KYN9SNHA0GNZKRCWX2VT5AJZ

Showing 20 of 851 non-completed runs.

@github-actions

Copy link
Copy Markdown
Contributor

Backport PR opened against stable: #3173. Merge conflicts were resolved by AI — please review carefully. (backport job run)

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.

4 participants