diff --git a/src/main/hook-archive-termination-safety.test.ts b/src/main/hook-archive-termination-safety.test.ts new file mode 100644 index 00000000000..7627c7e84fc --- /dev/null +++ b/src/main/hook-archive-termination-safety.test.ts @@ -0,0 +1,103 @@ +import { describe, expect, it, vi } from 'vitest' +import { mkdtempSync, rmSync, writeFileSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import type { Repo } from '../shared/repo-types' + +vi.mock('./effective-hook-config', () => ({ + getEffectiveHooksFromConfig: (_repo: unknown, hooks: unknown) => hooks +})) + +const REPO: Repo = { id: 'r', path: '/repo', displayName: 'r', badgeColor: '#000', addedAt: 0 } + +/** + * Run a hook past its deadline with `process.kill` intercepted, so the escalation's decisions are + * observed directly instead of raced against the kernel. `groupAlive` answers the signal-0 probe. + */ +async function signalsFromTimedOutHook(groupAlive: boolean): Promise { + const { runHook } = await import('./hooks') + const dir = mkdtempSync(join(tmpdir(), 'orca-hook-signals-')) + writeFileSync(join(dir, 'orca.yaml'), 'scripts:\n archive: |\n sleep 30\n') + const sent: string[] = [] + const fakeKill = (pid: number, signal?: string | number): true => { + if (signal === 0) { + if (!groupAlive) { + throw Object.assign(new Error('ESRCH'), { code: 'ESRCH' }) + } + return true + } + sent.push(`${pid < 0 ? 'group' : 'child'}:${String(signal)}`) + return true + } + const spy = vi.spyOn(process, 'kill').mockImplementation(fakeKill) + try { + await runHook('archive', dir, REPO, dir, undefined, 100) + await new Promise((resolve) => setTimeout(resolve, 2_400)) + return sent + } finally { + spy.mockRestore() + rmSync(dir, { recursive: true, force: true }) + } +} + +// Why (#19334): the escalation exists for descendants that outlive the shell — a setup hook that +// backgrounds a server typically loses its leader to the first SIGTERM while the server keeps +// running. Keying the skip on the CHILD's exit would miss exactly that case; the probe asks the +// GROUP instead. The residual hazard, stated in hooks.ts: a recycled pid answers the probe too. +describe.skipIf(process.platform === 'win32')('archive hook termination', () => { + it('escalates to the group when members survive the first signal', async () => { + await expect(signalsFromTimedOutHook(true)).resolves.toEqual(['group:SIGTERM', 'group:SIGKILL']) + }, 20_000) + + it('sends nothing once the group is provably empty', async () => { + // A group that answers ESRCH has no members left to kill, and its pid may since belong to + // someone else — so neither the SIGTERM nor the escalation is delivered. + await expect(signalsFromTimedOutHook(false)).resolves.toEqual([]) + }, 20_000) +}) + +// The regression the group probe exists for, pinned directly because it cannot be reproduced +// through `runHook` with signals intercepted: with `process.kill` mocked nothing actually dies, so +// the child never reaches the exited state that a child-liveness skip would key on. +describe.skipIf(process.platform === 'win32')('terminateHookTree', () => { + const fakeChild = (exited: boolean) => ({ + pid: 4242, + exitCode: exited ? 0 : null, + signalCode: null, + kill: vi.fn() + }) + + it('signals a surviving group even though the shell leader already exited', async () => { + const { terminateHookTree } = await import('./hooks') + const sent: (string | number | undefined)[][] = [] + const recordKill = (pid: number, signal?: string | number): true => { + if (signal !== 0) { + sent.push([pid, signal]) + } + return true + } + const spy = vi.spyOn(process, 'kill').mockImplementation(recordKill) + try { + // A hook that backgrounds a server loses its leader to the first SIGTERM; the server lives on. + terminateHookTree(fakeChild(true), 'SIGKILL') + expect(sent).toEqual([[-4242, 'SIGKILL']]) + } finally { + spy.mockRestore() + } + }) + + it('sends nothing when the group answers ESRCH', async () => { + const { terminateHookTree } = await import('./hooks') + const child = fakeChild(true) + const emptyGroup = (): true => { + throw Object.assign(new Error('ESRCH'), { code: 'ESRCH' }) + } + const spy = vi.spyOn(process, 'kill').mockImplementation(emptyGroup) + try { + terminateHookTree(child, 'SIGKILL') + expect(child.kill).not.toHaveBeenCalled() + } finally { + spy.mockRestore() + } + }) +}) diff --git a/src/main/hook-archive-timeout-observation.test.ts b/src/main/hook-archive-timeout-observation.test.ts new file mode 100644 index 00000000000..62f4b17a386 --- /dev/null +++ b/src/main/hook-archive-timeout-observation.test.ts @@ -0,0 +1,52 @@ +import { describe, expect, it, vi } from 'vitest' +import { mkdtempSync, rmSync, writeFileSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import type { Repo } from '../shared/repo-types' + +vi.mock('./effective-hook-config', () => ({ + getEffectiveHooksFromConfig: (_repo: unknown, hooks: unknown) => hooks +})) + +const REPO: Repo = { id: 'r', path: '/repo', displayName: 'r', badgeColor: '#000', addedAt: 0 } + +/** Run a real archive script in a real shell, under a deadline short enough to test. */ +async function runArchive(script: string, timeoutMs = 400) { + const { runHook } = await import('./hooks') + const dir = mkdtempSync(join(tmpdir(), 'orca-hook-deadline-')) + writeFileSync(join(dir, 'orca.yaml'), `scripts:\n archive: |\n ${script}\n`) + try { + return await runHook('archive', dir, REPO, dir, undefined, timeoutMs) + } finally { + rmSync(dir, { recursive: true, force: true }) + } +} + +// Why a real shell (#19334): this bug is invisible to a mock. Node's `exec({ timeout })` SIGTERMs +// the child and reports whatever it chose to do, so a hook that traps SIGTERM and exits 0 came +// back as a PASS — a hook cut off mid-archive, indistinguishable from one that finished its work. +describe.skipIf(process.platform === 'win32')('archive hook deadline', () => { + it('fails a hook that traps SIGTERM and exits zero, despite its zero exit', async () => { + const result = await runArchive("trap 'exit 0' TERM; sleep 30") + expect(result.success).toBe(false) + // Withheld, so the removal gate reads `unverifiable` rather than a pass. + expect(result.exitCode).toBeUndefined() + expect(result.output).toContain('timed out') + }, 20_000) + + it('settles at the deadline even when the hook refuses to die', async () => { + const started = Date.now() + const result = await runArchive("trap '' TERM; sleep 30") + expect(result.success).toBe(false) + // A hook that ignores the signal must not hold a removal open until it finishes. + expect(Date.now() - started).toBeLessThan(10_000) + }, 20_000) + + it('passes a hook that finishes inside its deadline', async () => { + await expect(runArchive('echo archived')).resolves.toMatchObject({ success: true }) + }) + + it('reports an observed non-zero exit as the exit it is', async () => { + await expect(runArchive('exit 23')).resolves.toMatchObject({ success: false, exitCode: 23 }) + }) +}) diff --git a/src/main/hooks-archive-exit-observation.test.ts b/src/main/hooks-archive-exit-observation.test.ts new file mode 100644 index 00000000000..7773894c4c4 --- /dev/null +++ b/src/main/hooks-archive-exit-observation.test.ts @@ -0,0 +1,63 @@ +import { describe, expect, it, vi } from 'vitest' +import type { Repo } from '../shared/repo-types' + +const { execMock } = vi.hoisted(() => ({ execMock: vi.fn() })) +vi.mock('child_process', () => ({ + exec: execMock, + execFileSync: vi.fn(), + execFile: vi.fn(), + spawn: vi.fn() +})) +vi.mock('./effective-hook-config', () => ({ + getEffectiveHooksFromConfig: () => ({ scripts: { archive: 'do-the-archive' } }) +})) + +const REPO: Repo = { id: 'r', path: '/repo', displayName: 'r', badgeColor: '#000', addedAt: 0 } + +const execFailure = (code: unknown): Error => Object.assign(new Error('Command failed'), { code }) + +/** Drive runHook once with the error object `exec` hands back for a given failure mode. */ +async function runArchiveWith( + error: Error | null +): Promise<{ success: boolean; exitCode?: number }> { + const { runHook } = await import('./hooks') + execMock.mockImplementationOnce((_script, _opts, cb) => { + cb(error, '', '') + return { pid: 1234, kill: vi.fn() } + }) + const outcome = await runHook('archive', '/repo/wt', REPO) + // Guard against a vacuous pass: if the mock ever stops intercepting, a real shell would run and + // this, rather than the subtle assertions below, is what fails. + expect(execMock).toHaveBeenCalled() + return outcome +} + +// Why (#19334): an ABSENT exitCode is what the removal gate reads as `unverifiable`. The guard is +// `typeof code === 'number'`, because `exec` reports a spawn failure with a *string* code — a +// looser null-check would file ENOENT as `exited "ENOENT"`, reading a hook that never ran as one +// that reported an exit. The timeout arm of the same contract is covered against a real shell in +// hook-archive-timeout-observation.test.ts. +describe('archive hook exit observation', () => { + it('passes a clean run through without an exit code', async () => { + await expect(runArchiveWith(null)).resolves.toEqual({ success: true, output: '' }) + }) + + it.each([ + ['a non-zero exit', 23], + ['a shell command-not-found', 127] + ])('reports %s as the observed exit it is', async (_label, code) => { + await expect(runArchiveWith(execFailure(code))).resolves.toMatchObject({ + success: false, + exitCode: code + }) + }) + + it.each([ + ['was killed by a signal', null], + ['never started, so the code is a string', 'ENOENT'] + ])('withholds the exit code when the hook %s', async (_label, code) => { + const result = await runArchiveWith(execFailure(code)) + expect(result.success).toBe(false) + expect(result.exitCode).toBeUndefined() + }) +}) diff --git a/src/main/hooks.ts b/src/main/hooks.ts index ef65fc28cf0..f9d91f38423 100644 --- a/src/main/hooks.ts +++ b/src/main/hooks.ts @@ -1,6 +1,5 @@ import { readFileSync, existsSync } from 'node:fs' import { join } from 'node:path' -import { exec } from 'node:child_process' import { parseOrcaYaml } from '../shared/orca-yaml' import { resolveHookCommandSourcePolicy } from '../shared/hook-command-source-policy' import { getEffectiveHooksFromConfig } from './effective-hook-config' @@ -15,9 +14,114 @@ import type { HookRuntimeTarget } from './hook-runtime-target' import type { OrcaHooks } from '../shared/orca-yaml-hook-types' import type { Repo } from '../shared/repo-types' import type { ProjectExecutionRuntimeResolution } from '../shared/project-execution-runtime' +import { exec } from 'node:child_process' const HOOK_TIMEOUT = 120_000 // 2 minutes +type HookProcessOutcome = { success: boolean; output: string; exitCode?: number } + +/** + * Turn a finished process into a hook verdict. + * + * Why `timedOut` decides before `code` (#19334): a hook that traps SIGTERM and exits 0 reports a + * zero exit for a run we cut off mid-archive. The exit code of something we stopped is not + * evidence it finished, so a timeout withholds the code and the removal gate reads that as + * `unverifiable` rather than as a pass. + */ +function classifyHookProcessResult( + result: { code: number | null; stdout: string; stderr: string; timedOut: boolean }, + context: { hookName: string; cwd: string; timeoutMs: number } +): HookProcessOutcome { + const streams = `${result.stdout}\n${result.stderr}` + if (result.timedOut) { + const message = `Hook timed out after ${context.timeoutMs}ms.` + console.error(`[hooks] ${context.hookName} hook failed in ${context.cwd}:`, message) + return { success: false, output: `${streams}\n${message}`.trim() } + } + if (result.code !== 0) { + const message = `Command failed with exit code ${result.code}.` + console.error(`[hooks] ${context.hookName} hook failed in ${context.cwd}:`, message) + return { + success: false, + output: `${streams}\n${message}`.trim(), + ...(typeof result.code === 'number' ? { exitCode: result.code } : {}) + } + } + console.log(`[hooks] ${context.hookName} hook completed in ${context.cwd}`) + return { success: true, output: streams.trim() } +} + +const SIGTERM_GRACE_MS = 2_000 + +/** Signal the hook's whole process group where the platform has one, else just the child. */ +export type TerminableChild = { + pid?: number + exitCode: number | null + signalCode: NodeJS.Signals | null + kill: (signal: NodeJS.Signals) => boolean +} + +export function terminateHookTree(child: TerminableChild, signal: NodeJS.Signals): void { + // Why probe the GROUP and not the child: the escalation exists for descendants that outlive the + // shell. A hook that backgrounds a server typically loses its leader to the first SIGTERM while + // the server keeps running, so keying this on `child.exitCode` would skip the SIGKILL in exactly + // the case it was added for. + // + // The trade-off it does not solve: signalling by negative pid names whatever group owns that pid + // now. Once the leader is reaped its pid can be recycled, and a probe cannot tell a surviving + // descendant from a stranger that inherited the number. Killing a runaway hook is the likelier + // event and the one the deadline promises, so the group is signalled whenever it answers; the + // residual window is pid wraparound inside the two-second grace. + if (process.platform !== 'win32' && child.pid) { + try { + // Signal 0 tests for members without delivering anything: ESRCH means the group is empty. + process.kill(-child.pid, 0) + } catch { + return + } + try { + process.kill(-child.pid, signal) + return + } catch { + // Raced with the last member exiting; fall through to the direct kill. + } + } + if (child.exitCode !== null || child.signalCode !== null) { + return + } + try { + child.kill(signal) + } catch { + // Already dead. + } +} + +/** An `exec` failure: a string `code` (ENOENT) means it never started, so no exit was observed. */ +function hookProcessError( + error: Error, + stdout: string, + stderr: string, + context: { hookName: string; cwd: string } +): HookProcessOutcome { + const code = 'code' in error ? error.code : undefined + console.error(`[hooks] ${context.hookName} hook failed in ${context.cwd}:`, error.message) + return { + success: false, + output: `${stdout}\n${stderr}\n${error.message}`.trim(), + ...(typeof code === 'number' ? { exitCode: code } : {}) + } +} + +/** A hook that never started reported no exit, so the code stays withheld. */ +function hookSpawnFailure( + error: unknown, + context: { hookName: string; cwd: string } +): HookProcessOutcome { + const message = error instanceof Error ? error.message : String(error) + console.error(`[hooks] ${context.hookName} hook failed in ${context.cwd}:`, message) + return { success: false, output: message } +} + function getHookShell(): string | undefined { if (process.platform === 'win32') { return process.env.ComSpec || 'cmd.exe' @@ -120,8 +224,12 @@ export function runHook( cwd: string, repo: Repo, hooksPath?: string, - projectRuntime?: ProjectExecutionRuntimeResolution | HookRuntimeTarget -): Promise<{ success: boolean; output: string }> { + projectRuntime?: ProjectExecutionRuntimeResolution | HookRuntimeTarget, + /** Deadline override. Production uses HOOK_TIMEOUT; tests use it to exercise the timeout path. */ + timeoutMs: number = HOOK_TIMEOUT + // Why (#19334): an absent exitCode means no exit was ever observed. The archive-hook removal + // gate reads that as `unverifiable` rather than folding it into a zero. +): Promise<{ success: boolean; output: string; exitCode?: number }> { const hooks = getEffectiveHooks(repo, hooksPath) const script = hooks?.scripts[hookName] @@ -165,57 +273,71 @@ export function runHook( shell: 'bash', cwd: wslInfo.linuxPath, env: guestEnv, - timeoutMs: HOOK_TIMEOUT + timeoutMs }) - .then((result) => { - if (result.timedOut) { - const message = `Hook timed out after ${HOOK_TIMEOUT}ms.` - console.error(`[hooks] ${hookName} hook failed in ${cwd}:`, message) - return { success: false, output: `${result.stdout}\n${result.stderr}\n${message}`.trim() } - } - if (result.code !== 0) { - const message = `Command failed with exit code ${result.code}.` - console.error(`[hooks] ${hookName} hook failed in ${cwd}:`, message) - return { success: false, output: `${result.stdout}\n${result.stderr}\n${message}`.trim() } - } - console.log(`[hooks] ${hookName} hook completed in ${cwd}`) - return { success: true, output: `${result.stdout}\n${result.stderr}`.trim() } - }) - .catch((error: unknown) => { - const message = error instanceof Error ? error.message : String(error) - console.error(`[hooks] ${hookName} hook failed in ${cwd}:`, message) - return { success: false, output: message } - }) + .then((result) => classifyHookProcessResult(result, { hookName, cwd, timeoutMs })) + .catch((error: unknown) => hookSpawnFailure(error, { hookName, cwd })) } const shellHookEnv: NodeJS.ProcessEnv = { ...process.env, ...getSetupEnvVars(repo, cwd) } dropIncoherentCondaActivationEnv(shellHookEnv) - return new Promise((resolve) => { - exec( + return new Promise((resolve) => { + // Why we own the deadline (#19334): Node's `exec({ timeout })` SIGTERMs the child and then + // reports whatever it chose to do, so a hook that traps SIGTERM and exits 0 came back as a + // PASS — a hook cut off mid-archive, indistinguishable from one that finished. Settle on the + // deadline instead, and settle AT it, so a hook that traps and keeps running cannot hold a + // removal open. `exec` stays because it owns the per-platform shell invocation (`cmd.exe` + // wants `/d /s /c`, not `-c`), which is not this change's to re-derive. + let settled = false + let deadline: NodeJS.Timeout | undefined + const settle = (result: HookProcessOutcome): void => { + if (settled) { + return + } + settled = true + if (deadline) { + clearTimeout(deadline) + } + resolve(result) + } + const child = exec( script, { cwd, - timeout: HOOK_TIMEOUT, shell: getHookShell(), // Why: hooks run unattended; block Git Credential Manager's interactive prompt while keeping cached auth (issue #7652). - env: promptGuardShellEnv(shellHookEnv) + env: promptGuardShellEnv(shellHookEnv), + // Signal the whole group on POSIX: the script is a shell, and the work is its children. + ...(process.platform === 'win32' ? {} : { detached: true }) }, (error, stdout, stderr) => { if (error) { - console.error(`[hooks] ${hookName} hook failed in ${cwd}:`, error.message) - resolve({ - success: false, - output: `${stdout}\n${stderr}\n${error.message}`.trim() - }) - } else { - console.log(`[hooks] ${hookName} hook completed in ${cwd}`) - resolve({ - success: true, - output: `${stdout}\n${stderr}`.trim() - }) + settle(hookProcessError(error, stdout, stderr, { hookName, cwd })) + return } + settle( + classifyHookProcessResult( + { code: 0, stdout, stderr, timedOut: false }, + { hookName, cwd, timeoutMs } + ) + ) } ) + // Why guarded: `exec`'s callback can fire synchronously (the unit test's mock does), and arming + // a deadline on an already-settled run would later signal a process group whose pid is long + // gone — and may by then belong to something else. + if (!settled) { + deadline = setTimeout(() => { + settle( + classifyHookProcessResult( + { code: null, stdout: '', stderr: '', timedOut: true }, + { hookName, cwd, timeoutMs } + ) + ) + terminateHookTree(child, 'SIGTERM') + setTimeout(() => terminateHookTree(child, 'SIGKILL'), SIGTERM_GRACE_MS).unref?.() + }, timeoutMs) + } }) }