fix(hooks): report a timed-out hook as unverifiable and terminate its process tree

Node's `exec({ timeout })` SIGTERMs the child and then reports whatever the child
chose to do. A hook that traps SIGTERM and exits 0 — a graceful
`process.on('SIGTERM')` in a Node wrapper, an rsync wrapper cleaning up — comes
back with a NULL error, so a hook cut off mid-run is indistinguishable from one
that finished its work. Reproduced:
`exec("trap 'exit 0' TERM; sleep 5", { timeout: 200 })` yields no error.

`runHook` now owns the deadline. The verdict comes from running out of time
rather than from the corpse's exit code, and it is settled AT the deadline so a
hook that traps the signal and keeps running cannot hold its caller open. A
timeout withholds the exit code entirely: callers that distinguish "exited N"
from "outcome never observed" can now trust that distinction. The same applies
to a spawn failure, where `exec` reports a string code.

Termination reaches the process GROUP, because the script is a shell and the
work is its children — signalling only the shell leaves `sleep` or `rsync` alive
holding the pipes. The SIGKILL escalation probes the group with signal 0 first:
ESRCH means nothing is left to kill. Keying that on the direct child instead
would skip the escalation exactly when a hook has backgrounded something that
outlived its shell. The residual trade is stated at the call site — a recycled
pid answers the probe too, so the window is pid wraparound inside the grace.

One `classifyHookProcessResult` now serves both the native and WSL branches,
which had been mapping a finished process to a hook verdict by hand, identically.

This changes `setup` hooks as well as `archive` ones, since both share
`runHook`: a setup hook that backgrounds a long-running server now has that
server terminated with the rest of its group at the deadline, where previously it
was orphaned and survived.

Refs #19334
This commit is contained in:
Neil
2026-09-13 22:17:27 -07:00
parent 3cd60e76e9
commit 23fa74bcbb
4 changed files with 378 additions and 38 deletions
@@ -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<string[]> {
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()
}
})
})
@@ -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 })
})
})
@@ -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()
})
})
+160 -38
View File
@@ -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<HookProcessOutcome>((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)
}
})
}