measure-journal-read.ts
171 lines · scripts/measure-journal-read.ts at 3f79d81
1#!/usr/bin/env -S bun --no-env-file --config=/dev/null
2/**
3 * CEO-2 / CEO-6 acceptance for the /autoplan guard's bounded journal read:
4 * build a synthetic parent journal around one real /autoplan invocation, keep
5 * appending to it while the guard runs, and measure one hook call (read plus
6 * evaluation) in a fresh process: wall milliseconds and peak RSS.
7 *
8 * bun scripts/measure-journal-read.ts [--runs N] [--json] [--strict]
9 *
10 * Two journals, 120 MiB each:
11 * - `mixed`: many records of mixed size (assistant text, Bash and Read pairs,
12 * hook attachments), about 10% before the invocation and the rest inside it.
13 * - `large-invocation`: a current invocation of many small records.
14 * Acceptance (CEO-2): at most 1000 ms and 256 MiB peak RSS on a 4-vCPU Linux
15 * runner, with an allow decision. macOS numbers are recorded, not gated
16 * (CEO-6). `--strict` exits 1 on a miss. `--measure` and `--append` are the
17 * per-run child modes; `--build <benchmark>` writes one journal and prints its
18 * metadata path, for profiling.
19 */
20import * as fs from 'node:fs';
21import * as path from 'node:path';
22import * as os from 'node:os';
23import { randomUUID } from 'node:crypto';
25const MiB = 1024 * 1024;
26const BUDGET_MS = 1000, BUDGET_RSS_MIB = 256;
27type Row = { type: string; message?: Record<string, unknown>; extra?: Record<string, unknown> };
28type RowMaker = (rnd: () => number, i: number) => Row;
29/** Shares of the journal: before /autoplan (`head`), inside its phase work, and after the close Read. */
30interface Benchmark { name: string; bytes: number; headShare: number; afterCloseShare: number; head: RowMaker; window: RowMaker }
32/** Deterministic, so every runner measures the same journal. */
33function random(seed: number) { return () => (seed = (seed * 1103515245 + 12345) % 2147483648) / 2147483648; }
34const pad = (n: number) => 'x'.repeat(Math.max(0, Math.round(n)));
35/** The envelope Claude Code writes on every assistant message (model, usage), so record sizes match real journals. */
36const assistant = (i: number, content: unknown[]): Row => ({ type: 'assistant', message: { id: `msg_pad${i}`, type: 'message', role: 'assistant',
37 model: 'claude-opus-4-1-20250805', content, stop_reason: null, stop_sequence: null,
38 usage: { input_tokens: 4, cache_creation_input_tokens: 812, cache_read_input_tokens: 48213, output_tokens: 312, service_tier: 'standard' } },
39 extra: { requestId: `req_pad${i}`, userType: 'external', gitBranch: 'main' } });
41function mixedRow(rnd: () => number, i: number): Row {
42 const p = rnd(), id = `toolu_pad${i}`;
43 if (p < 0.4) return assistant(i, [{ type: 'text', text: pad(300 + rnd() * 900) }]);
44 if (p < 0.55) return assistant(i, [{ type: 'tool_use', id, name: 'Bash', input: { command: `ls ${pad(40)}` } }]);
45 if (p < 0.7) return { type: 'user', message: { role: 'user', content: [{ type: 'tool_result', tool_use_id: `${id}b`, content: pad(300 + rnd() * 2700), is_error: false }] },
46 extra: { toolUseResult: { stdout: pad(100), stderr: '' } } };
47 if (p < 0.78) {
48 const content = pad(4000 + rnd() * 36000);
49 return { type: 'user', message: { role: 'user', content: [{ type: 'tool_result', tool_use_id: `${id}r`, content }] },
50 extra: { toolUseResult: { type: 'text', file: { filePath: '/repo/src/file.ts', content, numLines: 400, startLine: 1, totalLines: 400 } } } };
51 }
52 return { type: 'attachment', extra: { attachment: { type: 'hook_success', hookEvent: 'PostToolUse', content: pad(150 + rnd() * 300) } } };
53}
55function smallRow(rnd: () => number, i: number): Row {
56 const p = rnd(), id = `toolu_small${i}`;
57 if (p < 0.35) return assistant(i, [{ type: 'text', text: pad(40 + rnd() * 160) }]);
58 if (p < 0.6) return assistant(i, [{ type: 'tool_use', id, name: 'Grep', input: { pattern: 'x' } }]);
59 if (p < 0.85) return { type: 'user', message: { role: 'user', content: [{ type: 'tool_result', tool_use_id: `${id}g`, content: pad(20 + rnd() * 200), is_error: false }] } };
60 return { type: 'attachment', extra: { attachment: { type: 'hook_success', hookEvent: 'PostToolUse', content: pad(50) } } };
61}
63const BENCHMARKS: Benchmark[] = [
64 { name: 'mixed', bytes: 120 * MiB, headShare: 0.1, afterCloseShare: 0.02, head: mixedRow, window: mixedRow },
65 // ENG-5: a current invocation of many small records (about 60k), after an ordinary mixed history.
66 { name: 'large-invocation', bytes: 120 * MiB, headShare: 0.6, afterCloseShare: 0.01, head: mixedRow, window: smallRow },
67];
69/** Build one journal: a published Phase 1 and the Phase 2 entry Read as the current, journaled call. */
70async function build(bench: Benchmark) {
71 const { guardFixture, section } = await import('../test/helpers/autoplan-guard-fixture');
72 const f = guardFixture('ceo');
73 f.publish();
74 f.use('next', 'Read', { file_path: section('design-phase.md') });
75 const step = (id: string) => f.steps.findIndex(s => s.kind === 'result' && s.id === id);
76 const head = bench.bytes * bench.headShare, after = bench.bytes * bench.afterCloseShare, window = bench.bytes - head - after;
77 const rnd = random(bench.name.length);
78 let i = 0, records = 0;
79 const fill = (budget: number, row: RowMaker) => {
80 const rows: Row[] = [];
81 // About 300 bytes of per-record metadata (uuid, parent, cwd, session, version, timestamp) join each row.
82 for (let used = 0; used < budget; i++) { const r = row(rnd, i); rows.push(r); used += JSON.stringify(r).length + 300; }
83 records += rows.length;
84 return rows;
85 };
86 // An earlier typed conversation that ended its turn; then /autoplan's phase work after init and after the
87 // entry Read; then a little after the close Read.
88 const earlier = (): Row[] => [{ type: 'user', message: { role: 'user', content: 'Review the retry change first.' },
89 extra: { origin: { kind: 'human' }, promptSource: 'typed', promptId: randomUUID() } }, ...fill(head, bench.head),
90 { type: 'assistant', message: { role: 'assistant', id: 'msg_earlier_end', content: [{ type: 'text', text: 'Done.' }], stop_reason: 'end_turn' } }];
91 f.journal(f.steps.length, at => at === -1 ? earlier() : at === step('init') || at === step('entry') ? fill(window / 2, bench.window)
92 : at === step('close') ? fill(after, bench.window) : []);
93 const input = f.input('next', 'Read', { file_path: section('design-phase.md') });
94 const meta = path.join(f.cwd, 'measure.json');
95 fs.writeFileSync(meta, JSON.stringify({ input, cwd: f.cwd, stateRoot: f.stateRoot }));
96 return { f, meta, records };
97}
99/** Child: one hook call in a fresh process; peak RSS is this process's own. */
100async function measure(meta: string) {
101 const { input, cwd, stateRoot } = JSON.parse(fs.readFileSync(meta, 'utf8'));
102 const { runPublicationHook } = await import('../autoplan/bin/phase-publication-hook.ts');
103 const root = fs.realpathSync(path.join(import.meta.dir, '..'));
104 process.env.CLAUDE_PROJECT_DIR = cwd; process.env.GSTACK_STATE_ROOT = stateRoot; process.env.GSTACK_HOME = stateRoot;
105 const started = performance.now();
106 const output: any = await runPublicationHook(input, root);
107 const wallMs = performance.now() - started;
108 const decision = output?.hookSpecificOutput?.permissionDecision === 'deny' ? `deny: ${output.hookSpecificOutput.permissionDecisionReason}`
109 : output?.systemMessage ? `unverified: ${output.systemMessage}` : 'allow';
110 // resourceUsage().maxRSS is in kilobytes on Linux and macOS.
111 process.stdout.write(JSON.stringify({ wallMs: Math.round(wallMs), peakRssMiB: Math.round(process.resourceUsage().maxRSS / 1024), decision }) + '\n');
112}
114/** Child: Claude Code keeps writing while the guard reads (progress records outside the conversation chain). */
115function append(file: string) {
116 const fd = fs.openSync(file, 'a');
117 let n = 0;
118 const tick = () => {
119 fs.writeSync(fd, JSON.stringify({ type: 'progress', uuid: randomUUID(), parentUuid: randomUUID(), isSidechain: false,
120 sessionId: path.basename(file, '.jsonl'), cwd: path.dirname(file), timestamp: new Date().toISOString(), data: pad(800), n: n++ }) + '\n');
121 setTimeout(tick, 1);
122 };
123 tick();
124}
126async function child(args: string[], timeoutMs: number) {
127 const proc = Bun.spawn([process.execPath, import.meta.path, ...args], { stdout: 'pipe', stderr: 'inherit' });
128 const timer = setTimeout(() => proc.kill(), timeoutMs);
129 const text = await new Response(proc.stdout).text();
130 clearTimeout(timer);
131 if ((await proc.exited) !== 0) throw new Error(`measure child failed: ${args.join(' ')}`);
132 return JSON.parse(text.trim());
133}
135async function main() {
136 const argv = process.argv.slice(2);
137 if (argv[0] === '--measure') return measure(argv[1]!);
138 if (argv[0] === '--append') return append(argv[1]!);
139 if (argv[0] === '--build') { const built = await build(BENCHMARKS.find(b => b.name === argv[1])!); return console.log(built.meta); }
140 const requested = argv.includes('--runs') ? Number(argv[argv.indexOf('--runs') + 1]) : 3;
141 const runs = Number.isInteger(requested) && requested > 0 ? requested : 3;
142 const results = [];
143 for (const bench of BENCHMARKS) {
144 const built = await build(bench);
145 try {
146 for (let run = 1; run <= runs; run++) {
147 const before = fs.statSync(built.f.transcript).size;
148 const appender = Bun.spawn([process.execPath, import.meta.path, '--append', built.f.transcript], { stdout: 'ignore', stderr: 'inherit' });
149 await Bun.sleep(50);
150 try {
151 const measured = await child(['--measure', built.meta], 60_000);
152 results.push({ benchmark: bench.name, run, journalMiB: Number((before / MiB).toFixed(1)), records: built.records,
153 appendedBytes: fs.statSync(built.f.transcript).size - before, ...measured,
154 pass: measured.wallMs <= BUDGET_MS && measured.peakRssMiB <= BUDGET_RSS_MIB && measured.decision === 'allow' });
155 } finally { appender.kill(); await appender.exited; }
156 }
157 } finally { built.f.cleanup(); }
158 }
159 const platform = { os: `${os.platform()} ${os.release()}`, arch: os.arch(), cpus: os.cpus().length, cpu: os.cpus()[0]?.model, bun: Bun.version };
160 if (argv.includes('--json')) process.stdout.write(JSON.stringify({ platform, budget: { ms: BUDGET_MS, rssMiB: BUDGET_RSS_MIB }, results }, null, 2) + '\n');
161 else {
162 console.log(`# Journal read measurement (${platform.os}, ${platform.arch}, ${platform.cpus} vCPU, Bun ${platform.bun})`);
163 console.log('| benchmark | run | journal MiB | records | appended bytes | wall ms | peak RSS MiB | decision | verdict |');
164 console.log('|---|---|---|---|---|---|---|---|---|');
165 for (const r of results) console.log(`| ${r.benchmark} | ${r.run} | ${r.journalMiB} | ${r.records} | ${r.appendedBytes} | ${r.wallMs} | ` +
166 `${r.peakRssMiB} | ${r.decision.slice(0, 60)} | ${r.pass ? 'PASS' : 'MISS'} |`);
167 }
168 if (argv.includes('--strict') && results.some(r => !r.pass)) process.exit(1);
169}
171await main();