Skip to content

Commit 8d5d8bd

Browse files
committed
fix: attribute subagent volume to the model that dispatched it
The tokens report read one model per session transcript (its head, or its tail as a fallback) and pinned every subagent in it to that model. Long sessions switch models with /model, so in a 7d sample 135 of 269 agents were attributed to a model the session was not on when it dispatched them, and the dispatch report - which stamps the model at dispatch time - disagreed with the tokens report about the same window. Each agent now resolves its session model in this order: the assistant message carrying the tool_use id named by the agent sidecar (in the session transcript, or in the parent agent transcript for nested agents), then the model in effect at the agent transcript's first timestamp (max timestamp <= launch, since a resumed transcript is not in chronological file order), and only then the transcript head/tail as before. The --session filter for main sessions is now per line model, since a switched session no longer belongs wholly to one.
1 parent 0f6679b commit 8d5d8bd

3 files changed

Lines changed: 177 additions & 22 deletions

File tree

commands/stats.md

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -30,14 +30,14 @@ the answer. A dispatch row is one line in a log whether it cost four
3030
thousand tokens or four million, and only the token report knows which
3131
model actually ran and how much it processed. Only the dispatch report
3232
knows what was asked for and what the session model was at that moment -
33-
it stamps the session at dispatch time, while the token side reads it from
34-
the parent transcript's head.
33+
both sides stamp the session at dispatch time - the token side matches each
34+
agent back to the assistant message that dispatched it.
3535

3636
So when a dispatch-side warning names an agent - a tier leak, or a dispatch
3737
below its pin - carry its volume from the "By agent" block into the
3838
sentence. When that volume is not there, say the count overstated it and
3939
name why: most often an agent from another plugin pinning a model cheaper
4040
than the session, which the dispatch log cannot see unless that agent is in
41-
FOREIGN_AGENT_PINS. When the two disagree
42-
and the window contains a mid-session /model switch, say that instead - the
43-
token side attributes those subagents to the model the session started on.
41+
FOREIGN_AGENT_PINS. When the two disagree,
42+
say that instead - the token side had no sidecar for those agents, or could
43+
not read the parent transcript.

hooks/dispatch-counter.mjs

Lines changed: 85 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -343,9 +343,10 @@ function readSlice(file, bytes, fromEnd) {
343343
}
344344

