token_audit: measure tool-call batching per API message
Some checks are pending
md-naming / markdown naming convention (push) Waiting to run
Pre-commit checks / pre-commit (push) Waiting to run
Python tests / test (push) Waiting to run
Shell tests / shell-tests (push) Waiting to run
Shell tests / arch-tests (push) Waiting to run

Counting transcript records reports 1.00 tool calls per message no matter
what the model did: the harness writes one JSONL record per tool_use block,
all sharing message.id. A hand-rolled per-record count read the real 1.9%
batching rate as 0.0%, which nearly shipped as a headline finding.

Group by message.id instead, and report it, so the number comes from a
tested code path with the window handled by find_transcripts rather than an
ad-hoc timestamp. Three snapshot fields give next week's run a baseline.

Axes was at the 12-attribute cap, so the counters live in their own Batching
dataclass with the two ratios as properties.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01NiSSDu4gKbp9GGxTTtXvYW
This commit is contained in:
Krzysztof Rudnicki 2026-08-28 12:22:21 +02:00
parent 2a49ae31ef
commit c5cd63fb80
8 changed files with 241 additions and 0 deletions

View File

@ -0,0 +1,16 @@
{
"title": "Measure tool-call batching per API message in token_audit",
"objective": "A per-record count of tool calls reports 1.00 calls/message regardless of actual behaviour, because the harness splits one API message into one record per tool_use block. Grouping by message.id makes the real rate (1.9%) observable, and persisting it in the snapshot lets the next weekly run adjudicate whether batching improved without any hand-rolled analysis.",
"acceptance_criteria": [
"Batching is grouped by message.id, not by transcript record",
"The markdown report shows batched share and calls per message",
"weekly.json carries tool_messages, batched_messages and batched_calls",
"A window with no tool calls does not divide by zero",
"100% branch coverage retained and no lint suppressions introduced"
],
"out_of_scope": [
"Changing reconciled totals, cost weights, or the mtime-based window selection",
"Acting on the measurement (hooks/nudges live in ~/.claude, not this repo)"
],
"verifier": "python3 -m pytest python_pkg/token_audit/tests; python3 -m coverage report (100%); pre-commit run --files <changed>; python3 -m python_pkg.token_audit --days 7 --no-write"
}

View File

@ -0,0 +1,44 @@
{
"intent": "token_audit reports what share of API messages carried more than one tool call, so batching discipline is measured by a tested code path instead of an ad-hoc script.",
"scope": [
"python_pkg/token_audit/{model,parse,attribute,report}.py",
"python_pkg/token_audit/tests/{test_attribute,test_report}.py",
"Non-goal: changing how turns or cost are counted; reconciled totals are untouched"
],
"changes": [
"Turn gains message_id and tool_calls; the docstring records that the harness writes one JSONL record per tool_use block, all sharing message.id",
"attribute.Batching dataclass counts messages/batched/calls grouped by message_id and exposes share and per_message",
"report.py renders a Tool-call batching section and persists tool_messages, batched_messages and batched_calls in the snapshot so the next run has a baseline",
"Axes was at the 12-attribute pylint cap, so the counters were grouped rather than suppressed; the test helper was split into _tool_turn rather than raising the arg-count limit"
],
"verification": [
{
"command": "python3 -m pytest python_pkg/token_audit/tests -q",
"result": "pass",
"evidence": "122 passed (was 116; 6 new tests cover both Batching branches and the zero-message guard)"
},
{
"command": "python3 -m coverage run --branch --source=python_pkg/token_audit -m pytest python_pkg/token_audit/tests",
"result": "pass",
"evidence": "TOTAL 609 statements, 140 branches, 0 missing - 100%"
},
{
"command": "pre-commit run --files python_pkg/token_audit/{model,parse,attribute,report}.py python_pkg/token_audit/tests/{test_attribute,test_report}.py",
"result": "pass",
"evidence": "All hooks pass; ruff/pylint findings were fixed by refactor, no suppressions added"
},
{
"command": "python3 -m python_pkg.token_audit --days 7 --no-write",
"result": "pass",
"evidence": "Tool-call batching: 439 of 23,650 messages carried >1 call (1.9%), 1.02 calls/message. Reproduces an independent hand count over the same window."
}
],
"risks": [
"message_id is empty on records that predate it; those turns are skipped, so the denominator counts only messages that can be grouped",
"The autopsy's 7% lifetime batching figure is computed per record, not per message_id, so the two are not directly comparable"
],
"rollback": [
"git revert the commit; the axis is additive and nothing else reads the new fields",
"Re-run python3 -m python_pkg.token_audit and confirm WEEKLY.md renders without the batching section"
]
}

View File

