diff --git a/tests/runner-e2e/process-tree-owner.test.ts b/tests/runner-e2e/process-tree-owner.test.ts index 4f32f088ca7..862ff8ba998 100644 --- a/tests/runner-e2e/process-tree-owner.test.ts +++ b/tests/runner-e2e/process-tree-owner.test.ts @@ -1,6 +1,6 @@ import { spawn, type ChildProcess } from "node:child_process"; import { expect, it } from "vitest"; -import { createProcessTreeOwner } from "./process-tree-owner.js"; +import { createProcessTreeOwner, stopOwnedProcessTree } from "./process-tree-owner.js"; import { readProcessTable, type ProcessObservation } from "./process-tree.js"; function row(pid: number, parentPid: number, processGroupId: number, started = `start-${pid}`, state = "S"): ProcessObservation { @@ -209,3 +209,74 @@ it.skipIf(process.platform === "win32")("keeps EPERM fatal while the group still await expect(f.owner.signal("SIGKILL")).rejects.toThrow("kill EPERM"); } finally { f.owner.stopObserving(); } }); + +function turnoverFixture(uncertainReads: number) { + // Server 100 owns runner group 200. Between two inspections the observed + // runner exits and a straggler nobody saw start (201) is left in group 200, + // reparented to init: its identity is unproven, so it must never be signaled. + const settledTable = () => [row(process.pid, 1, 10)]; + let table = [row(process.pid, 1, 10), row(100, process.pid, 100), row(200, 100, 200)]; + const killed: NodeJS.Signals[] = []; + const signals: Array<[number, NodeJS.Signals]> = []; + const child = { pid: 100, exitCode: null as number | null, signalCode: null as NodeJS.Signals | null, + kill: (signal: NodeJS.Signals) => { killed.push(signal); return true; } }; + let stopping = false; + let uncertain = 0; + const owner = createProcessTreeOwner(child as unknown as ChildProcess, { + readTable: async () => { + if (!stopping) return table; + if (uncertain < uncertainReads) { + uncertain += 1; + return [row(process.pid, 1, 10), row(201, 1, 200, "unseen-start")]; + } + child.exitCode = 0; + return settledTable(); + }, + signalGroup: (pid, signal) => { signals.push([pid, signal]); }, + }); + return { owner, child: child as unknown as ChildProcess, signals, killed, stop: () => { stopping = true; table = settledTable(); } }; +} + +it.skipIf(process.platform === "win32")("waits out a briefly uncertain group under load without signaling it", async () => { + const f = turnoverFixture(3); + try { + await f.owner.observe(); + f.stop(); + await stopOwnedProcessTree(f.child, f.owner, 2_000, 500); + expect(f.signals.filter(([pid]) => pid === 200)).toEqual([]); + expect(f.killed).toEqual([]); + } finally { f.owner.stopObserving(); } +}); + +it.skipIf(process.platform === "win32")("still fails without signaling the uncertain group when the uncertainty outlasts the deadline", async () => { + const f = turnoverFixture(Number.POSITIVE_INFINITY); + try { + await f.owner.observe(); + f.stop(); + await expect(stopOwnedProcessTree(f.child, f.owner, 300, 100)).rejects.toThrow("identity became uncertain"); + expect(f.signals).toEqual([]); + } finally { f.owner.stopObserving(); } +}); + +it.skipIf(process.platform === "win32")("keeps an uncertainty that starts at SIGKILL escalation inside one forced window", async () => { + // The launcher ignores grace; its runner group turns over only once grace has expired. + const gracefulMs = 300, forcedMs = 300; + const self = row(process.pid, 1, 10); + let stopAt: number | null = null; + const signals: Array<[number, NodeJS.Signals]> = []; + const child = { pid: 100, exitCode: null as number | null, signalCode: null as NodeJS.Signals | null, kill: () => true }; + const owner = createProcessTreeOwner(child as unknown as ChildProcess, { + readTable: async () => stopAt === null || Date.now() - stopAt < gracefulMs + ? [self, row(100, process.pid, 100), row(200, 100, 200)] + : [self, row(100, process.pid, 100), row(201, 1, 200, "unseen-start")], + signalGroup: (pid, signal) => { signals.push([pid, signal]); }, + }); + try { + await owner.observe(); + stopAt = Date.now(); + await expect(stopOwnedProcessTree(child as unknown as ChildProcess, owner, gracefulMs, forcedMs)).rejects.toThrow("identity became uncertain"); + const elapsed = Date.now() - stopAt; + expect(elapsed).toBeLessThan(gracefulMs + forcedMs + 250); + expect(signals.filter(([, signal]) => signal === "SIGKILL")).toEqual([]); + } finally { owner.stopObserving(); } +}); diff --git a/tests/runner-e2e/process-tree-owner.ts b/tests/runner-e2e/process-tree-owner.ts index ed12bf10d72..8fcbed6aae5 100644 --- a/tests/runner-e2e/process-tree-owner.ts +++ b/tests/runner-e2e/process-tree-owner.ts @@ -28,6 +28,26 @@ export function restartProcessStartMatches(observed: string, expected: string, p : actualTime === expectedTime; } +export const UNCERTAIN_GROUP_IDENTITY = "Owned process group identity became uncertain"; + +/** + * Under load or during a graceful drain a whole group can turn over between + * two inspections: its observed members exit and a member nobody saw start + * is left for a moment, reparented away from every owned anchor. Its identity + * is unproven, so the owner refuses to signal anything. Re-run the step until + * a later inspection settles it or the deadline passes, never signaling + * meanwhile; a straggler that outlives the deadline keeps the original error. + */ +export async function settleUncertainIdentity(step: () => Promise, until: () => number, pollMs = 100): Promise { + for (;;) { + try { return await step(); } + catch (error) { + if (!String(error).includes(UNCERTAIN_GROUP_IDENTITY) || Date.now() >= until()) throw error; + await new Promise(resolve => setTimeout(resolve, pollMs)); + } + } +} + export function createProcessTreeOwner(root: ChildProcess, options: { readTable?: () => Promise; signalGroup?: (pid: number, signal: NodeJS.Signals) => void; @@ -67,7 +87,13 @@ export function createProcessTreeOwner(root: ChildProcess, options: { const lost = groups.filter(group => !retained.includes(group) && next.some(row => row.processGroupId === group.processGroupId && running(row))); const uncertain = lost.filter(group => next.some(row => row.processGroupId === group.processGroupId && running(row) && !ownedNow.has(row.pid))); - if (uncertain.length) throw new Error(`Owned process group identity became uncertain: ${uncertain.map(group => group.processGroupId).join(",")}`); + if (uncertain.length) { + // Name the unproven members so the next occurrence identifies the process. + const ids = new Set(uncertain.map(group => group.processGroupId)); + const members = next.filter(row => ids.has(row.processGroupId) && running(row) && !ownedNow.has(row.pid)) + .map(row => `pid=${row.pid} ppid=${row.parentPid} pgid=${row.processGroupId} kind=${row.kind} started=${row.started}`); + throw new Error(`${UNCERTAIN_GROUP_IDENTITY}: ${[...ids].join(",")} (unowned members: ${members.join("; ")})`); + } const refreshed = refreshContinuouslyLiveProcessGroups([...retained, ...lost], next) .filter(group => group.processGroupId !== callerGroup); const anchors = refreshed.flatMap(group => group.members.map(member => member.pid)); @@ -251,25 +277,36 @@ export async function stopOwnedProcessTree( const wait = (ms: number) => new Promise(resolve => setTimeout(resolve, ms)); const deadline = Date.now() + gracefulMs; const phase: { gracefulSent: boolean; forcedDeadline?: number } = { gracefulSent: false }; + // Under load a whole group can turn over between two inspections: its + // observed members exit and a member nobody saw start is left behind, + // reparented away from every owned anchor. Its identity is then unproven, + // so the owner refuses to signal anything. That state is usually brief (the + // straggler exits with its group), so wait within the same deadline for a + // later inspection to settle it, never signaling meanwhile. If it persists, + // the original error stands. + const settled = settleUncertainIdentity; try { if (process.platform === "win32") { await stopKnownDirectChild(child, phase, deadline, forcedMs, gracefulSignal); return; } - const stopped = async () => { - await owner.observe(); + const stopped = async (until: () => number) => { + await settled(() => owner.observe(), until); return (child.exitCode !== null || child.signalCode !== null) && owner.liveGroups().length === 0; }; + const graceDeadline = () => deadline; + const forcedDeadline = () => phase.forcedDeadline!; do { - await owner.signalGracefully(gracefulSignal); + await settled(() => owner.signalGracefully(gracefulSignal), graceDeadline); phase.gracefulSent ||= owner.directGraceDelivered(); - if (await stopped()) return; + if (await stopped(graceDeadline)) return; await wait(50); } while (Date.now() < deadline); - await owner.signal("SIGKILL"); + // One forced window covers the escalation retry, the stop check and any fallback. phase.forcedDeadline = Date.now() + forcedMs; + await settled(() => owner.signal("SIGKILL"), forcedDeadline); do { - if (await stopped()) return; + if (await stopped(forcedDeadline)) return; await wait(50); } while (Date.now() < phase.forcedDeadline); throw new Error("Observed launcher descendants remained after bounded cleanup"); diff --git a/tests/runner-e2e/server-stop.test.ts b/tests/runner-e2e/server-stop.test.ts index 1655146b30c..dd5572e49b7 100644 --- a/tests/runner-e2e/server-stop.test.ts +++ b/tests/runner-e2e/server-stop.test.ts @@ -6,7 +6,7 @@ import path from "node:path"; import { afterEach, expect, it } from "vitest"; import { createRunnerE2EServerStopper, runnerE2EServerDetached } from "./server-stop.js"; import { readProcessTable } from "./process-tree.js"; -import { createProcessTreeOwner, stopOwnedProcessTree } from "./process-tree-owner.js"; +import { createProcessTreeOwner, stopOwnedProcessTree, UNCERTAIN_GROUP_IDENTITY } from "./process-tree-owner.js"; import { runnerE2ETypeScriptProcessArgs } from "./web-server-command.js"; const children: ChildProcess[] = []; @@ -375,3 +375,58 @@ it.skipIf(process.platform === "win32")("crashes the owned controller and detach expect(() => process.kill(neighbor.pid!, 0)).not.toThrow(); } finally { await stop.stopAll(); } }); + +it.skipIf(process.platform === "win32")("waits out a provider group that is briefly unproven during the graceful drain", async () => { + const { entry } = await fixture(); + const child = start(entry); + await once(child, "message"); + let uncertainInspections = 0; + let owner: ReturnType | undefined; + const messages: unknown[] = []; + child.on("message", message => { + messages.push(message); + // The provider group turns over while the server drains: three inspections cannot prove it. + if (message === "stopping") uncertainInspections = 3; + }); + const stop = createRunnerE2EServerStopper({ + gracefulTimeoutMs: 5_000, forcedTimeoutMs: 2_000, + hasSpawnError: () => false, markExpectedStop: () => {}, log: () => {}, + createOwner: candidate => { + owner = createProcessTreeOwner(candidate); + return { ...owner, observe: async () => { + if (uncertainInspections > 0) { + uncertainInspections -= 1; + if (uncertainInspections === 0 && child.connected) child.send("finish"); + throw new Error(`${UNCERTAIN_GROUP_IDENTITY}: 16058 (unowned members: pid=16070 ppid=1 pgid=16058 kind=node started=x)`); + } + await owner!.observe(); + } }; + }, + }); + try { + await stop(child); + expect(messages).toEqual(["stopping", "close-complete"]); + expect([child.exitCode, child.signalCode]).toEqual([0, null]); + } finally { owner?.stopObserving(); } +}); + +it.skipIf(process.platform === "win32")("still fails safely when a group stays unproven past the drain deadline", async () => { + const { entry } = await fixture(`process.on('SIGTERM', () => {}); process.send('ready'); setInterval(() => {}, 1000);`); + const child = start(entry); + await once(child, "message"); + const groupSignals: number[] = []; + let stopping = false; + const owner = createProcessTreeOwner(child, { signalGroup: pid => { groupSignals.push(pid); } }); + const uncertain = { ...owner, observe: async () => { + if (stopping) throw new Error(`${UNCERTAIN_GROUP_IDENTITY}: 16058 (unowned members: pid=16070 ppid=1 pgid=16058 kind=node started=x)`); + await owner.observe(); + } }; + try { + await uncertain.observe(); + stopping = true; + const stop = createRunnerE2EServerStopper({ gracefulTimeoutMs: 200, forcedTimeoutMs: 200, + hasSpawnError: () => false, markExpectedStop: () => {}, log: () => {}, createOwner: () => uncertain }); + await expect(stop(child)).rejects.toThrow(/identity became uncertain: 16058 \(unowned members: pid=16070/); + expect(groupSignals).toEqual([]); + } finally { owner.stopObserving(); if (child.exitCode === null && child.signalCode === null) child.kill("SIGKILL"); } +}); diff --git a/tests/runner-e2e/server-stop.ts b/tests/runner-e2e/server-stop.ts index a74cff18614..32a523443a7 100644 --- a/tests/runner-e2e/server-stop.ts +++ b/tests/runner-e2e/server-stop.ts @@ -1,5 +1,5 @@ import type { ChildProcess } from "node:child_process"; -import { createProcessTreeOwner, incompleteTreeFallback, type RestartRunnerIdentity } from "./process-tree-owner.js"; +import { createProcessTreeOwner, incompleteTreeFallback, settleUncertainIdentity, type RestartRunnerIdentity } from "./process-tree-owner.js"; // The wrapper receives Playwright's group signal; only it signals Paperclip. export const runnerE2EServerDetached = process.platform !== "win32"; @@ -43,12 +43,16 @@ export function createRunnerE2EServerStopper(options: { } async function stopOnce(child: ChildProcess, state: State, signal: NodeJS.Signals, restarting = false) { state.gracefulDeadline ??= Date.now() + options.gracefulTimeoutMs; - await state.owner.observe(); + // A provider group that tears itself down during the drain can be briefly + // unproven; wait within the phase deadline, never signaling it meanwhile. + const grace = () => state.gracefulDeadline!; + const observe = (until: () => number) => settleUncertainIdentity(() => state.owner.observe(), until); + await observe(grace); if (!exited(child) && !state.gracefulSent) { state.gracefulSent = child.kill(signal); } while (Date.now() < state.gracefulDeadline) { - await state.owner.observe(); + await observe(grace); if (restarting && state.finalRequested) throw new Error("Final shutdown interrupted controller restart"); if (exited(child)) { if (restarting) { @@ -59,7 +63,7 @@ export function createRunnerE2EServerStopper(options: { // The leader is gone. Retire only descendants whose start identities // we observed while they belonged to this server, including private groups. const unsignaled = new Set((restarting ? [...state.owner.restartCleanupGroups()] : state.owner.liveGroups().map(group => group.processGroupId)).filter(pid => !state.groupSignals.has(pid))); - for (const pid of await state.owner.signal("SIGTERM", unsignaled)) state.groupSignals.add(pid); + for (const pid of await settleUncertainIdentity(() => state.owner.signal("SIGTERM", unsignaled), grace)) state.groupSignals.add(pid); } await wait(25); } @@ -68,11 +72,12 @@ export function createRunnerE2EServerStopper(options: { options.log(`\nPaperclip did not stop within ${options.gracefulTimeoutMs}ms; sending SIGKILL\n`); state.escalationLogged = true; } - if (runnerE2EServerDetached) await state.owner.signal("SIGKILL"); - else if (!exited(child)) child.kill("SIGKILL"); state.forcedDeadline ??= finalForcedDeadline ?? Date.now() + options.forcedTimeoutMs; + const forced = () => state.forcedDeadline!; + if (runnerE2EServerDetached) await settleUncertainIdentity(() => state.owner.signal("SIGKILL"), forced); + else if (!exited(child)) child.kill("SIGKILL"); do { - await state.owner.observe(); + await observe(forced); if (exited(child) && !state.owner.liveGroups().length) { state.owner.stopObserving(); return; } await wait(25); } while (Date.now() < state.forcedDeadline);