diff --git a/scripts/agent-eval/bench-readme.sh b/scripts/agent-eval/bench-readme.sh index 60a5330..67c01b6 100644 --- a/scripts/agent-eval/bench-readme.sh +++ b/scripts/agent-eval/bench-readme.sh @@ -1,28 +1,47 @@ #!/usr/bin/env bash # Re-run the README "Benchmark Results" A/B (with vs without codegraph) on the # current build: the 7 README repos, same queries, RUNS per arm (default 4). -# Output → /tmp/ab-readme//run/run-headless-{with,without}.jsonl +# Output → /tmp/ab-readme//run/run-headless-{with,without}[.tN].jsonl # Aggregate with parse-bench-readme.mjs. Repos must be cloned + indexed under # $CORPUS (default /tmp/codegraph-corpus) by the build under test. +# +# Each row is a THREE-TURN session: the README question, then two follow-ups +# that stay inside the same flow. Turns 2-3 are where residual context occupancy +# is actually charged — the first answer's tool output is still in the window, +# so the arms diverge on how much headroom each left behind. CG_TURNS=1 runs the +# README question alone (the original single-question A/B). set -uo pipefail H="$(cd "$(dirname "$0")" && pwd)" C="${CORPUS:-/tmp/codegraph-corpus}" RUNS="${RUNS:-4}" +TURNS="${CG_TURNS:-3}" ROWS=( -"vscode|How does the extension host communicate with the main process?" -"excalidraw|How does Excalidraw render and update canvas elements?" -"django|How does Django's ORM build and execute a query from a QuerySet?" -"tokio|How does tokio schedule and run async tasks on its runtime?" -"okhttp|How does OkHttp process a request through its interceptor chain?" -"gin|How does gin route requests through its middleware chain?" -"alamofire|How does Alamofire build, send, and validate a request?" +"vscode|How does the extension host communicate with the main process?|Where in that path would a message be dropped if the extension host crashes?|What would I need to change to add a new message type to that protocol?" +"excalidraw|How does Excalidraw render and update canvas elements?|Which part of that path decides whether a full re-render happens or an incremental one?|If I added a new element type, what in that render path would need to change?" +"django|How does Django's ORM build and execute a query from a QuerySet?|Where in that path is the SQL actually compiled into a string?|What would I change to add a new lookup type to that pipeline?" +"tokio|How does tokio schedule and run async tasks on its runtime?|Where does a task move between the local and the global queue in that path?|What in that path would I touch to add a per-task instrumentation hook?" +"okhttp|How does OkHttp process a request through its interceptor chain?|Where in that chain is the connection actually acquired?|What would I change to add a new interceptor stage before the cache?" +"gin|How does gin route requests through its middleware chain?|Where is the 404 / no-route case handled in that same chain?|What would I change to add a per-route middleware that runs before the global ones?" +"alamofire|How does Alamofire build, send, and validate a request?|Where does retry / interceptor logic hook into that path?|What would I change to add a new validation step to it?" ) -echo "### README A/B START $(date) RUNS=$RUNS" +echo "### README A/B START $(date) RUNS=$RUNS TURNS=$TURNS" for row in "${ROWS[@]}"; do - repo="${row%%|*}"; q="${row#*|}" - echo "===== $repo =====" + repo="${row%%|*}"; rest="${row#*|}" + # Take the first $TURNS questions and join them with "||" for run-all.sh. + q=""; n=0 + while [ "$n" -lt "$TURNS" ] && [ -n "$rest" ]; do + part="${rest%%|*}" + if [ "$rest" = "$part" ]; then rest=""; else rest="${rest#*|}"; fi + [ -n "$q" ] && q="$q||" + q="$q$part"; n=$((n + 1)) + done + echo "===== $repo ($n turns) =====" for run in $(seq 1 "$RUNS"); do - AGENT_EVAL_OUT="/tmp/ab-readme/$repo/run$run" bash "$H/run-all.sh" "$C/$repo" "$q" headless 2>&1 | grep -E "exit [0-9]" || echo " run$run: (no exit line)" + out="/tmp/ab-readme/$repo/run$run" + mkdir -p "$out" + AGENT_EVAL_OUT="$out" bash "$H/run-all.sh" "$C/$repo" "$q" headless > "$out/console.log" 2>&1 + grep -E "^exit [0-9]" "$out/console.log" | sed 's/^/ /' || echo " run$run: (no exit line)" + grep -E "codegraph +[0-9,]+ tok|→ file-access" "$out/console.log" | sed 's/^/ /' || true done done echo "### README A/B DONE $(date)" diff --git a/scripts/agent-eval/parse-bench-readme.mjs b/scripts/agent-eval/parse-bench-readme.mjs index f7c5ade..e0cf4af 100644 --- a/scripts/agent-eval/parse-bench-readme.mjs +++ b/scripts/agent-eval/parse-bench-readme.mjs @@ -1,71 +1,87 @@ #!/usr/bin/env node // Aggregate the README A/B (bench-readme.sh output): per repo, median of N runs -// per arm → time, tool calls, tokens, cost, and % saved. Plus an average row. +// per arm → time, tool calls, tokens, cost, % saved, and RESIDUAL CONTEXT +// OCCUPANCY. Plus an average row. // // Tokens = SUM of per-turn assistant `usage` (input + output + cache read + // cache creation) — the cumulative "total tokens processed". NOTE: `result.usage` -// is last-turn-only in current Claude Code, so it under-counts badly; don't use it. -// `total_cost_usd` and `duration_ms` are already cumulative. +// is last-turn-only in some Claude Code versions, so reading it alone can +// under-count badly; parseSession() sums per-segment and dedupes assistant +// events by message.id (Claude Code emits one event per content block, each +// carrying the same usage — summing per EVENT double-counts). +// +// The occupancy table answers the question "tokens processed" cannot: how much +// of the window each arm's tool output STILL OCCUPIES when the run ends. Under +// multi-turn rows that residual is charged against every following turn. // // Usage: node parse-bench-readme.mjs [/tmp/ab-readme] -import { readFileSync, existsSync, readdirSync } from 'fs'; +import { existsSync, readdirSync } from 'fs'; import { join } from 'path'; +import { parseSession } from './parse-run.mjs'; + const ROOT = process.argv[2] || '/tmp/ab-readme'; const REPOS = ['vscode', 'excalidraw', 'django', 'tokio', 'okhttp', 'gin', 'alamofire']; -function parse(file) { - if (!existsSync(file)) return null; - const L = readFileSync(file, 'utf8').split('\n').filter(Boolean); - let tools = 0, reads = 0, grep = 0, cg = 0, tokens = 0, r = null, raced = false; - for (const l of L) { let e; try { e = JSON.parse(l); } catch { continue; } - if (e.type === 'assistant') { - const u = e.message?.usage; - if (u) tokens += (u.input_tokens || 0) + (u.output_tokens || 0) + (u.cache_read_input_tokens || 0) + (u.cache_creation_input_tokens || 0); - for (const b of (e.message?.content || [])) if (b.type === 'tool_use') { - const n = b.name; - if (n === 'ToolSearch') continue; - tools++; - if (n === 'Read') reads++; - else if (n === 'Grep' || n === 'Glob') grep++; - else if (/codegraph/.test(n)) cg++; - } - } - // MCP cold-start race: the headless agent fired before `codegraph serve --mcp` - // finished registering its tools, so early calls returned "No such tool - // available" and the agent floundered into grep/Read. That measures CodeGraph's - // startup latency, NOT its steady-state value — flag the run so the aggregate - // can exclude it (an artifact of headless first-turn timing, not the tool). - if (e.type === 'user') for (const b of (Array.isArray(e.message?.content) ? e.message.content : [])) { - if (b.type === 'tool_result') { - const t = Array.isArray(b.content) ? b.content.map(c => c.text || '').join('') : (b.content || ''); - if (/No such tool available/.test(t)) raced = true; - } - } - if (e.type === 'result') r = e; - } - if (!r || r.subtype !== 'success') return null; - return { dur: r.duration_ms / 1000, tools, reads, grep, cg, tokens, cost: r.total_cost_usd || 0, raced }; +/** All segment files of one arm's session, in turn order (t1, t2, t3, …). */ +function segments(dir, label) { + const first = join(dir, `run-${label}.jsonl`); + if (!existsSync(first)) return null; + const rest = readdirSync(dir) + .map((f) => [f, new RegExp(`^run-${label}\\.t(\\d+)\\.jsonl$`).exec(f)]) + .filter(([, m]) => m) + .sort((a, b) => Number(a[1][1]) - Number(b[1][1])) + .map(([f]) => join(dir, f)); + return [first, ...rest]; } + +function parse(dir, label) { + const files = segments(dir, label); + if (!files) return null; + const s = parseSession(files); + if (!s.ok) return null; + const o = s.occupancy; + return { + dur: s.dur, tools: s.tools, reads: s.reads, grep: s.grep, cg: s.cg, + tokens: s.processed, cost: s.cost, raced: s.raced, turns: s.turns, + segments: files.length, + ctx: o.ctxFinal, + occCg: o.residual.codegraph, + occFile: o.residualFileAccess, + // The arm's own retrieval residual: codegraph in the with-arm, Read/Grep/Bash + // in the without-arm. Comparing these is the apples-to-apples pair. + occSelf: o.residual.codegraph + o.residualFileAccess, + occShareCtx: o.ctxFinal > 0 ? ((o.residual.codegraph + o.residualFileAccess) / o.ctxFinal) * 100 : 0, + occShareWin: ((o.residual.codegraph + o.residualFileAccess) / o.windowTokens) * 100, + window: o.windowTokens, + }; +} + const median = (arr) => { const v = [...arr].sort((a, b) => a - b); const n = v.length; return n === 0 ? 0 : n % 2 ? v[(n - 1) / 2] : (v[n / 2 - 1] + v[n / 2]) / 2; }; const fmtTime = (s) => s >= 60 ? `${Math.floor(s / 60)}m ${Math.round(s % 60)}s` : `${Math.round(s)}s`; const fmtTok = (t) => t >= 1e6 ? `${(t / 1e6).toFixed(1)}M` : `${Math.round(t / 1000)}k`; const pct = (w, wo) => wo > 0 ? Math.round((1 - w / wo) * 100) : 0; -console.log('repo n(w/wo) time WITH→WITHOUT tools W→WO tokens W→WO (saved) cost W→WO (saved)'); -const savings = { cost: [], tokens: [], time: [], tools: [] }; +// Exclude MCP-cold-start-raced WITH runs by default — they measure a startup +// race, not steady-state value. `CG_INCLUDE_RACED=1` keeps them (to see the raw +// distribution). The WITHOUT arm has no MCP, so it's never raced. +const includeRaced = process.env.CG_INCLUDE_RACED === '1'; +const rows = []; for (const repo of REPOS) { const dir = join(ROOT, repo); - const runDirs = existsSync(dir) ? readdirSync(dir).filter(d => /^run\d+$/.test(d)) : []; - // Exclude MCP-cold-start-raced WITH runs by default — they measure a startup - // race, not steady-state value. `CG_INCLUDE_RACED=1` keeps them (to see the raw - // distribution). The WITHOUT arm has no MCP, so it's never raced. - const includeRaced = process.env.CG_INCLUDE_RACED === '1'; + const runDirs = existsSync(dir) ? readdirSync(dir).filter(d => /^run\d+$/.test(d)).sort() : []; const W = [], WO = []; let racedExcluded = 0; for (const rd of runDirs) { - const w = parse(join(dir, rd, 'run-headless-with.jsonl')); + const w = parse(join(dir, rd), 'headless-with'); if (w) { if (w.raced && !includeRaced) racedExcluded++; else W.push(w); } - const wo = parse(join(dir, rd, 'run-headless-without.jsonl')); if (wo) WO.push(wo); + const wo = parse(join(dir, rd), 'headless-without'); if (wo) WO.push(wo); } + rows.push({ repo, W, WO, racedExcluded }); +} + +// ---- Table 1: the existing throughput view. -------------------------------- +console.log('repo n(w/wo) time WITH→WITHOUT tools W→WO tokens W→WO (saved) cost W→WO (saved)'); +const savings = { cost: [], tokens: [], time: [], tools: [] }; +for (const { repo, W, WO, racedExcluded } of rows) { if (!W.length || !WO.length) { console.log(`${repo.padEnd(11)} (incomplete: w=${W.length} wo=${WO.length})`); continue; } const m = (arr, k) => median(arr.map(x => x[k])); const wT = m(W, 'dur'), woT = m(WO, 'dur'), wTok = m(W, 'tokens'), woTok = m(WO, 'tokens'); @@ -82,3 +98,38 @@ for (const repo of REPOS) { } const avg = (a) => a.length ? Math.round(a.reduce((s, x) => s + x, 0) / a.length) : 0; console.log(`\nAVERAGE saved: cost ${avg(savings.cost)}% · tokens ${avg(savings.tokens)}% · time ${avg(savings.time)}% · tool calls ${avg(savings.tools)}%`); + +// ---- Table 2: residual context occupancy. ---------------------------------- +// WITH's retrieval residual is codegraph's tool output; WITHOUT's is Read + +// Grep/Glob + Bash. Same question, same window — so the pair is comparable. +const anyMulti = rows.some(({ W, WO }) => [...W, ...WO].some(r => r.segments > 1)); +console.log(`\n\nRESIDUAL CONTEXT OCCUPANCY — retrieval tokens still in the window at end of run`); +console.log(`(WITH = codegraph responses · WITHOUT = Read + Grep/Glob + Bash responses)`); +console.log(`${anyMulti ? 'multi-turn sessions' : 'SINGLE-TURN sessions — see the caveat below'}\n`); +console.log('repo turns final ctx W→WO residual W→WO % of ctx W→WO % of window W→WO'); +const occ = { resid: [], shareCtx: [] }; +for (const { repo, W, WO } of rows) { + if (!W.length || !WO.length) { console.log(`${repo.padEnd(11)} (incomplete)`); continue; } + const m = (arr, k) => median(arr.map(x => x[k])); + const wR = m(W, 'occSelf'), woR = m(WO, 'occSelf'); + const wCtx = m(W, 'ctx'), woCtx = m(WO, 'ctx'); + const wSc = m(W, 'occShareCtx'), woSc = m(WO, 'occShareCtx'); + const wSw = m(W, 'occShareWin'), woSw = m(WO, 'occShareWin'); + occ.resid.push(pct(wR, woR)); occ.shareCtx.push(pct(wSc, woSc)); + console.log( + `${repo.padEnd(11)} ${String(median(W.map(x => x.turns)) + '/' + median(WO.map(x => x.turns))).padEnd(7)} ` + + `${(fmtTok(wCtx) + '→' + fmtTok(woCtx)).padEnd(21)}` + + `${(fmtTok(wR) + '→' + fmtTok(woR) + ' (' + pct(wR, woR) + '%)').padEnd(22)}` + + `${(wSc.toFixed(1) + '%→' + woSc.toFixed(1) + '%').padEnd(18)}` + + `${wSw.toFixed(1)}%→${woSw.toFixed(1)}%` + ); +} +console.log(`\nAVERAGE: retrieval residual ${avg(occ.resid)}% lower with codegraph · share-of-context ${avg(occ.shareCtx)}% lower`); +if (!anyMulti) { + console.log( + `\nCAVEAT: every row above is a SINGLE-turn session, so the residual is measured at the\n` + + `moment the one question is answered. Occupancy is a cost that compounds over the turns\n` + + `that FOLLOW; a single-turn number does not settle it. Re-run with "||"-separated\n` + + `follow-ups (see run-all.sh) to measure the regime this metric is actually about.` + ); +} diff --git a/scripts/agent-eval/parse-run.mjs b/scripts/agent-eval/parse-run.mjs index 6d64d58..d227dc3 100644 --- a/scripts/agent-eval/parse-run.mjs +++ b/scripts/agent-eval/parse-run.mjs @@ -1,45 +1,321 @@ #!/usr/bin/env node -// Parse a Claude Code stream-json run log: tool-call sequence + token usage. +// Parse Claude Code stream-json run log(s): tool-call sequence, token usage, and +// RESIDUAL CONTEXT OCCUPANCY — how many tokens of the context window each tool +// family's responses still occupy when the run ends. +// +// Usage: parse-run.mjs [run.t2.jsonl ...] +// Multiple files = one multi-turn session's segments, IN ORDER (run-all.sh +// writes run-