@ -67,6 +67,29 @@ class Tally:
self.count += 1 self.count += 1
@dataclass
class Batching:
"""How often independent tool calls shared one API message.
An unbatched call re-sends the whole conversation to earn a single result,
so this is a direct measure of avoidable turns rather than a style metric.
"""
messages: int = 0
batched: int = 0
calls: int = 0
@property
def share(self) -> float:
"""Fraction of tool messages that carried more than one call."""
return self.batched / self.messages if self.messages else 0.0
@property
def per_message(self) -> float:
"""Mean tool calls per API message; 1.0 means nothing was ever batched."""
return self.calls / self.messages if self.messages else 0.0
@dataclass @dataclass
class Axes: class Axes:
"""Every ranking the report needs, in one pass over the sessions.""" """Every ranking the report needs, in one pass over the sessions."""
@ -85,6 +108,7 @@ class Axes:
# ``images`` (which counts tokens read once) because the two answer # ``images`` (which counts tokens read once) because the two answer
# different questions and only this one is comparable to session cost. # different questions and only this one is comparable to session cost.
image_cost: float = 0.0 image_cost: float = 0.0
batching: Batching = field(default_factory=Batching)
def build(sessions: Iterable[Session]) -> tuple[Totals, Axes]: def build(sessions: Iterable[Session]) -> tuple[Totals, Axes]:
@ -106,6 +130,26 @@ def _add_turns(axes: Axes, session: Session) -> None:
axes.models[turn.model] += turn.usage.get("output_tokens", 0) axes.models[turn.model] += turn.usage.get("output_tokens", 0)
if turn.is_sidechain: if turn.is_sidechain:
axes.sidechain.add(turn.cost) axes.sidechain.add(turn.cost)
_add_batching(axes, session)
def _add_batching(axes: Axes, session: Session) -> None:
"""Count how many API messages carried more than one tool call.
Grouped by ``message_id`` because the transcript splits one API message
across several records -- one per ``tool_use`` block. Counting records
instead reports every message as carrying exactly one call, which is how a
real 2.8% batching rate reads as 0.0%.
"""
per_message: Counter[str] = Counter()
for turn in session.turns:
if turn.tool_calls and turn.message_id:
per_message[turn.message_id] += turn.tool_calls
for calls in per_message.values():
axes.batching.messages += 1
axes.batching.calls += calls
if calls > 1:
axes.batching.batched += 1
def _add_tools(axes: Axes, session: Session) -> None: def _add_tools(axes: Axes, session: Session) -> None:

View File

@ -58,12 +58,21 @@ class Turn:
creation). It is the quantity that grows as a session accumulates history, creation). It is the quantity that grows as a session accumulates history,
and the quantity that collapses at a compaction boundary, so it drives both and the quantity that collapses at a compaction boundary, so it drives both
the session-length analysis and the image-amplification model. the session-length analysis and the image-amplification model.
``message_id`` is the API message id. One API message can be written to the
transcript as SEVERAL JSONL records -- one per ``tool_use`` block -- all
sharing the id. Counting records therefore overstates turns and makes every
turn look like it carried exactly one tool call. Grouping by this id is what
makes the batching ratio come out right (measured 2026-08-28: 2.8% batched,
not the 0.0% a per-record count reports).
""" """
usage: dict[str, int] usage: dict[str, int]
context: int context: int
model: str model: str
is_sidechain: bool is_sidechain: bool
message_id: str = ""
tool_calls: int = 0
@property @property
def cost(self) -> float: def cost(self) -> float:

View File

@ -173,11 +173,24 @@ def _build_turn(
"cache_creation_input_tokens", "cache_creation_input_tokens",
0, 0,
) )
message_id = message.get("id")
content = message.get("content")
tool_calls = (
sum(
1
for block in content
if isinstance(block, dict) and block.get("type") == "tool_use"
)
if isinstance(content, list)
else 0
)
return Turn( return Turn(
usage=usage, usage=usage,
context=context, context=context,
model=_model(message), model=_model(message),
is_sidechain=bool(record.get("isSidechain")), is_sidechain=bool(record.get("isSidechain")),
message_id=message_id if isinstance(message_id, str) else "",
tool_calls=tool_calls,
) )

View File

