From bce82811da469508035c77cd6f2fe2f8dffd661f Mon Sep 17 00:00:00 2001 From: garrytan Date: Tue, 3 Nov 2026 14:52:37 +0000 Subject: [PATCH 1/3] fix(hooks): question-log hook children share the hook's 5 s budget instead of a fixed 3 s each Co-authored-by: capy-ai[bot] <230910855+capy-ai[bot]@users.noreply.github.com> --- changelog.d/gsta262-hook-budget.md | 3 ++ hosts/claude/hooks/question-log-hook.ts | 18 +++++++--- hosts/claude/hooks/spawn-bin.ts | 15 ++++++++ test/question-log-hook.test.ts | 48 +++++++++++++++++++++++++ 4 files changed, 79 insertions(+), 5 deletions(-) create mode 100644 changelog.d/gsta262-hook-budget.md diff --git a/changelog.d/gsta262-hook-budget.md b/changelog.d/gsta262-hook-budget.md new file mode 100644 index 000000000..9a0a8afdd --- /dev/null +++ b/changelog.d/gsta262-hook-budget.md @@ -0,0 +1,3 @@ +### Fixed + +- **The AskUserQuestion log hook no longer kills a slow first run on Windows, and never outlives Claude Code's 5-second hook limit.** `question-log-hook` gave each `gstack-question-log` call a fixed 3-second timeout. On a cold Windows runner the first call takes just over 3 seconds (3,149 and 3,188 ms in windows-pregate runs 41605458462 and 41406459043), so the hook killed it and logged "exited null" even though Claude Code allows the hook 5 seconds. A fixed timeout per call also let several questions run well past those 5 seconds (six slow calls took 16 s). Now every call gets what is left of the hook's 5-second budget, less a 500 ms exit reserve. When the budget runs out, the hook stops and logs which questions it skipped, and a killed call's log line names the signal and how long it ran. diff --git a/hosts/claude/hooks/question-log-hook.ts b/hosts/claude/hooks/question-log-hook.ts index 3ed739ca7..dec7b7e6f 100644 --- a/hosts/claude/hooks/question-log-hook.ts +++ b/hosts/claude/hooks/question-log-hook.ts @@ -35,7 +35,7 @@ import * as crypto from 'crypto'; import * as fs from 'fs'; import * as path from 'path'; -import { runBin } from './spawn-bin'; +import { HOOK_TIMEOUT_MS, hookChildBudgetMs, runBin } from './spawn-bin'; import { logHookError as sharedLogHookError } from './hook-log'; import { parseQidMarker } from '../../../scripts/qid-marker'; @@ -67,6 +67,7 @@ interface ExtractedQuestion { } const RECOMMENDED_LABEL_RE = /\(recommended\)\s*$/i; +const HOOK_STARTED_AT = Date.now() - Math.round(process.uptime() * 1000); function logHookError(msg: string): void { sharedLogHookError('question-log-hook', msg); @@ -238,17 +239,19 @@ function detectSkill(cwd: string | undefined): string { return 'unknown'; } -function spawnLog(payload: Record, cwd?: string): void { +function spawnLog(payload: Record, budgetMs: number, cwd?: string): void { + const startedAt = Date.now(); const res = runBin('gstack-question-log', [JSON.stringify(payload)], { encoding: 'utf-8', stdio: ['ignore', 'pipe', 'pipe'], - timeout: 3000, + timeout: budgetMs, // Run from the originating tool call's cwd so gstack-slug resolves to // the project the user is actually in, not the hook script's location. cwd: cwd && fs.existsSync(cwd) ? cwd : undefined, }); if (res.status !== 0) { - logHookError(`gstack-question-log exited ${res.status}: ${res.stderr || res.stdout}`); + const how = res.signal ? ` (${res.signal} after ${Date.now() - startedAt} of ${budgetMs} ms)` : ''; + logHookError(`gstack-question-log exited ${res.status}${how}: ${res.stderr || res.stdout}`); } } @@ -309,7 +312,12 @@ async function main(): Promise { if (signal_key) payload.signal_key = signal_key; if (choice.free_text) payload.free_text = String(choice.free_text); - spawnLog(payload, stdin.cwd); + const budgetMs = hookChildBudgetMs(HOOK_STARTED_AT); + if (budgetMs <= 0) { + logHookError(`gstack-question-log skipped for questions ${i + 1}-${questions.length}: the hook's ${HOOK_TIMEOUT_MS} ms budget is spent`); + break; + } + spawnLog(payload, budgetMs, stdin.cwd); } process.exit(0); diff --git a/hosts/claude/hooks/spawn-bin.ts b/hosts/claude/hooks/spawn-bin.ts index 845b28eb6..95c26bbd4 100644 --- a/hosts/claude/hooks/spawn-bin.ts +++ b/hosts/claude/hooks/spawn-bin.ts @@ -41,6 +41,21 @@ export function runBin(name: string, args: string[], opts: SpawnSyncOptions) { }); } +/** Claude Code's timeout for a gstack hook, as setup registers it (`--timeout 5`). */ +export const HOOK_TIMEOUT_MS = 5000; +/** Kept back from HOOK_TIMEOUT_MS so a hook logs and exits before Claude Code kills it. */ +export const HOOK_EXIT_RESERVE_MS = 500; + +/** + * What is left of a hook's registered budget for its next child. Every child + * a hook spawns shares one deadline: a fixed per-child timeout either kills a + * cold child that would have finished in time, or lets several children run + * past the point where Claude Code kills the hook itself. + */ +export function hookChildBudgetMs(startedAtMs: number, nowMs: number = Date.now()): number { + return HOOK_TIMEOUT_MS - HOOK_EXIT_RESERVE_MS - (nowMs - startedAtMs); +} + /** Kept tail of the child's stderr, for the caller's error log. */ const STDERR_TAIL_BYTES = 500; /** After a group kill, how long to wait for 'exit'/'close' before resolving anyway (kept under the callers' post-spawn reserve). */ diff --git a/test/question-log-hook.test.ts b/test/question-log-hook.test.ts index 5033a561a..3952f5d3b 100644 --- a/test/question-log-hook.test.ts +++ b/test/question-log-hook.test.ts @@ -19,6 +19,7 @@ import * as fs from 'fs'; import * as path from 'path'; import * as os from 'os'; import { spawnSync } from 'child_process'; +import { HOOK_EXIT_RESERVE_MS, HOOK_TIMEOUT_MS, hookChildBudgetMs } from '../hosts/claude/hooks/spawn-bin'; const ROOT = path.resolve(import.meta.dir, '..'); const HOOK = path.join(ROOT, 'hosts', 'claude', 'hooks', 'question-log-hook'); @@ -394,3 +395,50 @@ describe('PostToolUse hook (crash safety)', () => { expect(fs.readFileSync(errLog, 'utf-8')).toContain('stdin parse failed'); }); }); + +// ---------------------------------------------------------------------- +// One budget for every child (Claude Code kills the hook at 5 s) +// ---------------------------------------------------------------------- + +describe('PostToolUse hook (budget)', () => { + test('every child shares the registered 5 s budget, less the exit reserve', () => { + expect(hookChildBudgetMs(1_000, 1_000)).toBe(HOOK_TIMEOUT_MS - HOOK_EXIT_RESERVE_MS); + expect(hookChildBudgetMs(1_000, 3_000)).toBe(HOOK_TIMEOUT_MS - HOOK_EXIT_RESERVE_MS - 2_000); + expect(hookChildBudgetMs(1_000, 1_000 + HOOK_TIMEOUT_MS)).toBeLessThan(0); + }); + + test('slow children stop at the hook budget and the skipped questions are logged', () => { + const fakeBin = fs.mkdtempSync(path.join(os.tmpdir(), 'gstack-slow-bun-')); + try { + fs.writeFileSync(path.join(fakeBin, 'bun'), `#!/bin/sh\nsleep 1\nexec "${process.execPath}" "$@"\n`, { mode: 0o755 }); + const env: Record = {}; + for (const [k, v] of Object.entries(process.env)) { + if (v !== undefined) env[k] = v; + } + env.GSTACK_STATE_ROOT = stateRoot; + delete env.GSTACK_HOME; + env.GSTACK_QUESTION_LOG_NO_DERIVE = '1'; + env.PATH = `${fakeBin}${path.delimiter}${env.PATH ?? ''}`; + const questions = Array.from({ length: 6 }, (_, i) => ({ question: `Budget question ${i}`, options: ['A', 'B'] })); + const res = spawnSync(process.execPath, [path.join(ROOT, 'hosts', 'claude', 'hooks', 'question-log-hook.ts')], { + env, + input: JSON.stringify({ + session_id: 'budget', + tool_name: 'AskUserQuestion', + tool_use_id: 'tu-budget', + tool_input: { questions }, + tool_response: { answers: questions.map(() => ({ option_label: 'A' })) }, + cwd: ROOT, + }), + encoding: 'utf-8', + cwd: ROOT, + timeout: 30_000, + }); + expect(res.status).toBe(0); + expect(readLog().length).toBeLessThan(questions.length); + expect(fs.readFileSync(path.join(stateRoot, 'hook-errors.log'), 'utf-8')).toContain('budget is spent'); + } finally { + fs.rmSync(fakeBin, { recursive: true, force: true }); + } + }, 30_000); +}); From 77b47c05bd2c141692ada734c8c709bc1f81f6b8 Mon Sep 17 00:00:00 2001 From: garrytan Date: Tue, 3 Nov 2026 15:04:37 +0000 Subject: [PATCH 2/3] fix: pre-landing review fixes Assert the killed child's signal-and-elapsed log line; pin hookChildBudgetMs to literal values and stop exporting HOOK_EXIT_RESERVE_MS. Co-authored-by: capy-ai[bot] <230910855+capy-ai[bot]@users.noreply.github.com> --- hosts/claude/hooks/spawn-bin.ts | 2 +- test/question-log-hook.test.ts | 12 +++++++----- 2 files changed, 8 insertions(+), 6 deletions(-) diff --git a/hosts/claude/hooks/spawn-bin.ts b/hosts/claude/hooks/spawn-bin.ts index 95c26bbd4..5a000c9fc 100644 --- a/hosts/claude/hooks/spawn-bin.ts +++ b/hosts/claude/hooks/spawn-bin.ts @@ -44,7 +44,7 @@ export function runBin(name: string, args: string[], opts: SpawnSyncOptions) { /** Claude Code's timeout for a gstack hook, as setup registers it (`--timeout 5`). */ export const HOOK_TIMEOUT_MS = 5000; /** Kept back from HOOK_TIMEOUT_MS so a hook logs and exits before Claude Code kills it. */ -export const HOOK_EXIT_RESERVE_MS = 500; +const HOOK_EXIT_RESERVE_MS = 500; /** * What is left of a hook's registered budget for its next child. Every child diff --git a/test/question-log-hook.test.ts b/test/question-log-hook.test.ts index 3952f5d3b..60f8b1896 100644 --- a/test/question-log-hook.test.ts +++ b/test/question-log-hook.test.ts @@ -19,7 +19,7 @@ import * as fs from 'fs'; import * as path from 'path'; import * as os from 'os'; import { spawnSync } from 'child_process'; -import { HOOK_EXIT_RESERVE_MS, HOOK_TIMEOUT_MS, hookChildBudgetMs } from '../hosts/claude/hooks/spawn-bin'; +import { hookChildBudgetMs } from '../hosts/claude/hooks/spawn-bin'; const ROOT = path.resolve(import.meta.dir, '..'); const HOOK = path.join(ROOT, 'hosts', 'claude', 'hooks', 'question-log-hook'); @@ -402,9 +402,9 @@ describe('PostToolUse hook (crash safety)', () => { describe('PostToolUse hook (budget)', () => { test('every child shares the registered 5 s budget, less the exit reserve', () => { - expect(hookChildBudgetMs(1_000, 1_000)).toBe(HOOK_TIMEOUT_MS - HOOK_EXIT_RESERVE_MS); - expect(hookChildBudgetMs(1_000, 3_000)).toBe(HOOK_TIMEOUT_MS - HOOK_EXIT_RESERVE_MS - 2_000); - expect(hookChildBudgetMs(1_000, 1_000 + HOOK_TIMEOUT_MS)).toBeLessThan(0); + expect(hookChildBudgetMs(1_000, 1_000)).toBe(4_500); + expect(hookChildBudgetMs(1_000, 3_000)).toBe(2_500); + expect(hookChildBudgetMs(1_000, 6_000)).toBeLessThan(0); }); test('slow children stop at the hook budget and the skipped questions are logged', () => { @@ -436,7 +436,9 @@ describe('PostToolUse hook (budget)', () => { }); expect(res.status).toBe(0); expect(readLog().length).toBeLessThan(questions.length); - expect(fs.readFileSync(path.join(stateRoot, 'hook-errors.log'), 'utf-8')).toContain('budget is spent'); + const errors = fs.readFileSync(path.join(stateRoot, 'hook-errors.log'), 'utf-8'); + expect(errors).toMatch(/exited null \(SIG\w+ after \d+ of \d+ ms\)/); + expect(errors).toContain('budget is spent'); } finally { fs.rmSync(fakeBin, { recursive: true, force: true }); } From 1ee952242bcdbb02a43a94093b8d796ac9a234dc Mon Sep 17 00:00:00 2001 From: garrytan Date: Tue, 3 Nov 2026 15:17:27 +0000 Subject: [PATCH 3/3] fix(hooks): read the question-log budget after the Git Bash lookup and skip under 250 ms Scoped fix-check grant a-67d987ab49cc (GStack Minder). The changelog now claims only what the code guarantees. Co-authored-by: capy-ai[bot] <230910855+capy-ai[bot]@users.noreply.github.com> --- changelog.d/gsta262-hook-budget.md | 2 +- hosts/claude/hooks/question-log-hook.ts | 26 +++++++++++++++++++------ test/question-log-hook.test.ts | 10 +++++++++- 3 files changed, 30 insertions(+), 8 deletions(-) diff --git a/changelog.d/gsta262-hook-budget.md b/changelog.d/gsta262-hook-budget.md index 9a0a8afdd..5435ae3a0 100644 --- a/changelog.d/gsta262-hook-budget.md +++ b/changelog.d/gsta262-hook-budget.md @@ -1,3 +1,3 @@ ### Fixed -- **The AskUserQuestion log hook no longer kills a slow first run on Windows, and never outlives Claude Code's 5-second hook limit.** `question-log-hook` gave each `gstack-question-log` call a fixed 3-second timeout. On a cold Windows runner the first call takes just over 3 seconds (3,149 and 3,188 ms in windows-pregate runs 41605458462 and 41406459043), so the hook killed it and logged "exited null" even though Claude Code allows the hook 5 seconds. A fixed timeout per call also let several questions run well past those 5 seconds (six slow calls took 16 s). Now every call gets what is left of the hook's 5-second budget, less a 500 ms exit reserve. When the budget runs out, the hook stops and logs which questions it skipped, and a killed call's log line names the signal and how long it ran. +- **The AskUserQuestion log hook no longer kills a slow first run on Windows, and its calls now share Claude Code's 5-second hook limit.** `question-log-hook` gave each `gstack-question-log` call a fixed 3-second timeout. On a cold Windows runner the first call takes just over 3 seconds (3,149 and 3,188 ms in windows-pregate runs 41605458462 and 41406459043), so the hook killed it and logged "exited null" even though Claude Code allows the hook 5 seconds. A fixed timeout per call also let several questions run well past those 5 seconds (six slow calls took 16 s). Now the calls share one budget: 5 seconds from when Bun starts the hook, less a 500 ms exit reserve. On Windows the hook finds Git Bash before it reads that budget, so the lookup comes out of the budget instead of adding to a call's time. When less than 250 ms is left, the hook skips the remaining questions and logs which ones; a killed call's log line names the signal and how long it ran. The budget doesn't cover the bash shim that starts Bun, and the first Git Bash lookup on a fresh install has no time limit of its own, so Claude Code can still stop the hook in those cases. diff --git a/hosts/claude/hooks/question-log-hook.ts b/hosts/claude/hooks/question-log-hook.ts index dec7b7e6f..f31417830 100644 --- a/hosts/claude/hooks/question-log-hook.ts +++ b/hosts/claude/hooks/question-log-hook.ts @@ -38,6 +38,8 @@ import * as path from 'path'; import { HOOK_TIMEOUT_MS, hookChildBudgetMs, runBin } from './spawn-bin'; import { logHookError as sharedLogHookError } from './hook-log'; import { parseQidMarker } from '../../../scripts/qid-marker'; +import { resolveWindowsBashCached } from '../../../lib/script-invocation'; +import { resolveStateRoot } from '../../../lib/state-root'; interface HookStdin { session_id?: string; @@ -68,6 +70,14 @@ interface ExtractedQuestion { const RECOMMENDED_LABEL_RE = /\(recommended\)\s*$/i; const HOOK_STARTED_AT = Date.now() - Math.round(process.uptime() * 1000); +/** Below this much budget a child cannot launch and finish, so the hook skips it instead of starting a call it must kill. */ +const MIN_LAUNCH_BUDGET_MS = 250; + +/** Why the next gstack-question-log call is skipped with `budgetMs` left, or null when it may launch. */ +export function launchSkipReason(budgetMs: number): string | null { + if (budgetMs >= MIN_LAUNCH_BUDGET_MS) return null; + return `the hook's ${HOOK_TIMEOUT_MS} ms budget is spent (${Math.max(0, budgetMs)} ms left, under the ${MIN_LAUNCH_BUDGET_MS} ms a call needs)`; +} function logHookError(msg: string): void { sharedLogHookError('question-log-hook', msg); @@ -286,6 +296,7 @@ async function main(): Promise { const choices = extractUserChoices(stdin.tool_response, questions, (msg) => logHookError(`${msg} (tool_use_id=${stdin.tool_use_id || 'n/a'})`), ); + if (process.platform === 'win32') resolveWindowsBashCached(path.join(resolveStateRoot(), 'cache', 'windows-bash.json')); for (let i = 0; i < questions.length; i++) { const q = questions[i]; @@ -313,8 +324,9 @@ async function main(): Promise { if (choice.free_text) payload.free_text = String(choice.free_text); const budgetMs = hookChildBudgetMs(HOOK_STARTED_AT); - if (budgetMs <= 0) { - logHookError(`gstack-question-log skipped for questions ${i + 1}-${questions.length}: the hook's ${HOOK_TIMEOUT_MS} ms budget is spent`); + const skip = launchSkipReason(budgetMs); + if (skip) { + logHookError(`gstack-question-log skipped for questions ${i + 1}-${questions.length}: ${skip}`); break; } spawnLog(payload, budgetMs, stdin.cwd); @@ -323,7 +335,9 @@ async function main(): Promise { process.exit(0); } -main().catch((e) => { - logHookError(`main crash: ${(e as Error).message}`); - process.exit(0); -}); +if (import.meta.main) { + main().catch((e) => { + logHookError(`main crash: ${(e as Error).message}`); + process.exit(0); + }); +} diff --git a/test/question-log-hook.test.ts b/test/question-log-hook.test.ts index 60f8b1896..1c06bcd31 100644 --- a/test/question-log-hook.test.ts +++ b/test/question-log-hook.test.ts @@ -20,6 +20,7 @@ import * as path from 'path'; import * as os from 'os'; import { spawnSync } from 'child_process'; import { hookChildBudgetMs } from '../hosts/claude/hooks/spawn-bin'; +import { launchSkipReason } from '../hosts/claude/hooks/question-log-hook.ts'; const ROOT = path.resolve(import.meta.dir, '..'); const HOOK = path.join(ROOT, 'hosts', 'claude', 'hooks', 'question-log-hook'); @@ -407,10 +408,17 @@ describe('PostToolUse hook (budget)', () => { expect(hookChildBudgetMs(1_000, 6_000)).toBeLessThan(0); }); + test('a call launches only with at least 250 ms of budget left', () => { + expect(launchSkipReason(4_500)).toBeNull(); + expect(launchSkipReason(250)).toBeNull(); + expect(launchSkipReason(249)).toBe("the hook's 5000 ms budget is spent (249 ms left, under the 250 ms a call needs)"); + expect(launchSkipReason(-40)).toBe("the hook's 5000 ms budget is spent (0 ms left, under the 250 ms a call needs)"); + }); + test('slow children stop at the hook budget and the skipped questions are logged', () => { const fakeBin = fs.mkdtempSync(path.join(os.tmpdir(), 'gstack-slow-bun-')); try { - fs.writeFileSync(path.join(fakeBin, 'bun'), `#!/bin/sh\nsleep 1\nexec "${process.execPath}" "$@"\n`, { mode: 0o755 }); + fs.writeFileSync(path.join(fakeBin, 'bun'), `#!/bin/sh\nsleep 5\nexec "${process.execPath}" "$@"\n`, { mode: 0o755 }); const env: Record = {}; for (const [k, v] of Object.entries(process.env)) { if (v !== undefined) env[k] = v;