Token report: include workflow subagents and add a per-agent wall-clock table

[sv-tmueller]

Part of batch #417

Rescoped at batch #417 sign-off (2026-10-01): the tokens-per-second column is dropped in favor of measured wall-clock per agent. The original body is in the issue edit history.

What to build

The token report posted at every /tm-advisor batch report and every /tm-kickoff wave end (.claude/skills/tm-kickoff/token-report.mjs) should show what a run really spent, and how long each agent took.

Completeness (bug). The report reads the lead transcript and <session>/subagents/agent-*.jsonl only. Agents spawned inside a Workflow keep their transcripts under subagents/workflows/<wf-id>/, which the report never reads, so a workflow's whole cost is left out without a warning. Found in #405 (docs/reviews/2026-09-28-ultracode-arm-379.md, sections 4 and 7): the merged script priced the arm at $4.28 against a measured $12.77, and the tm-review-changes run in that PR's kickoff session was missing from its report.

Per-agent wall-clock (new). For each agent (the lead, each dispatched seat, each workflow subagent), add a row with its wall-clock time. That shows which seats are slow, and whether a model or effort change sped them up.

Why wall-clock and not tokens per second, checked on 2026-10-01 against batch #403's transcripts:

• Interactive transcripts carry only streaming placeholders for output_tokens (values 5, 8 and 16 across 32 messages in one subagent transcript, with no later line per message id holding a larger count). The only output figure is the chars/4 estimate, which leaves out thinking and ran 3.8-4.4x low in A/B: native plan-and-execute vs the kickoff pipeline on real issues #400 (docs/reviews/2026-09-28-ab-native-vs-kickoff.md, "Cost-measurement gap"). Thinking is what an effort change moves, so a rate built on that estimate cannot answer the question.
• The lead transcript's task notifications carry a measured <duration_ms> per dispatched agent, alongside <tool_uses> and <subagent_tokens>. subagent_tokens looks like the agent's final context size (319,875 for an agent with 5 tool uses over 60 s), not its output; do not present it as output.
• Workflow subagents have no task notification of their own; the first-to-last timestamp span in each transcript is a candidate source. Check it against the workflow's own reported duration where one exists.

Acceptance criteria

• The report includes workflow subagents under subagents/workflows/, grouped by role and by model like every other agent. A fixture test covers a session with a workflow.
• The report names every subagent transcript directory it found but could not read, instead of leaving it out without a word.
• A per-agent table lists role, model, calls, tool uses, estimated output tokens, and wall-clock time for each agent (the lead, each dispatched seat, each workflow subagent).
• The report states where each wall-clock value comes from (for example, duration_ms in a task notification, or the first-to-last timestamp span in a transcript), and marks any estimated value.
• Tests are written first, against fixture transcripts. They include an agent with no output and an agent with a zero or missing duration, which shows as "n/a" (no division by zero, no made-up value).
• /tm-advisor section 5 and /tm-kickoff's wave-end report still post the report on every run, with the new table.
• npm test is green, and .claude/.claude-plugin/plugin.json gets a version bump (the change touches .claude/skills/).

Non-goals

• A tokens-per-second column.
• Pricing headless claude -p child sessions started by a seat (for example A/B trial runs). Those stay reported by the package that ran them.
• Real billing figures. The report stays at list prices.
• Live or streaming throughput during a run.

[sv-tmueller]

