W1: shared hook logging helper (hosts/claude/hooks/hook-log.ts)

One hook-errors.log writer: root from resolveStateRoot, 0600 on every
append, opt-in rate limit used only by memorable-user-prompt. The five
hooks route through it.
This commit is contained in:
garrytan committed 2026-09-30 06:38:50 +00:00
1 parent 496c29c938
commit 8a6ffdaca1
7 files changed
+161 -103

No files matched your search

+2 -19
View File
@@ -30,9 +30,9 @@
*/
import * as fs from 'fs';
import * as path from 'path';
import * as os from 'os';
import { runBin } from './spawn-bin';
import { SPAWNED_ESCAPE_SENTENCE } from './spawned-directive';
import { logHookError as sharedLogHookError } from './hook-log';
interface HookStdin {
tool_name?: string;
@@ -40,25 +40,8 @@ interface HookStdin {
cwd?: string;
}
function stateRoot(): string {
return (
process.env.GSTACK_STATE_ROOT ||
process.env.GSTACK_HOME ||
path.join(os.homedir(), '.gstack')
);
}
function logHookError(msg: string): void {
try {
const sr = stateRoot();
fs.mkdirSync(sr, { recursive: true });
fs.appendFileSync(
path.join(sr, 'hook-errors.log'),
`${new Date().toISOString()} auq-error-fallback-hook: ${msg}\n`,
);
} catch {
// last-resort swallow
}
sharedLogHookError('auq-error-fallback-hook', msg);
}
function readStdin(): Promise<string> {
+59
View File
@@ -0,0 +1,59 @@
/**
* hook-log — the one hook-errors.log writer for the Claude Code hooks in this
* directory. Root from resolveStateRoot() (lib/state-root.ts), mode 0600 on
* every append (an existing 0644 log is tightened), best-effort: logging never
* blocks a hook. Add a hook: `logHookError('my-hook', msg)`; pass
* `{ rateLimit: { nowMs, key } }` to drop repeats within LOG_RATE_LIMIT_MS
* (only memorable-user-prompt uses it). Moved from the five hooks' private
* copies; test/hook-log.test.ts pins the shared root and the mode.
*/
import * as fs from 'fs';
import * as path from 'path';
import { createHash } from 'crypto';
import { resolveStateRoot } from '../../../lib/state-root';
export const LOG_RATE_LIMIT_MS = 10 * 60 * 1000;
/** Distinct rate-limit keys remembered at once (the marker file is rewritten on every log line). */
const RATE_LIMIT_KEYS = 32;
export interface HookLogOptions {
/** Drop a repeat of `key` logged by this hook within LOG_RATE_LIMIT_MS of `nowMs`. */
rateLimit?: { nowMs: number; key: string };
}
export function hookErrorLogPath(env: NodeJS.ProcessEnv = process.env): string {
return path.join(resolveStateRoot(env), 'hook-errors.log');
}
/**
* Append one line to <state root>/hook-errors.log. With `rateLimit`, a
* per-hook marker (`hook-errors.<hook>.last`, up to RATE_LIMIT_KEYS live
* `digest:ts` lines) suppresses repeats, so hooks never contend on it.
*/
export function logHookError(hook: string, msg: string, opts: HookLogOptions = {}): void {
try {
const root = resolveStateRoot();
fs.mkdirSync(root, { recursive: true });
const nowMs = opts.rateLimit?.nowMs ?? Date.now();
if (opts.rateLimit) {
const marker = path.join(root, `hook-errors.${hook}.last`);
const digest = createHash('sha256').update(opts.rateLimit.key).digest('hex').slice(0, 16);
const live: string[] = [];
try {
for (const line of fs.readFileSync(marker, 'utf8').split('\n')) {
const [d, ts] = line.trim().split(':');
if (!d || !ts || nowMs - Number(ts) >= LOG_RATE_LIMIT_MS) continue;
if (d === digest) return;
live.push(line.trim());
}
} catch { /* no marker yet */ }
live.push(`${digest}:${nowMs}`);
fs.writeFileSync(marker, `${live.slice(-RATE_LIMIT_KEYS).join('\n')}\n`, { mode: 0o600 });
}
const log = path.join(root, 'hook-errors.log');
fs.appendFileSync(log, `${new Date(nowMs).toISOString()} ${hook}: ${msg}\n`, { mode: 0o600 });
if (process.platform !== 'win32') { try { fs.chmodSync(log, 0o600); } catch { /* not ours to tighten */ } }
} catch {
// best-effort; never block the session because logging failed
}
}
@@ -58,6 +58,9 @@ import {
import { wrapUntrustedTrackerContent } from '../../../lib/tracker-guard';
import { scan } from '../../../lib/redact-engine';
import { hasRepoPolicyStore, repoPolicyTier } from '../../../lib/gbrain-repo-policy-client';
import { LOG_RATE_LIMIT_MS, logHookError as sharedLogHookError } from './hook-log';
export { LOG_RATE_LIMIT_MS };
export const BUDGET_MS = 4500;
export const STDIN_CAP_BYTES = 1024 * 1024;
@@ -74,7 +77,6 @@ export const RECHECK_CAP_MS = 500;
export const OUTCOME_MIN_MS = 80;
/** Kept back from the clock when an outcome append is given the rest of it. */
export const OUTCOME_RESERVE_MS = 50;
export const LOG_RATE_LIMIT_MS = 10 * 60 * 1000;
export const ENVELOPE_SOURCE = 'memorable recall (third-party)';
export const SINK = 'memorable-recall';
export const CONSENT = 'memorable_recall=on';
@@ -84,8 +86,6 @@ export const PAYLOAD_CLASS = 'claude-user-prompt-json->local-vendor-cli';
const HOOK_NAME = 'memorable-user-prompt-hook';
/** Per-KiB allowance added to the scan admission check: ~1.5x the measured worst case of scan(). */
const SCAN_MS_PER_KIB = 1;
/** Distinct rate-limit keys remembered at once (the marker file is rewritten on every log line). */
const RATE_LIMIT_KEYS = 32;
/** Candidate objects tried by the tolerant stdout parser before giving up (bounds a hostile brace soup). */
const JSON_CANDIDATES = 64;
const GIT_MAX_BUFFER = 64 * 1024;
@@ -299,44 +299,16 @@ export function resolveVendor(env: Record<string, string | undefined>, homeDir:
return onPath && executable(onPath) ? onPath : null;
}
function stateRoot(): string {
return process.env.GSTACK_STATE_ROOT || process.env.GSTACK_HOME || process.env.GSTACK_STATE_DIR
|| path.join(os.homedir(), '.gstack');
}
/**
* Best-effort, rate-limited: a message with the same `key` (default: the
* message itself) within LOG_RATE_LIMIT_MS is not re-logged, so a vendor that
* fails on every prompt with a different timestamp in its stderr still costs
* one line per ten minutes, and two alternating failures cost two. The marker
* (up to RATE_LIMIT_KEYS live `digest:ts` lines) is per hook so hooks never
* contend. The log is chmod 0600 on every append: sibling hooks create the
* same file without a mode, and it can name the session's cwd and vendor
* Best-effort, rate-limited (hook-log.ts): a message with the same `key`
* (default: the message itself) within LOG_RATE_LIMIT_MS is not re-logged, so
* a vendor that fails on every prompt with a different timestamp in its stderr
* still costs one line per ten minutes, and two alternating failures cost two.
* The log is 0600 on every append; it can name the session's cwd and vendor
* diagnostics.
*/
export function logHookError(msg: string, nowMs: number = Date.now(), key: string = msg): void {
try {
const root = stateRoot();
fs.mkdirSync(root, { recursive: true });
const marker = path.join(root, `hook-errors.${HOOK_NAME}.last`);
const digest = sha256Hex(key).slice(0, 16);
const live: string[] = [];
try {
for (const line of fs.readFileSync(marker, 'utf8').split('\n')) {
const [d, ts] = line.trim().split(':');
if (!d || !ts || nowMs - Number(ts) >= LOG_RATE_LIMIT_MS) continue;
if (d === digest) return;
live.push(line.trim());
}
} catch { /* no marker yet */ }
live.push(`${digest}:${nowMs}`);
fs.writeFileSync(marker, `${live.slice(-RATE_LIMIT_KEYS).join('\n')}\n`, { mode: 0o600 });
const log = path.join(root, 'hook-errors.log');
fs.appendFileSync(log, `${new Date(nowMs).toISOString()} ${HOOK_NAME}: ${msg}\n`, { mode: 0o600 });
if (process.platform !== 'win32') { try { fs.chmodSync(log, 0o600); } catch { /* not ours to tighten */ } }
} catch {
// best-effort; never block the session because logging failed
}
sharedLogHookError(HOOK_NAME, msg, { rateLimit: { nowMs, key } });
}
function readStdin(maxBytes: number, timeoutMs: number): Promise<{ buf: Buffer; oversize: boolean; timedOut: boolean }> {
+2 -14
View File
@@ -35,8 +35,8 @@
import * as crypto from 'crypto';
import * as fs from 'fs';
import * as path from 'path';
import * as os from 'os';
import { runBin } from './spawn-bin';
import { logHookError as sharedLogHookError } from './hook-log';
interface HookStdin {
session_id?: string;
@@ -69,19 +69,7 @@ const MARKER_RE = /<gstack-qid:([a-z0-9-]{1,64})>/i;
const RECOMMENDED_LABEL_RE = /\(recommended\)\s*$/i;
function logHookError(msg: string): void {
try {
const stateRoot =
process.env.GSTACK_STATE_ROOT ||
process.env.GSTACK_HOME ||
path.join(os.homedir(), '.gstack');
fs.mkdirSync(stateRoot, { recursive: true });
fs.appendFileSync(
path.join(stateRoot, 'hook-errors.log'),
`${new Date().toISOString()} question-log-hook: ${msg}\n`,
);
} catch {
// Last-resort: swallow. Hook must not block.
}
sharedLogHookError('question-log-hook', msg);
}
function readStdin(): Promise<string> {
+4 -18
View File
@@ -42,11 +42,12 @@
*/
import * as fs from 'fs';
import * as path from 'path';
import * as os from 'os';
import { runBin, repoRoot } from './spawn-bin';
import { isConductor } from '../../../lib/is-conductor';
import { classifyQuestion } from '../../../scripts/one-way-doors';
import { SPAWNED_ESCAPE_SENTENCE, CONDUCTOR_SPAWNED_DENY_REASON, spawnedByEnv } from './spawned-directive';
import { resolveStateRoot } from '../../../lib/state-root';
import { logHookError as sharedLogHookError } from './hook-log';
interface HookStdin {
session_id?: string;
@@ -66,25 +67,10 @@ interface HookStdin {
const MARKER_RE = /<gstack-qid:([a-z0-9-]{1,64})>/i;
const RECOMMENDED_LABEL_RE = /\(recommended\)\s*$/i;
function stateRoot(): string {
return (
process.env.GSTACK_STATE_ROOT ||
process.env.GSTACK_HOME ||
path.join(os.homedir(), '.gstack')
);
}
const stateRoot = (): string => resolveStateRoot();
function logHookError(msg: string): void {
try {
const sr = stateRoot();
fs.mkdirSync(sr, { recursive: true });
fs.appendFileSync(
path.join(sr, 'hook-errors.log'),
`${new Date().toISOString()} question-preference-hook: ${msg}\n`,
);
} catch {
// last-resort swallow
}
sharedLogHookError('question-preference-hook', msg);
}
function readStdin(): Promise<string> {
+4 -15
View File
@@ -38,6 +38,8 @@ import * as fs from 'fs';
import * as os from 'os';
import * as path from 'path';
import { runBin } from './spawn-bin';
import { resolveStateRoot } from '../../../lib/state-root';
import { logHookError as sharedLogHookError } from './hook-log';
const DEADLINE_MS = 2000;
const MAX_TIMELINE_BYTES = 10 * 1024 * 1024;
@@ -68,21 +70,8 @@ function readTimelineTail(timelinePath: string, size: number): string {
}
}
function stateRoot(): string {
return process.env.GSTACK_HOME || path.join(os.homedir(), '.gstack');
}
function logHookError(msg: string): void {
try {
const root = stateRoot();
fs.mkdirSync(root, { recursive: true });
fs.appendFileSync(
path.join(root, 'hook-errors.log'),
`${new Date().toISOString()} timeline-stop-hook: ${msg}\n`,
);
} catch {
// best-effort; never block the session because logging failed
}
sharedLogHookError('timeline-stop-hook', msg);
}
interface TimelineEntry {
@@ -120,7 +109,7 @@ function main(): void {
return;
}
const timelinePath = path.join(stateRoot(), 'projects', slug, 'timeline.jsonl');
const timelinePath = path.join(resolveStateRoot(), 'projects', slug, 'timeline.jsonl');
let stat: fs.Stats;
try {
stat = fs.statSync(timelinePath);
+81
View File
@@ -0,0 +1,81 @@
/**
* hosts/claude/hooks/hook-log.ts is the one hook-errors.log writer. All five
* Claude Code hooks must log under the same resolved state root for the same
* env, and the log must end up 0600 even when it already existed as 0644.
*/
import { describe, test, expect } from 'bun:test';
import { spawnSync } from 'child_process';
import * as fs from 'fs';
import * as os from 'os';
import * as path from 'path';
const ROOT = path.resolve(import.meta.dir, '..');
const HOOKS = path.join(ROOT, 'hosts', 'claude', 'hooks');
function runHook(name: string, stdin: string, env: Record<string, string>, cwd: string) {
return spawnSync('bash', [path.join(HOOKS, name)], {
input: stdin,
cwd,
env: { ...process.env, GSTACK_STATE_ROOT: '', GSTACK_STATE_DIR: '', CLAUDE_PLUGIN_DATA: '', ...env },
encoding: 'utf-8',
timeout: 30_000,
});
}
describe('hook-log: one root, one mode', () => {
test('all five hooks append to <resolved root>/hook-errors.log, and a 0644 log becomes 0600', () => {
const tmp = fs.mkdtempSync(path.join(os.tmpdir(), 'gstack-hook-log-'));
try {
const state = path.join(tmp, 'state');
const home = path.join(tmp, 'home');
const proj = path.join(tmp, 'hooklog-proj');
fs.mkdirSync(state, { recursive: true });
fs.mkdirSync(home, { recursive: true });
fs.mkdirSync(proj, { recursive: true });
const log = path.join(state, 'hook-errors.log');
fs.writeFileSync(log, '');
fs.chmodSync(log, 0o644);
const env = { GSTACK_HOME: state, HOME: home };
for (const hook of ['question-log-hook', 'question-preference-hook', 'auq-error-fallback-hook', 'memorable-user-prompt-hook']) {
const r = runHook(hook, '{not json', env, proj);
expect(r.status).toBe(0);
}
const slug = spawnSync('bash', [path.join(ROOT, 'bin', 'gstack-slug')], { cwd: proj, env: { ...process.env, ...env }, encoding: 'utf-8', timeout: 30_000 })
.stdout.match(/^SLUG=(.+)$/m)?.[1];
expect(slug).toBeTruthy();
const timeline = path.join(state, 'projects', slug!, 'timeline.jsonl');
fs.mkdirSync(path.dirname(timeline), { recursive: true });
fs.writeFileSync(timeline, '');
fs.truncateSync(timeline, 10 * 1024 * 1024 + 1);
expect(runHook('timeline-stop-hook', JSON.stringify({ cwd: proj }), env, proj).status).toBe(0);
const text = fs.readFileSync(log, 'utf-8');
for (const hook of ['question-log-hook', 'question-preference-hook', 'auq-error-fallback-hook', 'memorable-user-prompt-hook', 'timeline-stop-hook']) {
expect(text).toContain(` ${hook}: `);
}
expect(fs.existsSync(path.join(home, '.gstack', 'hook-errors.log'))).toBe(false);
if (process.platform !== 'win32') expect(fs.statSync(log).mode & 0o777).toBe(0o600);
} finally {
fs.rmSync(tmp, { recursive: true, force: true });
}
});
test('rate limit drops a repeat key within the window and logs it again after', async () => {
const tmp = fs.mkdtempSync(path.join(os.tmpdir(), 'gstack-hook-log-rl-'));
const saved = process.env.GSTACK_HOME;
process.env.GSTACK_HOME = tmp;
try {
const { logHookError, LOG_RATE_LIMIT_MS } = await import('../hosts/claude/hooks/hook-log');
logHookError('rl-hook', 'first', { rateLimit: { nowMs: 1_000, key: 'k' } });
logHookError('rl-hook', 'second', { rateLimit: { nowMs: 2_000, key: 'k' } });
logHookError('rl-hook', 'third', { rateLimit: { nowMs: 1_000 + LOG_RATE_LIMIT_MS, key: 'k' } });
logHookError('rl-hook', 'plain');
const lines = fs.readFileSync(path.join(tmp, 'hook-errors.log'), 'utf-8').trim().split('\n');
expect(lines.map((l) => l.split(': ')[1])).toEqual(['first', 'third', 'plain']);
} finally {
if (saved === undefined) delete process.env.GSTACK_HOME; else process.env.GSTACK_HOME = saved;
fs.rmSync(tmp, { recursive: true, force: true });
}
});
});