test(agent-eval): measure residual context occupancy, over multi-turn sessions (CG-7)
The A/B arms reported cost, tokens, time and tool counts for one headless question. They could not report what issue #1500 actually measured: how much of the context window a tool's responses still occupy once the question is answered, which every later turn is then charged for. parse-run.mjs now measures that. Tokens are measured, not estimated: for each assistant request, input + cache_read + cache_creation is the exact token count of its whole prompt, so consecutive requests differ by exactly what was appended between them. That delta is priced against the characters in the gap, calibrated on gaps that are >=80% tool result. Explore output lands near 2.3 chars/token, so the usual bytes/4 estimate would have under-counted it by ~40%. Content also leaves the window, so residual is tracked apart from contributed: a compact_boundary clears the resident set, and a mid-run context drop is micro-compaction, which sheds the oldest tool results first and is applied FIFO. run-all.sh takes "Q1||Q2||Q3" and runs them as one resumed session, one segment file per turn; parse-run.mjs stitches the segments back together. bench-readme.sh now runs each README repo as a three-turn session (CG_TURNS=1 restores the single-question form). parse-bench-readme.mjs reports the arms' retrieval residual side by side -- codegraph's responses against the without-arm's Read/Grep/Bash -- in absolute tokens, share of context, and share of window, and says so explicitly when the rows it aggregated were single-turn. Two transcript traps are handled and documented at the call site: Claude Code emits one assistant event per content block, all carrying the same usage (summing per event double-counts every turn with both thinking and a tool_use), and the streamed output_tokens is a partial snapshot. Occupancy lives in parse-run.mjs and is imported by the aggregator rather than extracted to a module -- a new scripts/agent-eval/*.mjs scores into the self-query fixture's own corpus and moves its numbers.
This commit is contained in:
Colby McHenry
@@ -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.`
|
||||
);
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user