345345
function firstModelIn(file, bytes) {
346-
// Session-START model: the head of the session jsonl. Used by the tokens
347-
// report, which says so in its footer - a /model switch or fallback later
348-
// in the session is attributed to the start model.
346+
// Session-START model: the head of the session jsonl. The tokens report uses
347+
// it only as a LAST resort, when neither the dispatching assistant message
348+
// nor the timeline around the agent's first timestamp could name a model -
349+
// a /model switch later in the session is invisible to it.
349350
const m = readSlice(file, bytes, false).match(/"model":"(?:[a-z0-9-]+\.)*(claude-[a-z0-9.-]+)"/);
350351
return m?.[1] ?? null;
351352
}
@@ -733,6 +734,75 @@ if (process.argv[2] === "tokens") {
733734
return m && typeof m.agentType === "string" && m.agentType ? m : null;
734735
} catch { return null; }
735736
};
737+
// Which model DISPATCHED an agent. Every agent sidecar names the toolUseId of
738+
// the Agent tool_use block that spawned it, and that block lives on an
739+
// assistant line of the parent transcript whose message.model is the model the
740+
// session was on at that moment. Reading it there is what makes this report
741+
// agree with the dispatch log, which stamps the model at dispatch time: the
742+
// session head answered a different question, and in a 7d sample it gave 135
743+
// of 269 agents a model the session was no longer on when it dispatched them.
744+
// One read per parent transcript, memoized by path - the walk reaches a
745+
// subagents dir BEFORE the parent transcript beside it, and every agent in
746+
// that dir shares the same parent, so the index has to be built lazily.
747+
const dispatchCache = new Map(); // path -> { ids: Map(toolUseId -> model), timeline: [ts, model][] }
748+
const dispatchIndexOf = (file) => {
749+
const hit = dispatchCache.get(file);
750+
if (hit) return hit;
751+
const idx = { ids: new Map(), timeline: [] };
752+
dispatchCache.set(file, idx);
753+
let text;
754+
try { text = readFileSync(file, "utf-8"); } catch { return idx; }
755+
for (const line of text.split("\n")) {
756+
if (!line.includes('"assistant"')) continue;
757+
try {
758+
const obj = JSON.parse(line);
759+
if (obj.type !== "assistant") continue;
760+
const model = obj.message?.model;
761+
if (!model) continue;
762+
const ts = obj.timestamp ? Date.parse(obj.timestamp) : NaN;
763+
if (Number.isFinite(ts)) idx.timeline.push([ts, model]);
764+
if (!Array.isArray(obj.message.content)) continue;
765+
for (const b of obj.message.content) {
766+
if (b?.type === "tool_use" && b.id) idx.ids.set(b.id, model);
767+
}
768+
} catch {}
769+
}
770+
return idx;
771+
};
772+
// The agent transcript's own first timestamp - when it was launched.
773+
const launchedAt = (file) => {
774+
const m = readSlice(file, 8192, false).split("\n", 1)[0].match(/"timestamp":"([^"]+)"/);
775+
const ts = m ? Date.parse(m[1]) : NaN;
776+
return Number.isFinite(ts) ? ts : null;
777+
};
778+
const dispatchModelOf = (p, meta, sessionJsonl) => {
779+
if (!sessionJsonl) return null;
780+
const idx = dispatchIndexOf(sessionJsonl);
781+
if (meta?.toolUseId) {
782+
const own = idx.ids.get(meta.toolUseId);
783+
if (own) return own;
784+
// A nested agent (spawnDepth 2) was dispatched by another AGENT, so its
785+
// tool_use line sits in that agent's transcript, not the session's.
786+
if (meta.parentAgentId) {
787+
const up = dispatchIndexOf(join(dirname(p), `agent-${meta.parentAgentId}.jsonl`)).ids.get(meta.toolUseId);
788+
if (up) return up;
789+
}
790+
}
791+
// No sidecar, or a dispatch line this read could not see: the model in
792+
// effect when the agent started. MAX timestamp <= launch, not the last
793+
// assistant line in FILE order - a resumed session re-appends its history,
794+
// so file order is not chronological.
795+
const launch = launchedAt(p);
796+
if (launch != null) {
797+
let best = null, bestTs = -Infinity;
798+
for (const [ts, model] of idx.timeline) {
799+
if (ts <= launch && ts > bestTs) { bestTs = ts; best = model; }
800+
}
801+
if (best) return best;
802+
}
803+
if (!sessionModelCache.has(sessionJsonl)) sessionModelCache.set(sessionJsonl, sessionModelOf(sessionJsonl));
804+
return sessionModelCache.get(sessionJsonl);
805+
};
736806
const walk = (dir, depth) => {
737807
let entries;
738808
try { entries = readdirSync(dir, { withFileTypes: true }); } catch { return; }
@@ -770,27 +840,29 @@ if (process.argv[2] === "tokens") {
770840
if (!fileVols.size) continue;
771841
if (isMainSession) {
772842
// Scoped by the same --session filter as the agents, so the denominator
773-
// always describes the same population as the headline above it.
774-
if (!sessionModelCache.has(p)) sessionModelCache.set(p, sessionModelOf(p));
775-
const sessionModel = sessionModelCache.get(p);
776-
if (sf && !(sessionModel && shortModel(sessionModel).toLowerCase().includes(sf))) continue;
777-
mainSessions++;
843+
// always describes the same population as the headline above it. Per
844+
// LINE model, not per file: agents are attributed at dispatch time now,
845+
// so a session that switched mid-way contributes only the volume that
846+
// actually ran on the filtered model, and counts as a session only if
847+
// any of it did.
848+
let matched = false;
778849
for (const [model, v] of fileVols) {
850+
if (sf && !shortModel(model).toLowerCase().includes(sf)) continue;
851+
matched = true;
779852
mainPerModel.set(model, (mainPerModel.get(model) ?? 0) + volOf(v));
780853
const c = costOf(model, v, priceAt);
781854
if (c == null) mainUnpricedVol += volOf(v); else mainCost += c;
782855
}
856+
if (matched) mainSessions++;
783857
continue;
784858
}
785859
// The parent session transcript is <session-id>.jsonl, sibling of the
786860
// first "subagents" dir on the path - one level up for plain Agent
787861
// dispatches, further up for Workflow agents nested in workflows/<wf>/.
788862
const anchored = p.match(/^(.*?)[\\/]subagents[\\/]/);
789863
const sessionJsonl = anchored ? anchored[1] + ".jsonl" : null;
790-
if (sessionJsonl && !sessionModelCache.has(sessionJsonl)) {
791-
sessionModelCache.set(sessionJsonl, sessionModelOf(sessionJsonl));
792-
}
793-
const sessionModel = sessionJsonl ? sessionModelCache.get(sessionJsonl) : null;
864+
const meta = readMeta(p);
865+
const sessionModel = dispatchModelOf(p, meta, sessionJsonl);
794866
const tsess = tierOf(sessionModel);
795867
// Accumulated BEFORE the filter returns: --session narrows to the sessions
796868
// where routing has the most room, so the scoped share is printed next to
@@ -813,7 +885,6 @@ if (process.argv[2] === "tokens") {
813885
const ss = perSession.get(sessKey) ?? { agents: 0, vol: 0, cmpVol: 0, downVol: 0 };
814886
ss.agents++;
815887
perSession.set(sessKey, ss);
816-
const meta = readMeta(p);
817888
if (!meta) metaless++;
818889
// One transcript is one agent, counted here for the same reason ss.agents
819890
// is counted outside the per-model loop: a mid-run fallback splits the
@@ -1046,7 +1117,7 @@ if (process.argv[2] === "tokens") {
10461117
] : []),
10471118
"",
10481119
"Volume = tokens the subagent processed; cache reads are billed at the subagent's model rate, which is where routing saves.",
1049-
"Session model is read from the head of each session transcript - the model it started on - so a mid-session /model switch or fallback attributes later subagents to the start model (the dispatch report does not have this limit). In a session long enough that its head names no model at all, the tail is read instead and that session is attributed to its LAST model, which is the opposite bias for those sessions.",
1120+
"Session model is the model of the assistant message that DISPATCHED the agent, matched through the toolUseId in the agent's sidecar - the same instant the dispatch report stamps, so a mid-session /model switch moves both reports together. Without a usable sidecar the model in effect at the agent's first timestamp is used, and failing that the head of the session transcript (or its tail, when the head names no model at all).",
10501121
];
10511122
process.stdout.write(out.join("\n"));
10521123
process.exit(0);

hooks/dispatch-counter.test.mjs

Lines changed: 87 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -975,9 +975,9 @@ test("tokens falls back to the transcript tail when the head names no model", ()
975975
const out = run(["tokens"], cfg);
976976
assert.match(out, /opus-5: 1k across 1 agents - 100% below session tier/);
977977
assert.doesNotMatch(out, /session unknown/);
978-
// The footer must admit the tail case: for these sessions the attribution
979-
// is the LAST model, the opposite bias from the start-model promise.
980-
assert.match(out, /the tail is read instead and that session is attributed to its LAST model/);
978+
// The footer must name the fallback ladder that got there: no sidecar, no
979+
// usable timestamp, so the transcript head - and here its tail.
980+
assert.match(out, /or its tail, when the head names no model at all/);
981981
} finally { rmSync(cfg, { recursive: true, force: true }); }
982982
});
983983

