From 0499513435f0cc47716497ca1fa8dfba4c0c7ea7 Mon Sep 17 00:00:00 2001 From: Dotta Date: Wed, 30 Sep 2026 10:57:15 -0500 Subject: [PATCH] fix(runner-e2e): bound inspection failure and graceful delivery races Keep direct-child fallback bounded when process inspection fails, preserve incomplete cleanup evidence, and select graceful owners from the delivery snapshot without signaling already-covered descendants again. Co-Authored-By: Paperclip --- tests/runner-e2e/README.md | 6 +- tests/runner-e2e/launch.ts | 23 +++- tests/runner-e2e/process-tree-owner.test.ts | 58 +++++++++- tests/runner-e2e/process-tree-owner.ts | 112 +++++++++++++++----- tests/runner-e2e/process-tree.ts | 6 +- tests/runner-e2e/server-stop.test.ts | 54 +++++++++- tests/runner-e2e/server-stop.ts | 25 +++-- 7 files changed, 235 insertions(+), 49 deletions(-) diff --git a/tests/runner-e2e/README.md b/tests/runner-e2e/README.md index adbd7496a8..16df504182 100644 --- a/tests/runner-e2e/README.md +++ b/tests/runner-e2e/README.md @@ -1103,7 +1103,11 @@ Launcher cancellation first signals its outer group, so Playwright and the wrapp own graceful server shutdown. It allows 45 seconds for that chain before bounded 5-second forced cleanup of revalidated descendants. Normal launcher exit uses the same retained descendant inventory. Zombies count as stopped; an unavailable or -uncertain identity inspection fails cleanup instead of granting signal authority. +uncertain identity inspection triggers bounded direct-child-only retirement and +still fails the tree audit. Failed cleanup preserves the temporary state. Graceful +owners are selected from the same validated table used for delivery; ESRCH allows +selection of a surviving owner, while a delivered signal covers that owner's +existing descendants through the grace window even if the owner exits first. Everyday restart and Stop scenarios exempt only their recorded cancellation, graceful-shutdown interruption, or process-loss outcome. A later adapter error diff --git a/tests/runner-e2e/launch.ts b/tests/runner-e2e/launch.ts index ea74bf8aea..0492112083 100644 --- a/tests/runner-e2e/launch.ts +++ b/tests/runner-e2e/launch.ts @@ -290,10 +290,13 @@ async function runProcess( let childSettled = false; let postResultStallError: string | null = null; let boundedCleanup: Promise | undefined; + let cleanupSettled!: () => void; + const cleanupFinished = new Promise(resolve => { cleanupSettled = () => resolve(1); }); const stopChildTree = (_diagnostic?: ProcessTreeDiagnostic) => { if (boundedCleanup) return; boundedCleanup = stopOwnedProcessTree(child, processOwner) - .then(() => null, error => error instanceof Error ? error.message : String(error)); + .then(() => null, error => error instanceof Error ? error.message : String(error)) + .finally(cleanupSettled); activeProcessCleanup.set(child.pid!, boundedCleanup); }; activeProcessTerminators.set(child.pid, stopChildTree); @@ -345,7 +348,7 @@ async function runProcess( }, timeoutMs); timer?.unref(); let spawnError: string | null = null; - const exitCode = await new Promise((resolve, reject) => { + const childExit = new Promise((resolve, reject) => { child.once("error", reject); child.once("exit", (code) => { childSettled = true; @@ -356,6 +359,7 @@ async function runProcess( spawnError = error instanceof Error ? error.message : String(error); return 1; }); + const exitCode = await Promise.race([childExit, cleanupFinished]); if (timer) clearTimeout(timer); if (completionPoll) clearInterval(completionPoll); // Even a successful launcher exit can leave an already-observed detached @@ -363,6 +367,13 @@ async function runProcess( stopChildTree(); const processCleanupError = await boundedCleanup!; processOwner.stopObserving(); + // Even a failed direct-child kill must not hold cancellation forever or let + // inherited pipes write into an ended log. The cleanup error remains fatal. + if (processCleanupError) { + child.stdout?.destroy(); + child.stderr?.destroy(); + if (child.exitCode === null && child.signalCode === null) child.unref(); + } if (child.pid) { activeProcessGroups.delete(child.pid); activeProcessCleanup.delete(child.pid); @@ -468,6 +479,7 @@ async function runAttempt(input: { const publishedResults: RunnerE2EResult[] = []; const publishedResultPaths = new Map(); let attemptSecrets: string[] = []; + let processCleanupFailed = false; try { const paperclipHome = path.join(temporaryRoot, "paperclip-home"); const workspace = path.join(temporaryRoot, "workspace"); @@ -579,6 +591,7 @@ async function runAttempt(input: { ), options.ui || options.debug, ); + processCleanupFailed = processResult.processCleanupError !== null; const processFailure = processResult.spawnError ? `Playwright failed to start: ${processResult.spawnError}` : processResult.timedOut @@ -780,9 +793,11 @@ async function runAttempt(input: { } return [...publishedResults]; } finally { - reapNewDetachedDarwinSharedMemory(sharedMemoryBaseline); + if (!processCleanupFailed) reapNewDetachedDarwinSharedMemory(sharedMemoryBaseline); let cleanupError: unknown; - if ( + if (processCleanupFailed) { + cleanupError = new Error(`Preserving temporary state after incomplete process cleanup: ${temporaryRoot}`); + } else if ( temporaryRoot.startsWith(`${os.tmpdir()}${path.sep}paperclip-runner-e2e-`) ) { for (let cleanupAttempt = 1; cleanupAttempt <= 3; cleanupAttempt += 1) { diff --git a/tests/runner-e2e/process-tree-owner.test.ts b/tests/runner-e2e/process-tree-owner.test.ts index a5b9849674..b3fa3b4543 100644 --- a/tests/runner-e2e/process-tree-owner.test.ts +++ b/tests/runner-e2e/process-tree-owner.test.ts @@ -1,7 +1,7 @@ -import type { ChildProcess } from "node:child_process"; +import { spawn, type ChildProcess } from "node:child_process"; import { expect, it } from "vitest"; import { createProcessTreeOwner } from "./process-tree-owner.js"; -import type { ProcessObservation } from "./process-tree.js"; +import { readProcessTable, type ProcessObservation } from "./process-tree.js"; function row(pid: number, parentPid: number, processGroupId: number, started = `start-${pid}`, state = "S"): ProcessObservation { return { pid, parentPid, processGroupId, started, state, kind: "node" }; @@ -64,3 +64,57 @@ it.skipIf(process.platform === "win32")("sends launcher grace only to the root w expect(f.signals.slice(1).map(([pid]) => pid).sort()).toEqual([200, 300]); } finally { f.owner.stopObserving(); } }); + +it.skipIf(process.platform === 'win32')('reselects a vanished owner only when no graceful signal was delivered', async () => { + let table = [row(process.pid, 1, 10), row(100, process.pid, 100), row(200, 100, 200)]; + const child = { pid: 100, exitCode: null as number | null, signalCode: null }; + const delivered: number[] = []; + let reads = 0; + let stopping = false; + const owner = createProcessTreeOwner(child as ChildProcess, { + readTable: async () => { + if (stopping && ++reads === 2) { child.exitCode = 0; table = [row(process.pid, 1, 10), row(200, 1, 200)]; } + return table; + }, + signalGroup: (pid, signal) => { + expect(signal).toBe('SIGTERM'); + if (pid === 100) { + child.exitCode = 0; table = [row(process.pid, 1, 10), row(200, 1, 200)]; + throw Object.assign(new Error('vanished'), { code: 'ESRCH' }); + } + delivered.push(pid); table = [row(process.pid, 1, 10)]; + }, + }); + try { + await owner.observe(); stopping = true; + const { stopOwnedProcessTree } = await import('./process-tree-owner.js'); + await stopOwnedProcessTree(child as ChildProcess, owner, 150, 100); + expect(delivered).toEqual([200]); + } finally { owner.stopObserving(); } +}); + + +it.skipIf(process.platform === "win32")("rejects an overflowing inspector instead of returning a partial identity table", async () => { + const inspector = spawn(process.execPath, ["-e", "process.stdout.write('x'.repeat(2 * 1024 * 1024)); setInterval(() => {}, 1000)"], { + stdio: ["ignore", "pipe", "ignore"], + }); + const exited = new Promise(resolve => inspector.once("exit", () => resolve())); + try { + expect(await readProcessTable(() => inspector)).toBeNull(); + await exited; + expect(inspector.signalCode).toBe("SIGKILL"); + } finally { if (inspector.exitCode === null && inspector.signalCode === null) inspector.kill("SIGKILL"); } +}); + +it.skipIf(process.platform === 'win32')('bounds fallback even when the known direct child cannot be killed', async () => { + const signals: NodeJS.Signals[] = []; + const child = { pid: 100, exitCode: null, signalCode: null, + kill: (signal: NodeJS.Signals) => { signals.push(signal); return false; } } as ChildProcess; + const owner = createProcessTreeOwner(child, { readTable: async () => null, + signalGroup: () => { throw new Error('must not signal an unobserved group'); } }); + try { + const { stopOwnedProcessTree } = await import('./process-tree-owner.js'); + await expect(stopOwnedProcessTree(child, owner, 10, 10)).rejects.toThrow('Known direct child remained'); + expect(signals).toEqual(['SIGTERM', 'SIGKILL']); + } finally { owner.stopObserving(); } +}); diff --git a/tests/runner-e2e/process-tree-owner.ts b/tests/runner-e2e/process-tree-owner.ts index 3301d0885b..a5da0dbbd7 100644 --- a/tests/runner-e2e/process-tree-owner.ts +++ b/tests/runner-e2e/process-tree-owner.ts @@ -13,6 +13,7 @@ export function createProcessTreeOwner(root: ChildProcess, options: { let table: ProcessObservation[] = []; let rootStarted: string | undefined; let observing: Promise | undefined; + const covered = new Set(); const readTable = options.readTable ?? readProcessTable; const signalGroup = options.signalGroup ?? ((pid, signal) => process.kill(-pid, signal)); const exited = () => root.exitCode !== null || root.signalCode !== null || !root.pid; @@ -39,7 +40,10 @@ export function createProcessTreeOwner(root: ChildProcess, options: { const byGroup = new Map(refreshed.map(group => [group.processGroupId, group])); for (const pid of anchors) { for (const group of observeDescendantProcessTree(next, pid).groups) { - if (group.processGroupId !== callerGroup) byGroup.set(group.processGroupId, group); + if (group.processGroupId !== callerGroup) { + byGroup.set(group.processGroupId, group); + if (covered.has(next.find(row => row.pid === pid)!.processGroupId)) covered.add(group.processGroupId); + } } } groups = [...byGroup.values()]; @@ -56,8 +60,7 @@ export function createProcessTreeOwner(root: ChildProcess, options: { function liveGroups() { return groups.filter(group => table.some(row => row.processGroupId === group.processGroupId && running(row))); } - async function signal(signal: NodeJS.Signals, selected?: ReadonlySet) { - await observe(); + function signalSnapshot(signal: NodeJS.Signals, selected?: ReadonlySet) { const currentProcessGroupId = table.find(row => row.pid === process.pid)?.processGroupId ?? null; if (currentProcessGroupId === null) throw new Error("Cleanup caller group identity is unavailable"); const live = liveGroups(); @@ -66,11 +69,15 @@ export function createProcessTreeOwner(root: ChildProcess, options: { for (const pid of ordered) { if (selected && !selected.has(pid)) continue; try { signalGroup(pid, signal); } - catch (error) { if ((error as NodeJS.ErrnoException).code !== "ESRCH") throw error; } + catch (error) { if ((error as NodeJS.ErrnoException).code !== "ESRCH") throw error; else continue; } signaled.push(pid); } return signaled; } + async function signal(signal: NodeJS.Signals, selected?: ReadonlySet) { + await observe(); + return signalSnapshot(signal, selected); + } function gracefulRoots() { const live = liveGroups(); const ids = new Set(live.map(group => group.processGroupId)); @@ -90,10 +97,57 @@ export function createProcessTreeOwner(root: ChildProcess, options: { return false; })).map(group => group.processGroupId)); } - return { observe, signal, liveGroups, gracefulRoots, stopObserving: () => { if (timer) clearInterval(timer); } }; + let graceComplete = false; + let directGraceDelivered = false; + async function signalGracefully() { + if (graceComplete) return; + await observe(); + // Choose and deliver from one validated table. ESRCH grants no ownership + // coverage: the next grace poll can select that branch's surviving owner. + const selected = new Set([...gracefulRoots()].filter(pid => !covered.has(pid))); + const delivered = signalSnapshot("SIGTERM", selected); + for (const pid of delivered) { + if (pid === root.pid) directGraceDelivered = true; + covered.add(pid); + for (const member of table.filter(row => row.processGroupId === pid)) { + for (const group of observeDescendantProcessTree(table, member.pid).groups) covered.add(group.processGroupId); + } + } + // Never reselect descendants after their owner received grace, even if it + // exits before their asynchronous close completes. + graceComplete = selected.size > 0 && delivered.length === selected.size; + } + return { observe, signal, liveGroups, gracefulRoots, signalGracefully, + directGraceDelivered: () => directGraceDelivered, stopObserving: () => { if (timer) clearInterval(timer); } }; } +/** Inspection failure grants no group authority. The unreaped ChildProcess + * handle still owns its direct child, so retire only that child within the + * original grace deadline, then report the incomplete tree audit. */ +export async function stopKnownDirectChild(child: ChildProcess, phase: { gracefulSent: boolean; forcedDeadline?: number }, + deadline: number, forcedMs: number, signal: NodeJS.Signals = "SIGTERM") { + const exited = () => child.exitCode !== null || child.signalCode !== null || !child.pid; + const wait = () => new Promise(resolve => setTimeout(resolve, 25)); + if (!exited() && !phase.gracefulSent) { + phase.gracefulSent = child.kill(signal); + } + while (!exited() && Date.now() < deadline) await wait(); + if (exited()) return; + child.kill("SIGKILL"); + phase.forcedDeadline ??= Date.now() + forcedMs; + while (!exited() && Date.now() < phase.forcedDeadline) await wait(); + if (!exited()) throw new Error("Known direct child remained after bounded fallback"); +} + +export async function incompleteTreeFallback(error: unknown, child: ChildProcess, + phase: { gracefulSent: boolean; forcedDeadline?: number }, deadline: number, forcedMs: number) { + let fallbackError: unknown; + try { await stopKnownDirectChild(child, phase, deadline, forcedMs); } + catch (failure) { fallbackError = failure; } + throw new Error(`Owned tree cleanup incomplete: ${String(error)}${fallbackError ? `; ${String(fallbackError)}` : ""}`); +} + /** Give the launcher/wrapper chain sole graceful-signal ownership, then retire * only still-observed descendants. Used on normal exit as well as cancellation. */ export async function stopOwnedProcessTree( @@ -103,28 +157,32 @@ export async function stopOwnedProcessTree( forcedMs = 5_000, ): Promise { const wait = (ms: number) => new Promise(resolve => setTimeout(resolve, ms)); - if (process.platform === "win32") { - if (child.exitCode === null && child.signalCode === null) child.kill("SIGTERM"); - } else { - await owner.observe(); - await owner.signal("SIGTERM", owner.gracefulRoots()); - } - const stopped = async () => { - await owner.observe(); - return (child.exitCode !== null || child.signalCode !== null) && owner.liveGroups().length === 0; - }; const deadline = Date.now() + gracefulMs; - while (Date.now() < deadline) { - if (await stopped()) return; - await wait(50); + const phase: { gracefulSent: boolean; forcedDeadline?: number } = { gracefulSent: false }; + try { + if (process.platform === "win32") { + await stopKnownDirectChild(child, phase, deadline, forcedMs); + return; + } + const stopped = async () => { + await owner.observe(); + return (child.exitCode !== null || child.signalCode !== null) && owner.liveGroups().length === 0; + }; + do { + await owner.signalGracefully(); + phase.gracefulSent ||= owner.directGraceDelivered(); + if (await stopped()) return; + await wait(50); + } while (Date.now() < deadline); + await owner.signal("SIGKILL"); + phase.forcedDeadline = Date.now() + forcedMs; + do { + if (await stopped()) return; + await wait(50); + } while (Date.now() < phase.forcedDeadline); + throw new Error("Observed launcher descendants remained after bounded cleanup"); + } catch (error) { + phase.gracefulSent ||= owner.directGraceDelivered(); + await incompleteTreeFallback(error, child, phase, deadline, forcedMs); } - if (process.platform === "win32") { - if (child.exitCode === null && child.signalCode === null) child.kill("SIGKILL"); - } else await owner.signal("SIGKILL"); - const forcedDeadline = Date.now() + forcedMs; - do { - if (await stopped()) return; - await wait(50); - } while (Date.now() < forcedDeadline); - throw new Error("Observed launcher descendants remained after bounded cleanup"); } diff --git a/tests/runner-e2e/process-tree.ts b/tests/runner-e2e/process-tree.ts index 7c939848fa..1ab4ebcddc 100644 --- a/tests/runner-e2e/process-tree.ts +++ b/tests/runner-e2e/process-tree.ts @@ -1,4 +1,4 @@ -import { spawn } from "node:child_process"; +import { spawn, type ChildProcess } from "node:child_process"; import path from "node:path"; export interface ProcessObservation { @@ -159,12 +159,12 @@ const diagnosticProcessKinds = new Set([ "tsx", ]); -export async function readProcessTable(): Promise { +export async function readProcessTable(startInspector?: () => ChildProcess): Promise { if (process.platform === "win32") { return null; } return await new Promise((resolve) => { - const inspector = spawn( + const inspector = startInspector ? startInspector() : spawn( "ps", ["-e", "-o", "pid=,ppid=,pgid=,lstart=,stat=,comm="], { diff --git a/tests/runner-e2e/server-stop.test.ts b/tests/runner-e2e/server-stop.test.ts index 49b487f14d..af7e137364 100644 --- a/tests/runner-e2e/server-stop.test.ts +++ b/tests/runner-e2e/server-stop.test.ts @@ -248,7 +248,10 @@ it.skipIf(process.platform === "win32")("recovers a failed cleanup without repea }, }); try { - await expect(stop(child)).rejects.toThrow("transient inspection failure"); + const failed = expect(stop(child)).rejects.toThrow("transient inspection failure"); + await new Promise(resolve => setTimeout(resolve, 100)); + if (child.connected) child.send("finish"); + await failed; const recovery = stop(child); // A second graceful signal would terminate this child's once-handler. await new Promise(resolve => setTimeout(resolve, 50)); @@ -258,3 +261,52 @@ it.skipIf(process.platform === "win32")("recovers a failed cleanup without repea expect([child.exitCode, child.signalCode]).toEqual([0, null]); } finally { owner?.stopObserving(); } }); + +it.skipIf(process.platform === 'win32').each([['launcher', 'null'], ['server', 'null'], ['launcher', 'throw'], ['server', 'throw']] as const)( + 'bounds the known %s child when inspection fails with %s', async (kind, failure) => { + const { entry } = await fixture(`process.on('SIGTERM', () => {}); process.send('ready'); setInterval(() => {}, 1000);`); + const child = start(entry); + await once(child, 'message'); + const groupSignals: number[] = []; + const owner = createProcessTreeOwner(child, { + readTable: async () => { if (failure === "throw") throw new Error("inspection failed"); return null; }, + signalGroup: pid => { groupSignals.push(pid); }, + }); + try { + const stopping = kind === 'launcher' + ? stopOwnedProcessTree(child, owner, 50, 500) + : createRunnerE2EServerStopper({ gracefulTimeoutMs: 50, forcedTimeoutMs: 500, + hasSpawnError: () => false, markExpectedStop: () => {}, log: () => {}, createOwner: () => owner })(child); + await expect(stopping).rejects.toThrow(/inspect|incomplete/i); + expect(child.signalCode).toBe('SIGKILL'); + expect(groupSignals).toEqual([]); + } finally { owner.stopObserving(); } + }, +); + +it.skipIf(process.platform === 'win32')('does not re-signal a server after its graceful wrapper forwards and exits', async () => { + const { root, entry } = await fixture(); + const marker = path.join(root, 'async-close-finished'); + await writeFile(entry, ` + const child = require('node:child_process').spawn(process.execPath, ['-e', ${JSON.stringify(` + process.once('SIGTERM', () => setTimeout(() => { + require('node:fs').writeFileSync(${JSON.stringify(marker)}, 'closed'); process.exit(0); + }, 300)); + process.send('ready'); setInterval(() => {}, 1000); + `)}], { detached: true, stdio: ['ignore', 'ignore', 'ignore', 'ipc'] }); + child.once('message', () => process.send({ pid: child.pid })); + process.once('SIGTERM', () => { child.kill('SIGTERM'); process.exit(0); }); + `); + const wrapper = start(entry); + const pid = (await once(wrapper, 'message'))[0].pid as number; + const owner = createProcessTreeOwner(wrapper); + try { + await owner.observe(); + await stopOwnedProcessTree(wrapper, owner, 2_000, 500); + expect(await readFile(marker, 'utf8')).toBe('closed'); + expect(wrapper.exitCode).toBe(0); + } finally { + owner.stopObserving(); + try { process.kill(-pid, 'SIGKILL'); } catch { /* already stopped */ } + } +}); diff --git a/tests/runner-e2e/server-stop.ts b/tests/runner-e2e/server-stop.ts index 7a28abb9c4..bbeddc734c 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 } from "./process-tree-owner.js"; +import { createProcessTreeOwner, incompleteTreeFallback } from "./process-tree-owner.js"; // The wrapper receives Playwright's group signal; only it signals Paperclip. export const runnerE2EServerDetached = process.platform !== "win32"; @@ -17,6 +17,7 @@ export function createRunnerE2EServerStopper(options: { owner: ReturnType; promise?: Promise; gracefulDeadline?: number; + forcedDeadline?: number; gracefulSent: boolean; groupSignals: Set; escalationLogged: boolean; @@ -32,11 +33,10 @@ export function createRunnerE2EServerStopper(options: { return state; } async function stopOnce(child: ChildProcess, state: State, signal: NodeJS.Signals) { - await state.owner.observe(); state.gracefulDeadline ??= Date.now() + options.gracefulTimeoutMs; + await state.owner.observe(); if (!exited(child) && !state.gracefulSent) { - child.kill(signal); - state.gracefulSent = true; + state.gracefulSent = child.kill(signal); } while (Date.now() < state.gracefulDeadline) { await state.owner.observe(); @@ -55,23 +55,26 @@ export function createRunnerE2EServerStopper(options: { } if (runnerE2EServerDetached) await state.owner.signal("SIGKILL"); else if (!exited(child)) child.kill("SIGKILL"); - const deadline = Date.now() + options.forcedTimeoutMs; + state.forcedDeadline ??= Date.now() + options.forcedTimeoutMs; do { await state.owner.observe(); if (exited(child) && !state.owner.liveGroups().length) { state.owner.stopObserving(); return; } await wait(25); - } while (Date.now() < deadline); + } while (Date.now() < state.forcedDeadline); throw new Error("Paperclip server or observed descendants did not exit after SIGKILL"); } const stop = (child: ChildProcess, signal: NodeJS.Signals = "SIGTERM"): Promise => { options.markExpectedStop(child); const state = watch(child); - state.promise ??= Promise.resolve().then(() => stopOnce(child, state, signal)).catch(error => { - // Retain the signal/deadline phase, but let final cleanup recover from an - // inspection/signaling failure without delivering another graceful signal. - state.promise = undefined; - throw error; + state.promise ??= Promise.resolve().then(() => stopOnce(child, state, signal)).catch(async error => { + try { + await incompleteTreeFallback(error, child, state, state.gracefulDeadline!, options.forcedTimeoutMs); + } finally { + state.promise = undefined; + } }); + /* Retain the signal/deadline phase so a later audit can recover without + repeating the graceful signal. */ return state.promise; }; return Object.assign(stop, { watch: (child: ChildProcess) => watch(child).owner.observe() });