diff --git a/packages/server/scripts/supervisor.logging.test.ts b/packages/server/scripts/supervisor.logging.test.ts index 61255358f..643bad2d7 100644 --- a/packages/server/scripts/supervisor.logging.test.ts +++ b/packages/server/scripts/supervisor.logging.test.ts @@ -10,9 +10,15 @@ import { resolveSupervisorLogFile } from "./supervisor-log-config.js"; const repoRoot = path.resolve(fileURLToPath(new URL("../../..", import.meta.url))); const supervisorPath = fileURLToPath(new URL("./supervisor.ts", import.meta.url)); +interface SupervisorSuspension { + afterMs: number; + durationMs: number; +} + async function runSupervisorFixture(options: { workerSource: string; restartOnCrash?: boolean; + suspension?: SupervisorSuspension; timeoutMs?: number; }): Promise<{ code: number | null; @@ -52,10 +58,23 @@ async function runSupervisorFixture(options: { const startedAt = Date.now(); const child = spawn(process.execPath, ["--import", "tsx", runnerPath], { cwd: repoRoot, + detached: options.suspension !== undefined, env: { ...process.env }, stdio: ["ignore", "pipe", "pipe"], }); + if (options.suspension) { + const supervisorPid = child.pid; + if (supervisorPid === undefined) { + throw new Error("Supervisor fixture did not start"); + } + const { afterMs, durationMs } = options.suspension; + setTimeout(() => { + process.kill(-supervisorPid, "SIGSTOP"); + setTimeout(() => process.kill(-supervisorPid, "SIGCONT"), durationMs); + }, afterMs); + } + let stdout = ""; let stderr = ""; child.stdout.setEncoding("utf8"); @@ -241,6 +260,40 @@ describe("supervisor durable logging", () => { expect(result.log).not.toContain('"msg":"Worker heartbeat timed out; restarting worker"'); }, 10_000); + test.skipIf(isPlatform("win32"))( + "keeps a healthy worker alive after the host resumes from sleep", + async () => { + const result = await runSupervisorFixture({ + suspension: { afterMs: 1_000, durationMs: 16_000 }, + timeoutMs: 25_000, + workerSource: ` + import { existsSync, writeFileSync } from "node:fs"; + + const marker = process.argv[1] + ".started"; + if (!existsSync(marker)) { + writeFileSync(marker, "started"); + setInterval(() => { + process.send?.({ type: "paseo:worker-heartbeat" }); + }, 250); + setTimeout(() => { + process.send?.({ type: "paseo:shutdown", reason: "sleep_resume_test_complete" }); + }, 17_000); + } else { + process.send?.({ type: "paseo:shutdown", reason: "unexpected_sleep_restart" }); + } + setInterval(() => {}, 1_000); + `, + }); + + expect(result.code).toBe(0); + expect(result.signal).toBeNull(); + expect(result.log).toContain('"reason":"sleep_resume_test_complete"'); + expect(result.log).not.toContain('"reason":"unexpected_sleep_restart"'); + expect(result.log).not.toContain('"msg":"Worker heartbeat timed out; restarting worker"'); + }, + 30_000, + ); + test.skipIf(isPlatform("win32"))( "forces shutdown when a worker ignores SIGTERM", async () => { diff --git a/packages/server/scripts/supervisor.ts b/packages/server/scripts/supervisor.ts index 4554e8d54..c44f2d583 100644 --- a/packages/server/scripts/supervisor.ts +++ b/packages/server/scripts/supervisor.ts @@ -5,7 +5,7 @@ import { createStream as createRotatingFileStream } from "rotating-file-stream"; import { signalProcessTree } from "../src/utils/tree-kill.js"; const WORKER_HEARTBEAT_INTERVAL_MS = 1_000; -const WORKER_HEARTBEAT_TIMEOUT_MS = 15_000; +const WORKER_HEARTBEAT_MISSED_CHECK_LIMIT = 15; const WORKER_TERMINATION_GRACE_MS = 10_000; interface SupervisorLogFileOptions { @@ -250,7 +250,7 @@ export function runSupervisor(options: SupervisorOptions): SupervisorController } const currentChild = child; - let lastWorkerHeartbeatAt = Date.now(); + let missedWorkerHeartbeatChecks = 0; const heartbeat = setInterval(() => { const message: SupervisorHeartbeatMessage = { type: "paseo:supervisor-heartbeat" }; if (currentChild.connected) { @@ -271,12 +271,12 @@ export function runSupervisor(options: SupervisorOptions): SupervisorController if (child !== currentChild || restarting || shuttingDown) { return; } - const heartbeatAgeMs = Date.now() - lastWorkerHeartbeatAt; - if (heartbeatAgeMs < WORKER_HEARTBEAT_TIMEOUT_MS) { + missedWorkerHeartbeatChecks += 1; + if (missedWorkerHeartbeatChecks < WORKER_HEARTBEAT_MISSED_CHECK_LIMIT) { return; } writeLifecycleLog("Worker heartbeat timed out; restarting worker", { - heartbeatAgeMs, + missedHeartbeatChecks: missedWorkerHeartbeatChecks, supervisorPid: process.pid, workerPid: currentChild.pid ?? null, }); @@ -300,7 +300,7 @@ export function runSupervisor(options: SupervisorOptions): SupervisorController child.on("message", (msg: unknown) => { if (isWorkerHeartbeatMessage(msg)) { - lastWorkerHeartbeatAt = Date.now(); + missedWorkerHeartbeatChecks = 0; return; } const lifecycleMessage = parseLifecycleMessage(msg);