diff --git a/.changeset/tidy-buttons-swim.md b/.changeset/tidy-buttons-swim.md new file mode 100644 index 0000000000..d07ebeeecc --- /dev/null +++ b/.changeset/tidy-buttons-swim.md @@ -0,0 +1,5 @@ +--- +'@workflow/core': patch +--- + +Stop reporting replay divergence for an event the workflow is still on its way to consuming, by waiting for in-flight step and hook deliveries instead of a fixed delay diff --git a/packages/core/src/events-consumer.test.ts b/packages/core/src/events-consumer.test.ts index ecf828f728..c85a660ea6 100644 --- a/packages/core/src/events-consumer.test.ts +++ b/packages/core/src/events-consumer.test.ts @@ -1,7 +1,11 @@ import { withResolvers } from '@workflow/utils'; import type { Event } from '@workflow/world'; import { describe, expect, it, vi } from 'vitest'; -import { EventConsumerResult, EventsConsumer } from './events-consumer.js'; +import { + DEFERRED_CHECK_DELAY_MS, + EventConsumerResult, + EventsConsumer, +} from './events-consumer.js'; // Helper function to create mock events function createMockEvent(overrides: Partial = {}): Event { @@ -476,4 +480,83 @@ describe('EventsConsumer', () => { expect(onUnconsumedEvent).not.toHaveBeenCalled(); }); }); + + describe('delivery-idle gate', () => { + // An event nobody claims is only evidence of divergence once the workflow + // VM has stopped reacting. While a delivery is in flight the walk is + // simply ahead of the code that would register the consumer, so the check + // has to wait rather than time out. See `isDeliveryIdle` in private.ts. + it('should not fire the unconsumed check while a delivery is in flight', async () => { + const event = createMockEvent(); + const onUnconsumedEvent = vi.fn(); + let idle = false; + const consumer = new EventsConsumer([event], { + onUnconsumedEvent, + getPromiseQueue: () => Promise.resolve(), + isDeliveryIdle: () => idle, + }); + + consumer.subscribe( + vi.fn().mockReturnValue(EventConsumerResult.NotConsumed) + ); + + // Several times the window the check would otherwise have fired in. + await new Promise((resolve) => + setTimeout(resolve, DEFERRED_CHECK_DELAY_MS * 5) + ); + expect(onUnconsumedEvent).not.toHaveBeenCalled(); + + idle = true; + await vi.waitFor(() => { + expect(onUnconsumedEvent).toHaveBeenCalledWith(event); + }); + }); + + it('should let a consumer registered during the wait claim the event', async () => { + const event = createMockEvent(); + const onUnconsumedEvent = vi.fn(); + let idle = false; + const consumer = new EventsConsumer([event], { + onUnconsumedEvent, + getPromiseQueue: () => Promise.resolve(), + isDeliveryIdle: () => idle, + }); + + consumer.subscribe( + vi.fn().mockReturnValue(EventConsumerResult.NotConsumed) + ); + await new Promise((resolve) => + setTimeout(resolve, DEFERRED_CHECK_DELAY_MS * 2) + ); + + // What the in-flight delivery was on its way to doing: resume workflow + // code that subscribes the consumer this event belongs to. + consumer.subscribe(vi.fn().mockReturnValue(EventConsumerResult.Finished)); + idle = true; + + await vi.waitFor(() => { + expect(consumer.eventIndex).toBe(1); + }); + await new Promise((resolve) => + setTimeout(resolve, DEFERRED_CHECK_DELAY_MS * 2) + ); + expect(onUnconsumedEvent).not.toHaveBeenCalled(); + }); + + it('should fire without delay for an event no delivery is waiting on', async () => { + const event = createMockEvent(); + const unconsumedReceived = withResolvers(); + const consumer = new EventsConsumer([event], { + onUnconsumedEvent: unconsumedReceived.resolve, + getPromiseQueue: () => Promise.resolve(), + isDeliveryIdle: () => true, + }); + + consumer.subscribe( + vi.fn().mockReturnValue(EventConsumerResult.NotConsumed) + ); + + expect(await unconsumedReceived.promise).toEqual(event); + }); + }); }); diff --git a/packages/core/src/events-consumer.ts b/packages/core/src/events-consumer.ts index cd2469747f..45b86099a0 100644 --- a/packages/core/src/events-consumer.ts +++ b/packages/core/src/events-consumer.ts @@ -1,6 +1,14 @@ import type { Event } from '@workflow/world'; import { eventsLogger } from './logger.js'; +/** + * Delay before firing the deferred unconsumed-event check after the promise + * queue has drained. Must be long enough for cross-VM microtask chains to + * propagate (resolve in host → workflow code in VM → subscribe call back + * in host). Any subscribe() arriving during this window cancels the check. + */ +export const DEFERRED_CHECK_DELAY_MS = 100; + export enum EventConsumerResult { /** * Callback consumed the event, but should not be removed from the callbacks list @@ -40,6 +48,16 @@ export interface EventsConsumerOptions { * deserialization delays the resolve() that triggers the next subscribe(). */ getPromiseQueue: () => Promise; + /** + * Whether no data delivery is in flight (`isDeliveryIdle` in private.ts). + * The unconsumed-event check waits for this before it fires: a delivery in + * flight means the workflow VM is mid-reaction, and an event it has not + * claimed yet is an event it has not reached yet. + * + * Defaults to always-idle so the tests that drive a consumer with no + * orchestrator context keep the pre-existing timing. + */ + isDeliveryIdle?: () => boolean; } export class EventsConsumer { @@ -49,6 +67,7 @@ export class EventsConsumer { private onConsumedEvent?: (event: Event) => void; private onUnconsumedEvent: (event: Event) => void; private getPromiseQueue: () => Promise; + private isDeliveryIdle: () => boolean; private pendingUnconsumedCheck: Promise | null = null; private pendingUnconsumedTimeout: ReturnType | null = null; private unconsumedCheckVersion = 0; @@ -59,6 +78,7 @@ export class EventsConsumer { this.onConsumedEvent = options.onConsumedEvent; this.onUnconsumedEvent = options.onUnconsumedEvent; this.getPromiseQueue = options.getPromiseQueue; + this.isDeliveryIdle = options.isDeliveryIdle ?? (() => true); } /** @@ -185,22 +205,70 @@ export class EventsConsumer { ) .then(() => this.getPromiseQueue()) .then(() => { - // Use a delayed setTimeout after the queue drains. The delay must be - // long enough for promise chains to propagate across the VM boundary - // (from resolve() in the host context through to the workflow code - // calling subscribe() in the VM context). Node.js does not guarantee - // that setTimeout(0) fires after all cross-context microtasks settle, - // so we use a small but non-zero delay. Any subscribe() call that - // arrives during this window will cancel the check via version - // invalidation + clearTimeout. - this.pendingUnconsumedTimeout = setTimeout(() => { - this.pendingUnconsumedTimeout = null; - if (this.unconsumedCheckVersion === checkVersion) { - this.pendingUnconsumedCheck = null; - this.onUnconsumedEvent(currentEvent); - } - }, 100); + // Wait out any delivery still in flight before starting the timer. + // The queue draining says the host has no hydration work left; it + // does not say the VM has finished reacting to what was hydrated. + this.whenDeliveryIdle(checkVersion, () => { + // Use a delayed setTimeout once deliveries are idle. The delay must + // be long enough for promise chains to propagate across the VM + // boundary (from resolve() in the host context through to the + // workflow code calling subscribe() in the VM context). Node.js + // does not guarantee that setTimeout(0) fires after all + // cross-context microtasks settle, so we use a small but non-zero + // delay. Any subscribe() call that arrives during this window will + // cancel the check via version invalidation + clearTimeout. + this.pendingUnconsumedTimeout = setTimeout(() => { + this.pendingUnconsumedTimeout = null; + if (this.unconsumedCheckVersion === checkVersion) { + this.pendingUnconsumedCheck = null; + this.onUnconsumedEvent(currentEvent); + } + }, DEFERRED_CHECK_DELAY_MS); + }); }); } } + + /** + * Run `fn` once no data delivery is in flight, polling the way + * `scheduleWhenIdle` does: let the promise queue drain, re-check a timer + * tick later, repeat. + * + * Without this the check is a bet that every delivery the walk is running + * ahead of lands inside a fixed window. Consumption is synchronous while the + * resolution it triggers is not: a step result hydrates in the host, resolves + * from a detached continuation behind `awaitEarlierDeliveries`, and only then + * does VM code run far enough to subscribe the next consumer. Replaying a + * batch of N parallel step results leaves N-1 of them on that detached path + * with the queue already drained, so the walk sits on the ordered event the + * VM is about to draw and the window is the only thing standing between a + * healthy run and `ReplayDivergenceError`. On a backend whose deliveries take + * longer than the window, that bet loses. + * + * Termination is `hasParkedCommittedDelivery`'s: it counts only deliveries + * that resolve on their own, so nothing here can gate its own retirement. A + * genuinely orphaned event has no delivery to wait on and reaches `fn` on the + * first poll. + */ + private whenDeliveryIdle(checkVersion: number, fn: () => void): void { + const poll = () => { + this.pendingUnconsumedTimeout = null; + if (this.unconsumedCheckVersion !== checkVersion) { + return; + } + if (this.isDeliveryIdle()) { + fn(); + return; + } + this.getPromiseQueue().then(() => { + if (this.unconsumedCheckVersion !== checkVersion) { + return; + } + // Held in the same field the fired check uses so subscribe() cancels a + // poll in progress exactly as it cancels the check itself. + this.pendingUnconsumedTimeout = setTimeout(poll, 0); + }); + }; + poll(); + } } diff --git a/packages/core/src/private.ts b/packages/core/src/private.ts index 5762a50fe5..00fe62eeae 100644 --- a/packages/core/src/private.ts +++ b/packages/core/src/private.ts @@ -527,12 +527,7 @@ function hasParkedCommittedDelivery(ctx: WorkflowOrchestratorContext): boolean { } /** - * Schedule a callback to fire only after all pending data deliveries - * (step results, hook payloads) and async deserialization have completed. - * Uses a polling loop: setTimeout(0) → check pendingDeliveries and the - * barrier registry → if anything is still in flight, wait for promiseQueue → - * repeat. This handles the multi-round delivery pattern where each hook - * payload delivery cycle appends new async work to the promiseQueue. + * Whether no data delivery (step result, hook payload) is in flight right now. * * "In flight" is two distinct windows, each with its own guard: * `pendingDeliveries > 0` covers hydration inside the serial queue slots, and @@ -540,6 +535,25 @@ function hasParkedCommittedDelivery(ctx: WorkflowOrchestratorContext): boolean { * releasing that counter and the delivery's `resolve()` actually running — * deliberately outside `pendingDeliveries` (see step.ts), and invisible to it. * + * Anything that decides a replay is over, or that a replay went wrong, has to + * consult this first: while it is false the workflow VM is mid-reaction, so + * what it has and has not done yet says nothing about the run. Two callers + * read it, for the two such decisions: {@link scheduleWhenIdle} for the + * suspension, and the events consumer's unconsumed-event check for divergence. + */ +export function isDeliveryIdle(ctx: WorkflowOrchestratorContext): boolean { + return ctx.pendingDeliveries === 0 && !hasParkedCommittedDelivery(ctx); +} + +/** + * Schedule a callback to fire only after all pending data deliveries + * (step results, hook payloads) and async deserialization have completed. + * Uses a polling loop: setTimeout(0) → check pendingDeliveries and the + * barrier registry → if anything is still in flight, wait for promiseQueue → + * repeat. This handles the multi-round delivery pattern where each hook + * payload delivery cycle appends new async work to the promiseQueue. What + * counts as in flight is {@link isDeliveryIdle}. + * * The initial `setTimeout(0)` macrotask is load-bearing and must NOT be * downgraded to a microtask (`queueMicrotask`/`Promise.resolve().then`). * `pendingDeliveries` only guards the host-side hydration window; between a @@ -557,7 +571,7 @@ export function scheduleWhenIdle( fn: () => void ): void { const check = () => { - if (ctx.pendingDeliveries > 0 || hasParkedCommittedDelivery(ctx)) { + if (!isDeliveryIdle(ctx)) { // A delivery is still hydrating, or is committed but parked behind its // deferral (whose resolve runs on a detached timer, not this queue). // Either way: let the queue drain, then re-check a timer tick later. diff --git a/packages/core/src/unconsumed-check-delivery-idle.test.ts b/packages/core/src/unconsumed-check-delivery-idle.test.ts new file mode 100644 index 0000000000..cfbf68cfdb --- /dev/null +++ b/packages/core/src/unconsumed-check-delivery-idle.test.ts @@ -0,0 +1,137 @@ +import { withResolvers } from '@workflow/utils'; +import type { Event } from '@workflow/world'; +import { describe, expect, it, vi } from 'vitest'; +import { EventConsumerResult, EventsConsumer } from './events-consumer.js'; +import type { WorkflowOrchestratorContext } from './private.js'; +import { isDeliveryIdle } from './private.js'; + +/** + * The events consumer walks the log synchronously; the resolutions that walk + * triggers do not resolve synchronously. A step result hydrates in the host + * and only then does VM code run far enough to `subscribe()` the consumer for + * the next event. So the walk routinely sits on an ordered event + * (`step_created`, `wait_created`) that nobody has claimed yet while the + * workflow is mid-flight on its way to claiming it. + * + * The unconsumed-event check used to resolve that by waiting a fixed + * `DEFERRED_CHECK_DELAY_MS` after the promise queue drained, which is a bet + * that every delivery lands inside the window. Replaying a batch of N parallel + * step results loses it: the queue drains with deliveries still in flight, and + * the check declares `ReplayDivergenceError` against a log the very same + * replay goes on to reproduce exactly. + * + * These tests pin the guard on the divergence path, using the production + * predicate rather than a mock: a delivery still in flight must hold the check + * off however long it takes, and the check must still fire for an event no + * delivery is waiting on. + */ + +function createEvent(overrides: Partial = {}): Event { + return { + id: 'event-1', + workflow_run_id: 'run-1', + event_type: 'step_created', + event_data: {}, + sequence_number: 1, + created_at: new Date(), + ...overrides, + } as unknown as Event; +} + +/** + * The slice of the orchestrator context that `isDeliveryIdle` reads. + * Everything else a replay carries is irrelevant to whether a delivery is in + * flight. + */ +function createDeliveryContext(): WorkflowOrchestratorContext { + const promiseQueueHolder = { current: Promise.resolve() }; + return { + pendingDeliveries: 0, + pendingDeliveryBarriers: new Map(), + get promiseQueue() { + return promiseQueueHolder.current; + }, + set promiseQueue(value: Promise) { + promiseQueueHolder.current = value; + }, + } as unknown as WorkflowOrchestratorContext; +} + +describe('unconsumed-event check against in-flight deliveries', () => { + it('does not declare divergence while a payload is hydrating', async () => { + const ctx = createDeliveryContext(); + const event = createEvent(); + const onUnconsumedEvent = vi.fn(); + const consumer = new EventsConsumer([event], { + onUnconsumedEvent, + getPromiseQueue: () => ctx.promiseQueue, + isDeliveryIdle: () => isDeliveryIdle(ctx), + }); + + // A delivery in flight: hydration inside a serial queue slot. + ctx.pendingDeliveries++; + + consumer.subscribe( + vi.fn().mockReturnValue(EventConsumerResult.NotConsumed) + ); + + // Several times the window the check would otherwise have fired in, so + // the run survives only if the check waits for the delivery rather than + // for the clock. + await new Promise((resolve) => setTimeout(resolve, 500)); + expect(onUnconsumedEvent).not.toHaveBeenCalled(); + + ctx.pendingDeliveries--; + await vi.waitFor(() => { + expect(onUnconsumedEvent).toHaveBeenCalledWith(event); + }); + }); + + it('lets a consumer registered during the wait claim the event', async () => { + const ctx = createDeliveryContext(); + const event = createEvent(); + const onUnconsumedEvent = vi.fn(); + const consumer = new EventsConsumer([event], { + onUnconsumedEvent, + getPromiseQueue: () => ctx.promiseQueue, + isDeliveryIdle: () => isDeliveryIdle(ctx), + }); + + ctx.pendingDeliveries++; + + consumer.subscribe( + vi.fn().mockReturnValue(EventConsumerResult.NotConsumed) + ); + + await new Promise((resolve) => setTimeout(resolve, 250)); + expect(onUnconsumedEvent).not.toHaveBeenCalled(); + + // What the in-flight delivery was on its way to doing: resume workflow + // code that subscribes the consumer this event belongs to. + ctx.pendingDeliveries--; + consumer.subscribe(vi.fn().mockReturnValue(EventConsumerResult.Finished)); + + await vi.waitFor(() => { + expect(consumer.eventIndex).toBe(1); + }); + await new Promise((resolve) => setTimeout(resolve, 250)); + expect(onUnconsumedEvent).not.toHaveBeenCalled(); + }); + + it('still declares divergence for an event no delivery is waiting on', async () => { + const ctx = createDeliveryContext(); + const event = createEvent(); + const unconsumedReceived = withResolvers(); + const consumer = new EventsConsumer([event], { + onUnconsumedEvent: unconsumedReceived.resolve, + getPromiseQueue: () => ctx.promiseQueue, + isDeliveryIdle: () => isDeliveryIdle(ctx), + }); + + consumer.subscribe( + vi.fn().mockReturnValue(EventConsumerResult.NotConsumed) + ); + + expect(await unconsumedReceived.promise).toEqual(event); + }); +}); diff --git a/packages/core/src/workflow.ts b/packages/core/src/workflow.ts index 2d79cda6e3..417e611c63 100644 --- a/packages/core/src/workflow.ts +++ b/packages/core/src/workflow.ts @@ -15,6 +15,7 @@ import type { QueueItem } from './global.js'; import { ENOTSUP, WorkflowSuspension } from './global.js'; import { runtimeLogger } from './logger.js'; import type { WorkflowOrchestratorContext } from './private.js'; +import { isDeliveryIdle } from './private.js'; import { getPortLazy } from './runtime/get-port-lazy.js'; import { dehydrateWorkflowReturnValue, @@ -142,6 +143,11 @@ export async function runWorkflow( // by step/hook/sleep callbacks as events are processed. const promiseQueueHolder = { current: Promise.resolve() }; + // Same reason as the queue holder: the consumer is built before the context + // whose delivery state it has to read. Idle until the context exists, which + // is before any delivery can be registered against it. + const deliveryIdleHolder = { current: (): boolean => true }; + const eventsConsumer = new EventsConsumer(events, { onConsumedEvent: (event) => { updateTimestamp(+event.createdAt); @@ -155,6 +161,7 @@ export async function runWorkflow( ); }, getPromiseQueue: () => promiseQueueHolder.current, + isDeliveryIdle: () => deliveryIdleHolder.current(), }); const workflowContext: WorkflowOrchestratorContext = { @@ -179,6 +186,8 @@ export async function runWorkflow( stepHydrationCache, }; + deliveryIdleHolder.current = () => isDeliveryIdle(workflowContext); + // Consume run lifecycle events - these are structural events that don't // need special handling in the workflow, but must be consumed to advance // past them in the event log