Sub-plan (architect, batch #417)

SUB_PLAN

Plan source: the #416 issue body (rescoped at batch #417 sign-off) and batch #417's P1 contract and refinement answers. Both are signed-off batch decisions, but they fix only the scope, the acceptance criteria and the transcript facts. Neither carries an approach, so the delta below is the approach. Nothing here conflicts with docs/architecture/. Size check: fits size:M, at the upper end.

Delta 1: workflow layout, role and model (checked 2026-10-01 on CLI 2.1.280 and 2.1.286)

• Workflow subagent transcripts are at <session>/subagents/workflows/<runId>/agent-<hex>.jsonl.
  • Each one has an agent-<hex>.meta.json sidecar: agentType: "workflow-subagent", description (the agent() label, e.g. review:bugs), and an optional model alias. The alias is missing in a dynamic (ultracode) workflow.
  • Each run directory also has one journal.jsonl. It is not a transcript and has no timestamps.
  • Across all 25 sessions with subagents, only this layout and plain subagents/agent-*.jsonl occur.
• Role: the lead's Workflow launch is a user line whose top-level toolUseResult carries taskType: "local_workflow", runId (the directory name), workflowName and taskId.
  • The role key is workflow:<workflowName>. Fall back to workflow:<runId> when no launch matches.
  • The label comes from the sidecar description, with | escaped. It appears only in the per-agent table. By role puts a whole workflow in one row.
• Model: take it per call from message.model, as today. Never use the sidecar alias.

Delta 2: which wall-clock source applies to which agent

• Task notifications are in the lead transcript, in three carriers. The same notification shows up in two or three of them:
  • a queue-operation with operation: "enqueue" (its content)
  • an attachment with commandMode: "task-notification" (its prompt)
  • a user line with origin.kind: "task-notification" (string message.content), seen for workflow and failed notifications
• Read only those carriers, never tool_result text. A lead that greps transcripts quotes notifications inside its own tool results. Extract the task id, tool-use id, status and duration_ms fields, and merge copies that agree on all four.
• For an agent, the task id is the agent hex, including on SendMessage resumes (there the tool-use id is the SendMessage's id).
  • An agent sends one notification per run, and each duration_ms covers only that run.
  • A failed run (limit death) sends a notification with no usage block.
• Run segments: in a subagent transcript, each user line with origin.kind: "coordinator" (a SendMessage resume) starts a new run. A segment's span is its last timestamp minus its first, over all line types inside the window, not only assistant lines.
• Dispatched seat:
  • Measured: the sum of duration_ms when the seat has at least one notification in the window and every one of them carries a positive value.
  • Otherwise: the sum of its segment spans, marked est.
• Workflow subagent: its segment span, marked est. It has no notification of its own.
• Lead: the first-to-last span of its lines in the window, marked est. The note must say this includes idle and waiting time.
• n/a: shown when no source gives a positive value. A zero or missing duration_ms falls through to the estimate.
  • This is my decision within the signed-off scope; the lead should log it. A rule that used only duration_ms would show n/a for every seat killed by a limit, and those are the slow seats this table is meant to show.
• Evidence from the 34f750e6 and c5168e00 sessions:
  • For 23 seats that ran once, the span was 7-23 ms off duration_ms. The transcript's tool_use count matched the notification's tool-uses field in every case.
  • For resumed seats, each segment's span was within 100 ms of its notification. A single first-to-last span overstates them by up to 9 hours.
  • Workflow cross-check (c5168e00, tm-review-changes): the 8 subagent spans together cover 648,607 ms, against the workflow's own duration_ms of 650,996 ms (0.4% under). Their tool_use counts sum to 162, which equals the workflow's tool-uses field.
• Tool uses: count tool_use blocks per record, summed across split lines the same way as visibleChars. Use this for every agent kind. Never use the notification's tool-uses field (it covers one run only), and never show the notification's subagent-tokens field.

Delta 3: shape of the change

• parse() still returns a record array, so the existing tests stay as they are.
  • Subagent input entries get optional workflowRunId and label fields.
  • Records get toolUses and label.
• A new pure export, for example perAgent({lead, subagents}, {since, until}), returns one row per transcript that has at least one timestamped line in the window. That includes agents with no assistant call. Each row has role, label, models, calls, toolUses, outputTokens, wallClockMs (or null) and source. A notification counts only when its own line is inside the window.
• render() gets agents = [] and unread = [].
  • It prints ## By agent only when agents is non-empty, so lead-dedupe.snapshot.md stays byte-identical.
  • Columns: Start (UTC) | Role | Model | Calls | Tool uses | Output (est.) | Wall-clock | Source.
  • Rows: lead first, then by start time. No wall-clock total.
  • No agent hex. The harness marks agentIds as internal, and the report gets posted to public issues. Start time tells rows apart instead.
  • Limitations gain two things: what est. and n/a mean, and a "found but not read" line.
• main() and findSubagents:
  • Also walk subagents/workflows/<run>/.
  • Any other directory under subagents/ or under a run directory, and any readdir or readFile error, goes into unread as a path relative to the session directory. Its usage is left out of every total.
  • Parse sidecars and notifications defensively, so the report the skills post never fails because of them (AC 6).
• No SKILL.md edit: both skills run the same command, so they get the new table automatically.

Fixture design (synthetic only, no real ids)
Add a new session at fixtures/token-report/cli-config/projects/test-project/workflow-session.jsonl with its workflow-session/subagents/ directory. Leave fixture-session untouched.

• Lead (opus):
  • Agent dispatches for developer, tester, reviewer and architect, with agentId: tool_results.
  • A Workflow launch with toolUseResult {taskType: "local_workflow", taskId, runId: "wf_fixture-001", workflowName: "tm-review-changes"}.
  • Notifications in the real carriers.
  • A Bash tool_result that quotes a fake task-notification block for the developer. It must be ignored.
  • A workflow-level notification. It must not become an agent row.
• Developer: measured 120000 ms, notified through both an enqueue and an attachment copy. Expected 2m 0s, not doubled.
• Tester: a 60 s run, a failed notification with no usage, 1 h idle, a coordinator resume, then a 30 s run with a completed notification of 30000 ms. Expected 1m 30s (est.): not 30 s, and not over 1 h.
• Reviewer: a thinking-only assistant line (the "no output" case) and a measured duration. Expected Output (est.) 0, with wall-clock shown.
• Architect: a prompt line only, with notification duration_ms 0. Expected 0 calls and n/a (the zero case).
• Unmapped agent: no dispatch, a transcript with a single timestamp, no notification. Expected n/a (the missing case).
• workflows/wf_fixture-001/:
  • a sonnet review:bugs agent (2 calls, 2 tool uses, 90 s)
  • an opus consolidate agent (1 call, 30 s)
  • meta sidecars for both
  • a journal.jsonl that must not be counted
• subagents/unknown-layout/agent-<hex>.jsonl: must be named in Limitations and left out of every total.
• Optional: a read-error test in a temp dir with chmod 000, skipped when uid is 0.

File order

1. Fixtures, then failing tests in .claude/workflows/__tests__/token-report.test.mjs.
   • Pure tests first: parse sets the workflow role and the runId fallback, and toolUses adds up across split lines.
   • perAgent: each source, est., n/a, merging of duplicate notifications, and the guard against quoted notifications.
   • render: the By agent table and the "not read" line.
   • CLI: --session workflow-session --config-dir <fixtures> --since <ISO> (the form both skills use), path form equals session form, and a new workflow-session.snapshot.md.
2. .claude/skills/tm-kickoff/token-report.mjs: the parse changes.
3. Same file: notification carriers, run segments and the per-agent export.
4. Same file: the render section and the limitations.
5. Same file: the walk in main/findSubagents, unread, the sidecar labels, and the wiring.
6. .claude/.claude-plugin/plugin.json: 2.7.0 to 2.8.0 (minor). If P2 or P3 merges first, rebase the version as the batch notes say.
7. Verify with npm test (must exit 0), then a read-only smoke run: node .claude/skills/tm-kickoff/token-report.mjs --session c5168e00-8b3d-486c-9ad3-d2f4cd14cb6a --config-dir ~/.claude-work. It must show a workflow:tm-review-changes row and 8 workflow agent rows. Put only counts in the PR body, and copy nothing from real transcripts into fixtures.

Note on the issue's facts (no scope change): lead transcripts seem to carry real output_tokens. In 34f750e6 there are 115 distinct values up to 4,886 across 118 messages, and none grows on a later line. I have not checked them against a result event. The placeholder fact holds for subagent transcripts, so wall-clock is still the right measure. The output column stays an estimate as the AC says; pricing the lead from output_tokens could be a follow-up.

Size: about 150-200 lines in the script, about 200 lines of tests, and around 15 small fixture files. That fits size:M at the upper end. If time runs short, defer only the read-error test, not the resume segmentation.

[sv-tmueller]

Package summary (batch #417): PR #421 ready for review

• Pipeline: architect sub-plan; developer; tester FAIL at f4cb270 (fix round 1/3: agent hex leaked through the "Found but not read" line; a newline in a label split a table row); fix a8e2393 with 4 new tests; tester re-test PASS at a8e2393; reviewer APPROVE, both passes clean.
• Checks at a8e2393: npm test 419 pass; node scripts/check-version-bump.mjs origin/main HEAD exit 0 (2.7.0 -> 2.8.0). Smoke run on a real session with a workflow: one workflow:tm-review-changes role row and 8 workflow agent rows, no agent hex in the output.
• Wall-clock rule: measured duration_ms from task notifications, else run-segment span marked est., else n/a (batch Batch: measurement-tools #417 Decision 3).
• Should-fix for the human review: none.
• Nits for the human review (not applied, exact text in the reviewer comment on PR feat: token report covers workflow subagents and adds a per-agent wall-clock table #421):
  1. token-report.mjs:10: the header comment's export list omits perAgent.
  2. token-report.mjs:299: first duplicates start in transcriptTiming.
• Untested claims: a sidecar description (an author-chosen agent() label) containing the text agent-<hex> prints as-is; not redacted, no test.
• Not in scope, found during the batch: token-prices.json has no claude-sonnet-5-5 entry, so Sonnet 5.5 calls show as unpriced (batch Batch: measurement-tools #417 Decision 6). Listed as a follow-on.
• Merge note: plugin.json is also bumped by PR feat: verify stage in tm-review-changes with spec-format item transforms #419 (Verify stage in tm-review-changes, with spec-format item transforms #406) and PR docs: add headless claude -p checklist to tm-ab-test #420 (Record the headless trial traps from #400, #404 and #405 in tm-ab-test #418). Whichever merges first, the others need a one-line rebase on the version.