From 16cebe56693decd5c0085cb82e1e3bc4d265b195 Mon Sep 17 00:00:00 2001 From: Peter Steinberger Date: Wed, 8 Apr 2026 01:06:40 +0800 Subject: [PATCH] Tests: stabilize cron timeout regressions --- src/cron/service/timer.regression.test.ts | 367 ++++++++++++---------- 1 file changed, 200 insertions(+), 167 deletions(-) diff --git a/src/cron/service/timer.regression.test.ts b/src/cron/service/timer.regression.test.ts index 26ad40e3999..0cbeb8582ef 100644 --- a/src/cron/service/timer.regression.test.ts +++ b/src/cron/service/timer.regression.test.ts @@ -571,137 +571,159 @@ describe("cron service timer regressions", () => { }); it("aborts isolated runs when cron timeout fires", async () => { - vi.useRealTimers(); - const store = timerRegressionFixtures.makeStorePath(); - const scheduledAt = Date.parse("2026-02-15T13:00:00.000Z"); - const cronJob = createIsolatedRegressionJob({ - id: "abort-on-timeout", - name: "abort timeout", - scheduledAt, - schedule: { kind: "at", at: new Date(scheduledAt).toISOString() }, - payload: { kind: "agentTurn", message: "work", timeoutSeconds: FAST_TIMEOUT_SECONDS }, - state: { nextRunAtMs: scheduledAt }, - }); - await writeCronJobs(store.storePath, [cronJob]); + vi.useFakeTimers(); + try { + const store = timerRegressionFixtures.makeStorePath(); + const scheduledAt = Date.parse("2026-02-15T13:00:00.000Z"); + const cronJob = createIsolatedRegressionJob({ + id: "abort-on-timeout", + name: "abort timeout", + scheduledAt, + schedule: { kind: "at", at: new Date(scheduledAt).toISOString() }, + payload: { kind: "agentTurn", message: "work", timeoutSeconds: FAST_TIMEOUT_SECONDS }, + state: { nextRunAtMs: scheduledAt }, + }); + await writeCronJobs(store.storePath, [cronJob]); - let now = scheduledAt; - const abortAwareRunner = createAbortAwareIsolatedRunner(); - const state = createCronServiceState({ - cronEnabled: true, - storePath: store.storePath, - log: noopLogger, - nowMs: () => now, - enqueueSystemEvent: vi.fn(), - requestHeartbeatNow: vi.fn(), - runIsolatedAgentJob: vi.fn(async (params) => { - const result = await abortAwareRunner.runIsolatedAgentJob(params); - now += 5; - return result; - }), - }); + let now = scheduledAt; + const abortAwareRunner = createAbortAwareIsolatedRunner(); + const state = createCronServiceState({ + cronEnabled: true, + storePath: store.storePath, + log: noopLogger, + nowMs: () => now, + enqueueSystemEvent: vi.fn(), + requestHeartbeatNow: vi.fn(), + runIsolatedAgentJob: vi.fn(async (params) => { + const result = await abortAwareRunner.runIsolatedAgentJob(params); + now += 5; + return result; + }), + }); - await onTimer(state); + const timerPromise = onTimer(state); + await abortAwareRunner.waitForStart(); + await vi.advanceTimersByTimeAsync(Math.ceil(FAST_TIMEOUT_SECONDS * 1_000) + 10); + await timerPromise; - expect(abortAwareRunner.getObservedAbortSignal()?.aborted).toBe(true); - const job = state.store?.jobs.find((entry) => entry.id === "abort-on-timeout"); - expect(job?.state.lastStatus).toBe("error"); - expect(job?.state.lastError).toContain("timed out"); + expect(abortAwareRunner.getObservedAbortSignal()?.aborted).toBe(true); + const job = state.store?.jobs.find((entry) => entry.id === "abort-on-timeout"); + expect(job?.state.lastStatus).toBe("error"); + expect(job?.state.lastError).toContain("timed out"); + } finally { + vi.useRealTimers(); + } }); it("suppresses isolated follow-up side effects after timeout", async () => { - vi.useRealTimers(); - const store = timerRegressionFixtures.makeStorePath(); - const scheduledAt = Date.parse("2026-02-15T13:00:00.000Z"); - const enqueueSystemEvent = vi.fn(); + vi.useFakeTimers(); + try { + const store = timerRegressionFixtures.makeStorePath(); + const scheduledAt = Date.parse("2026-02-15T13:00:00.000Z"); + const enqueueSystemEvent = vi.fn(); - const cronJob = createIsolatedRegressionJob({ - id: "timeout-side-effects", - name: "timeout side effects", - scheduledAt, - schedule: { kind: "every", everyMs: 60_000, anchorMs: scheduledAt }, - payload: { kind: "agentTurn", message: "work", timeoutSeconds: FAST_TIMEOUT_SECONDS }, - state: { nextRunAtMs: scheduledAt }, - }); - await writeCronJobs(store.storePath, [cronJob]); + const cronJob = createIsolatedRegressionJob({ + id: "timeout-side-effects", + name: "timeout side effects", + scheduledAt, + schedule: { kind: "every", everyMs: 60_000, anchorMs: scheduledAt }, + payload: { kind: "agentTurn", message: "work", timeoutSeconds: FAST_TIMEOUT_SECONDS }, + state: { nextRunAtMs: scheduledAt }, + }); + await writeCronJobs(store.storePath, [cronJob]); - let now = scheduledAt; - const state = createCronServiceState({ - cronEnabled: true, - storePath: store.storePath, - log: noopLogger, - nowMs: () => now, - enqueueSystemEvent, - requestHeartbeatNow: vi.fn(), - runIsolatedAgentJob: vi.fn(async (params) => { - const abortSignal = params.abortSignal; - if (abortSignal?.aborted) { - now += 100; - throw new Error("aborted"); - } - await new Promise((resolve, reject) => { - const onAbort = () => { - abortSignal?.removeEventListener("abort", onAbort); + let now = scheduledAt; + const state = createCronServiceState({ + cronEnabled: true, + storePath: store.storePath, + log: noopLogger, + nowMs: () => now, + enqueueSystemEvent, + requestHeartbeatNow: vi.fn(), + runIsolatedAgentJob: vi.fn(async (params) => { + const abortSignal = params.abortSignal; + if (abortSignal?.aborted) { now += 100; - reject(new Error("aborted")); + throw new Error("aborted"); + } + await new Promise((resolve, reject) => { + const onAbort = () => { + abortSignal?.removeEventListener("abort", onAbort); + now += 100; + reject(new Error("aborted")); + }; + abortSignal?.addEventListener("abort", onAbort, { once: true }); + }); + return { + status: "ok" as const, + summary: "late-summary", + delivered: false, + error: + abortSignal?.aborted && typeof abortSignal.reason === "string" + ? abortSignal.reason + : undefined, }; - abortSignal?.addEventListener("abort", onAbort, { once: true }); - }); - return { - status: "ok" as const, - summary: "late-summary", - delivered: false, - error: - abortSignal?.aborted && typeof abortSignal.reason === "string" - ? abortSignal.reason - : undefined, - }; - }), - }); + }), + }); - await onTimer(state); + const timerPromise = onTimer(state); + await vi.advanceTimersByTimeAsync(Math.ceil(FAST_TIMEOUT_SECONDS * 1_000) + 10); + await timerPromise; - const jobAfterTimeout = state.store?.jobs.find((entry) => entry.id === "timeout-side-effects"); - expect(jobAfterTimeout?.state.lastStatus).toBe("error"); - expect(jobAfterTimeout?.state.lastError).toContain("timed out"); - expect(enqueueSystemEvent).not.toHaveBeenCalled(); + const jobAfterTimeout = state.store?.jobs.find( + (entry) => entry.id === "timeout-side-effects", + ); + expect(jobAfterTimeout?.state.lastStatus).toBe("error"); + expect(jobAfterTimeout?.state.lastError).toContain("timed out"); + expect(enqueueSystemEvent).not.toHaveBeenCalled(); + } finally { + vi.useRealTimers(); + } }); it("applies timeoutSeconds to startup catch-up isolated executions", async () => { - vi.useRealTimers(); - const store = timerRegressionFixtures.makeStorePath(); - const scheduledAt = Date.parse("2026-02-15T13:00:00.000Z"); - const cronJob = createIsolatedRegressionJob({ - id: "startup-timeout", - name: "startup timeout", - scheduledAt, - schedule: { kind: "at", at: new Date(scheduledAt).toISOString() }, - payload: { kind: "agentTurn", message: "work", timeoutSeconds: FAST_TIMEOUT_SECONDS }, - state: { nextRunAtMs: scheduledAt }, - }); - await writeCronJobs(store.storePath, [cronJob]); + vi.useFakeTimers(); + try { + const store = timerRegressionFixtures.makeStorePath(); + const scheduledAt = Date.parse("2026-02-15T13:00:00.000Z"); + const cronJob = createIsolatedRegressionJob({ + id: "startup-timeout", + name: "startup timeout", + scheduledAt, + schedule: { kind: "at", at: new Date(scheduledAt).toISOString() }, + payload: { kind: "agentTurn", message: "work", timeoutSeconds: FAST_TIMEOUT_SECONDS }, + state: { nextRunAtMs: scheduledAt }, + }); + await writeCronJobs(store.storePath, [cronJob]); - let now = scheduledAt; - const abortAwareRunner = createAbortAwareIsolatedRunner(); - const state = createCronServiceState({ - cronEnabled: true, - storePath: store.storePath, - log: noopLogger, - nowMs: () => now, - enqueueSystemEvent: vi.fn(), - requestHeartbeatNow: vi.fn(), - runIsolatedAgentJob: vi.fn(async (params) => { - const result = await abortAwareRunner.runIsolatedAgentJob(params); - now += 5; - return result; - }), - }); + let now = scheduledAt; + const abortAwareRunner = createAbortAwareIsolatedRunner(); + const state = createCronServiceState({ + cronEnabled: true, + storePath: store.storePath, + log: noopLogger, + nowMs: () => now, + enqueueSystemEvent: vi.fn(), + requestHeartbeatNow: vi.fn(), + runIsolatedAgentJob: vi.fn(async (params) => { + const result = await abortAwareRunner.runIsolatedAgentJob(params); + now += 5; + return result; + }), + }); - await runMissedJobs(state); + const catchupPromise = runMissedJobs(state); + await abortAwareRunner.waitForStart(); + await vi.advanceTimersByTimeAsync(Math.ceil(FAST_TIMEOUT_SECONDS * 1_000) + 10); + await catchupPromise; - expect(abortAwareRunner.getObservedAbortSignal()?.aborted).toBe(true); - const job = state.store?.jobs.find((entry) => entry.id === "startup-timeout"); - expect(job?.state.lastStatus).toBe("error"); - expect(job?.state.lastError).toContain("timed out"); + expect(abortAwareRunner.getObservedAbortSignal()?.aborted).toBe(true); + const job = state.store?.jobs.find((entry) => entry.id === "startup-timeout"); + expect(job?.state.lastStatus).toBe("error"); + expect(job?.state.lastError).toContain("timed out"); + } finally { + vi.useRealTimers(); + } }); it("respects abort signals while retrying one-shot main-session wake-now heartbeat runs", async () => { @@ -948,67 +970,78 @@ describe("cron service timer regressions", () => { }); it("outer cron timeout fires at configured timeoutSeconds, not at 1/3 (#29774)", async () => { - vi.useRealTimers(); - const store = timerRegressionFixtures.makeStorePath(); - const scheduledAt = Date.parse("2026-02-15T13:00:00.000Z"); - const timeoutSeconds = 0.01; - const cronJob = createIsolatedRegressionJob({ - id: "timeout-fraction-29774", - name: "timeout fraction regression", - scheduledAt, - schedule: { kind: "at", at: new Date(scheduledAt).toISOString() }, - payload: { kind: "agentTurn", message: "work", timeoutSeconds }, - state: { nextRunAtMs: scheduledAt }, - }); - await writeCronJobs(store.storePath, [cronJob]); + vi.useFakeTimers(); + try { + const store = timerRegressionFixtures.makeStorePath(); + const scheduledAt = Date.parse("2026-02-15T13:00:00.000Z"); + const timeoutSeconds = 0.03; + const cronJob = createIsolatedRegressionJob({ + id: "timeout-fraction-29774", + name: "timeout fraction regression", + scheduledAt, + schedule: { kind: "at", at: new Date(scheduledAt).toISOString() }, + payload: { kind: "agentTurn", message: "work", timeoutSeconds }, + state: { nextRunAtMs: scheduledAt }, + }); + await writeCronJobs(store.storePath, [cronJob]); - let now = scheduledAt; - const wallStart = Date.now(); - let abortWallMs: number | undefined; - let started = false; + vi.setSystemTime(scheduledAt); + let now = scheduledAt; + const wallStart = Date.now(); + let abortWallMs: number | undefined; + let started = false; - const state = createCronServiceState({ - cronEnabled: true, - storePath: store.storePath, - log: noopLogger, - nowMs: () => now, - enqueueSystemEvent: vi.fn(), - requestHeartbeatNow: vi.fn(), - runIsolatedAgentJob: vi.fn(async ({ abortSignal }: { abortSignal?: AbortSignal }) => { - started = true; - await new Promise((resolve) => { - if (!abortSignal) { - resolve(); - return; - } - if (abortSignal.aborted) { - abortWallMs = Date.now(); - resolve(); - return; - } - abortSignal.addEventListener( - "abort", - () => { + const state = createCronServiceState({ + cronEnabled: true, + storePath: store.storePath, + log: noopLogger, + nowMs: () => now, + enqueueSystemEvent: vi.fn(), + requestHeartbeatNow: vi.fn(), + runIsolatedAgentJob: vi.fn(async ({ abortSignal }: { abortSignal?: AbortSignal }) => { + started = true; + await new Promise((resolve) => { + if (!abortSignal) { + resolve(); + return; + } + if (abortSignal.aborted) { abortWallMs = Date.now(); resolve(); - }, - { once: true }, - ); - }); - now += 5; - return { status: "ok" as const, summary: "done" }; - }), - }); + return; + } + abortSignal.addEventListener( + "abort", + () => { + abortWallMs = Date.now(); + resolve(); + }, + { once: true }, + ); + }); + now += 5; + return { status: "ok" as const, summary: "done" }; + }), + }); - await onTimer(state); + const timerPromise = onTimer(state); + expect(started).toBe(true); - expect(started).toBe(true); - const elapsedMs = (abortWallMs ?? Date.now()) - wallStart; - expect(elapsedMs).toBeGreaterThanOrEqual(timeoutSeconds * 1000 * 0.55); + await vi.advanceTimersByTimeAsync(15); + expect(abortWallMs).toBeUndefined(); - const job = state.store?.jobs.find((entry) => entry.id === "timeout-fraction-29774"); - expect(job?.state.lastStatus).toBe("error"); - expect(job?.state.lastError).toContain("timed out"); + await vi.advanceTimersByTimeAsync(20); + await timerPromise; + + const elapsedMs = (abortWallMs ?? Date.now()) - wallStart; + expect(elapsedMs).toBeGreaterThanOrEqual(timeoutSeconds * 1_000); + + const job = state.store?.jobs.find((entry) => entry.id === "timeout-fraction-29774"); + expect(job?.state.lastStatus).toBe("error"); + expect(job?.state.lastError).toContain("timed out"); + } finally { + vi.useRealTimers(); + } }); it("keeps state updates when cron next-run computation throws after a successful run (#30905)", () => {