@@ -1502,3 +1502,87 @@ test("the env-override caveat prints only in a window that contains one", () =>
15021502
assert.match(run(["tokens", "--session", "opus"], cfg), /1 dispatch in it ran under CLAUDE_CODE_SUBAGENT_MODEL/);
15031503
} finally { rmSync(cfg, { recursive: true, force: true }); }
15041504
});
1505+
1506+
// --- Dispatch-time attribution (sidecar toolUseId -> assistant message) -----
1507+
1508+
const assistantLine = (model, ts, content, input = 0) =>
1509+
JSON.stringify({
1510+
type: "assistant",
1511+
timestamp: ts,
1512+
message: { model, content, usage: { input_tokens: input, output_tokens: 10, cache_read_input_tokens: 0, cache_creation_input_tokens: 0 } },
1513+
});
1514+
const agentUsageLine = (model, ts, input) =>
1515+
JSON.stringify({ type: "assistant", timestamp: ts, message: { model, usage: { input_tokens: input, output_tokens: 10, cache_read_input_tokens: 0, cache_creation_input_tokens: 0 } } });
1516+
const iso = (msAgo) => new Date(Date.now() - msAgo).toISOString();
1517+
1518+
test("an agent is attributed to the model that dispatched it, not the session head", () => {
1519+
const cfg = freshConfigDir();
1520+
const dir = join(cfg, "projects", "proj", "sess-1", "subagents");
1521+
mkdirSync(dir, { recursive: true });
1522+
// The session STARTED on opus and switched to fable before dispatching, the
1523+
// exact shape that used to send half a real 7d sample to the wrong model.
1524+
writeFileSync(join(cfg, "projects", "proj", "sess-1.jsonl"),
1525+
assistantLine("claude-opus-5", iso(3600e3), [{ type: "text", text: "x" }], 5000) + "\n"
1526+
+ assistantLine("claude-fable-5-1", iso(1800e3), [{ type: "tool_use", id: "toolu_1", name: "Agent", input: {} }], 100) + "\n");
1527+
writeFileSync(join(dir, "agent-a.jsonl"), usageLine("claude-sonnet-5", 1000) + "\n");
1528+
writeFileSync(join(dir, "agent-a.meta.json"), JSON.stringify({ agentType: "model-routing:scout", toolUseId: "toolu_1", spawnDepth: 1 }));
1529+
try {
1530+
const out = run(["tokens"], cfg);
1531+
assert.match(out, /fable-5-1: 1k across 1 agents/);
1532+
assert.doesNotMatch(out, /opus-5: \S+ across \d+ agents/);
1533+
} finally { rmSync(cfg, { recursive: true, force: true }); }
1534+
});
1535+
1536+
test("a nested agent is attributed through its parent agent's transcript", () => {
1537+
const cfg = freshConfigDir();
1538+
const dir = join(cfg, "projects", "proj", "sess-1", "subagents");
1539+
mkdirSync(dir, { recursive: true });
1540+
writeFileSync(join(cfg, "projects", "proj", "sess-1.jsonl"),
1541+
assistantLine("claude-fable-5-1", iso(3600e3), [{ type: "tool_use", id: "toolu_1", name: "Agent", input: {} }], 100) + "\n");
1542+
// The dispatching tool_use for a spawnDepth-2 agent lives in the DISPATCHING
1543+
// AGENT's transcript, so the session index alone can never resolve it.
1544+
writeFileSync(join(dir, "agent-a.jsonl"),
1545+
assistantLine("claude-sonnet-5", iso(1800e3), [{ type: "tool_use", id: "toolu_2", name: "Agent", input: {} }], 1000) + "\n");
1546+
writeFileSync(join(dir, "agent-a.meta.json"), JSON.stringify({ agentType: "model-routing:scout", toolUseId: "toolu_1", spawnDepth: 1 }));
1547+
writeFileSync(join(dir, "agent-b.jsonl"), usageLine("claude-haiku-4-5", 2000) + "\n");
1548+
writeFileSync(join(dir, "agent-b.meta.json"), JSON.stringify({ agentType: "model-routing:test-runner", toolUseId: "toolu_2", parentAgentId: "a", spawnDepth: 2 }));
1549+
try {
1550+
const out = run(["tokens"], cfg);
1551+
assert.match(out, /sonnet-5: 2k across 1 agents/);
1552+
} finally { rmSync(cfg, { recursive: true, force: true }); }
1553+
});
1554+
1555+
test("without a sidecar match, the model in effect at the agent's first timestamp wins", () => {
1556+
const cfg = freshConfigDir();
1557+
const dir = join(cfg, "projects", "proj", "sess-1", "subagents");
1558+
mkdirSync(dir, { recursive: true });
1559+
// opus first, fable later, and the agent starts between them: the switch
1560+
// happened AFTER this dispatch, so the tail model must not claim it.
1561+
writeFileSync(join(cfg, "projects", "proj", "sess-1.jsonl"),
1562+
assistantLine("claude-opus-5", iso(3600e3), [{ type: "text", text: "x" }], 100) + "\n"
1563+
+ assistantLine("claude-fable-5-1", iso(600e3), [{ type: "text", text: "y" }], 100) + "\n");
1564+
writeFileSync(join(dir, "agent-a.jsonl"), agentUsageLine("claude-sonnet-5", iso(1800e3), 1000) + "\n");
1565+
try {
1566+
const out = run(["tokens"], cfg);
1567+
assert.match(out, /opus-5: 1k across 1 agents/);
1568+
assert.doesNotMatch(out, /fable-5-1: \S+ across \d+ agents/);
1569+
} finally { rmSync(cfg, { recursive: true, force: true }); }
1570+
});
1571+
1572+
test("--session scopes the main-session denominator per line model", () => {
1573+
const cfg = freshConfigDir();
1574+
const dir = join(cfg, "projects", "proj", "sess-1", "subagents");
1575+
mkdirSync(dir, { recursive: true });
1576+
// One transcript, two models: attributing agents at dispatch time means the
1577+
// filter can no longer take or drop a whole switched session at once.
1578+
writeFileSync(join(cfg, "projects", "proj", "sess-1.jsonl"),
1579+
assistantLine("claude-fable-5-1", iso(3600e3), [{ type: "tool_use", id: "toolu_1", name: "Agent", input: {} }], 4000) + "\n"
1580+
+ usageLine("claude-opus-5", 8000) + "\n");
1581+
writeFileSync(join(dir, "agent-a.jsonl"), usageLine("claude-sonnet-5", 1000) + "\n");
1582+
writeFileSync(join(dir, "agent-a.meta.json"), JSON.stringify({ agentType: "model-routing:scout", toolUseId: "toolu_1", spawnDepth: 1 }));
1583+
try {
1584+
const out = run(["tokens", "--session", "fable"], cfg);
1585+
assert.match(out, /Main sessions \(not routable\): 4k across 1 sessions/);
1586+
assert.doesNotMatch(out, /opus-5\s+8k/);
1587+
} finally { rmSync(cfg, { recursive: true, force: true }); }
1588+
});

0 commit comments

Comments
 (0)