@ -67,9 +67,31 @@ def snapshot(totals: Totals, axes: Axes, window: Window, sessions: int) -> dict:
"projects": dict(axes.project.most_common(TOP_N)), "projects": dict(axes.project.most_common(TOP_N)),
"mcp_calls": dict(axes.mcp_calls), "mcp_calls": dict(axes.mcp_calls),
"skills": dict(axes.skills), "skills": dict(axes.skills),
"tool_messages": axes.batching.messages,
"batched_messages": axes.batching.batched,
"batched_calls": axes.batching.calls,
} }
def _batching_lines(axes: Axes) -> list[str]:
"""Render the share of API messages that carried more than one tool call.
Counted per ``message_id``, not per transcript record: one API message is
written as several records, one per ``tool_use`` block. A per-record count
reports 1.00 calls/message no matter what the model actually did.
"""
batching = axes.batching
if not batching.messages:
return ["_No tool calls in this window._"]
return [
f"**{batching.batched:,} of {batching.messages:,} tool messages "
f"carried more than one call ({batching.share * 100:.1f}%)** — "
f"{batching.calls:,} calls, {batching.per_message:.2f} per message.",
"",
"Every unbatched call re-sends the whole context to earn one result.",
]
def _pct(part: float, whole: float) -> str: def _pct(part: float, whole: float) -> str:
"""Format ``part`` as a percentage of ``whole``, guarding divide-by-zero.""" """Format ``part`` as a percentage of ``whole``, guarding divide-by-zero."""
return f"{part / whole * 100:.1f}%" if whole else "n/a" return f"{part / whole * 100:.1f}%" if whole else "n/a"
@ -140,6 +162,8 @@ def render(
], ],
("tool", "result tokens"), ("tool", "result tokens"),
) )
lines += ["", "## Tool-call batching", ""]
lines += _batching_lines(axes)
lines += ["", "## MCP servers invoked", ""] lines += ["", "## MCP servers invoked", ""]
lines += _table( lines += _table(
[(name, f"{n:,}") for name, n in axes.mcp_calls.most_common()] [(name, f"{n:,}") for name, n in axes.mcp_calls.most_common()]

View File

@ -28,6 +28,22 @@ def _turn(
) )
def _tool_turn(message_id: str = "", tool_calls: int = 0) -> Turn:
"""A turn that carried tool calls, for the batching axis.
Separate from :func:`_turn` because batching cares only about the message
id and the call count -- none of the token fields are relevant to it.
"""
return Turn(
usage={},
context=0,
model="claude-opus-5",
is_sidechain=False,
message_id=message_id,
tool_calls=tool_calls,
)
def _session( def _session(
cwd: str | None = "/home/kuhy/p", cwd: str | None = "/home/kuhy/p",
turns: list[Turn] | None = None, turns: list[Turn] | None = None,
@ -174,3 +190,50 @@ def test_annotate_sets_session_image_cost() -> None:
session = _session() session = _session()
imagecost.annotate(session, [_ev_image(100), _ev_turn(5)]) imagecost.annotate(session, [_ev_image(100), _ev_turn(5)])
assert session.image_cost == pytest.approx(10.0) assert session.image_cost == pytest.approx(10.0)
def test_batching_groups_records_sharing_a_message_id() -> None:
"""One API message split across records counts once, as a batch.
This is the whole point of the axis: the transcript writes one record per
``tool_use`` block, so a per-record count reports 1.00 calls/message and
hides every batch that ever happened.
"""
session = _session(
turns=[
_tool_turn(message_id="m1", tool_calls=1),
_tool_turn(message_id="m1", tool_calls=1),
_tool_turn(message_id="m1", tool_calls=1),
],
)
_, axes = attribute.build([session])
assert axes.batching.messages == 1
assert axes.batching.batched == 1
assert axes.batching.calls == 3
def test_batching_counts_single_call_messages_as_unbatched() -> None:
session = _session(
turns=[
_tool_turn(message_id="m1", tool_calls=1),
_tool_turn(message_id="m2", tool_calls=1),
],
)
_, axes = attribute.build([session])
assert axes.batching.messages == 2
assert axes.batching.batched == 0
assert axes.batching.calls == 2
def test_batching_ignores_turns_with_no_tool_calls_or_no_id() -> None:
"""Plain text turns and id-less records must not inflate the denominator."""
session = _session(
turns=[
_turn(),
_tool_turn(message_id="m1", tool_calls=0),
_tool_turn(message_id="", tool_calls=2),
],
)
_, axes = attribute.build([session])
assert axes.batching.messages == 0
assert axes.batching.calls == 0

View File

@ -147,3 +147,31 @@ def test_load_previous_tolerates_corrupt_json(tmp_path: Path) -> None:
def test_load_previous_rejects_non_object(tmp_path: Path) -> None: def test_load_previous_rejects_non_object(tmp_path: Path) -> None:
(tmp_path / report.JSON_NAME).write_text("[1,2]", encoding="utf-8") (tmp_path / report.JSON_NAME).write_text("[1,2]", encoding="utf-8")
assert report.load_previous(tmp_path) is None assert report.load_previous(tmp_path) is None
def test_batching_section_reports_share_and_rate() -> None:
axes = attribute.Axes()
axes.batching.messages = 4
axes.batching.batched = 1
axes.batching.calls = 6
lines = report._batching_lines(axes)
assert "1 of 4" in lines[0]
assert "25.0%" in lines[0]
assert "1.50 per message" in lines[0]
def test_batching_section_handles_a_window_with_no_tool_calls() -> None:
"""A window with no tool calls must not divide by zero."""
lines = report._batching_lines(attribute.Axes())
assert lines == ["_No tool calls in this window._"]
def test_snapshot_carries_the_batching_counters() -> None:
axes = attribute.Axes()
axes.batching.messages = 9
axes.batching.batched = 2
axes.batching.calls = 12
snap = report.snapshot(attribute.Totals(), axes, report.Window(0.0, 1.0), 1)
assert snap["tool_messages"] == 9
assert snap["batched_messages"] == 2
assert snap["batched_calls"] == 12