cc-os/docs/orchestration-audit/2026-07-08-fable-econ-minia...

176 lines
12 KiB
Markdown
Raw Permalink Normal View History

# Fable-5 main-loop orchestration economics — mini-audit (2026-07-08)
**Model**: this audit was performed by `claude-sonnet-5`. All audited transcripts carry
`"model":"claude-fable-5"` on non-sidechain assistant messages (i.e. Fable 5 is the main-loop
model in every session below).
## Method
1. Scanned all `~/.claude/projects/*/*.jsonl` files modified in the last 10 days
(`scan.rb`), filtered to sessions with ≥20 non-sidechain assistant turns and at least one
`claude-fable-5` main-loop message, excluded the live session
(`ca17e6d2-6132-4681-8a02-8a7523cb5660`). 21 candidates found, almost all in `cc-os`; picked
6 for project diversity: 3 `cc-os`, 2 `servers`, 1 `servers/desktop`, all ≥20 turns (24255).
2. Ran the existing fact-sheet extractor
(`plugins/os-orchestration/audit/bin/extract`) on each for spawn count/models,
pre-/post-spawn tool segmentation, and its heuristic same-tool-run flags.
3. Wrote two throwaway Ruby scripts in scratchpad (`tokens.rb`, `bashcmds.rb`,
`firstprompt.rb`) to sum `usage.output_tokens` per session (main-loop vs sidechain), track
max/final context size, and find the longest unbroken run of main-loop tool calls with no
`Agent` spawn in between, then classified each run by reading the actual tool inputs
(Bash commands / file targets) in that range.
**Environment gotcha (noted for future audits):** in zsh, a variable named `path` is linked to
`$PATH`; `path=$(find ...)` silently corrupted `$PATH` mid-script and caused unrelated `ruby: not
found` (exit 127) failures. Renamed to `tpath`. Not a data issue, just a shell trap.
**Hard measurement limitation:** none of the 6 transcripts contain any `"isSidechain":true`
lines, even in the two sessions that used the `Agent` tool (9f45afcc, 5 spawns; df12b180, 1
spawn). Subagent execution in this environment/version is logged only as a `tool_use`/
`toolUseResult` pair (with `agentId`/`resolvedModel` metadata) plus an eventual
`<task-notification>` result — no subagent transcript is persisted into the parent `.jsonl`. So
**subagent output-token spend is not recoverable from these files at all.** The only proxy
available is the char length of the `tool_result`/notification payload returned to the main
loop, converted at ~4 chars/token. All "% main-loop" figures below use that proxy where spawns
occurred, and are explicitly not real subagent token counts (real subagent spend is very likely
much higher than the proxy, since it only reflects what was returned, not what the subagent
itself burned getting there).
> **Addendum (2026-07-08, WS4 Step 2):** the limitation above is narrower than stated —
> subagent spend is absent from the *parent* transcript, but each subagent's full transcript
> (with per-message `usage` blocks) persists separately at
> `~/.claude/projects/<flattened-cwd>/<session-id>/subagents/agent-<id>.jsonl` (verified for
> both interactive and headless sessions). Real main-loop-share measurement is therefore
> possible; the eval harness A-econ axis uses it. The proxy figures below were NOT recomputed.
> See vault note [[claude-code-subagent-transcripts-and-token-accounting]].
## Per-session detail
### 1. `9f45afcc` — cc-os — cache-refresh tooling + WS2 autoresearch prep
- 255 turns, 25 human prompts, 850 jsonl lines, 2026-07-04 16:1718:52
- 5 Agent spawns, all `general-purpose`, `model` param `sonnet`×4/`haiku`×1, **resolved model
`claude-haiku-4-5` in all 5 cases** (param mismatch: 4 of 5 requested sonnet, all resolved
haiku)
- main-loop output tokens: **237,679** (255 msgs); proxy subagent output: 13,575 chars via
result/notification payloads (≈3.4K tokens) → **main-loop ≈98.6% of proxy-measured output**
- pre-spawn segment: 19 calls / 23,658 bytes read (Bash 14, Read 4, Edit 1)
- longest direct run: **48 calls** (after spawn 3: ToolSearch 2, SendMessage 1, Bash 22, Edit 12,
Skill 2, Read 5, Write 3, TaskStop 1) — mixed: driving/monitoring the background eval-grid
agent (SendMessage/TaskStop/ToolSearch) interleaved with direct mechanical plugin-cache-refresh
edits. Not a clean single-purpose run.
### 2. `eba26343` — cc-os — WS2 os-vault wording loop (`/autoresearch`)
- 223 turns, 2 human prompts (127 total `type:user` lines incl. tool results/notifications), 583
jsonl lines, 2026-07-07 16:4818:01
- **0 Agent spawns**
- main-loop output tokens: **216,019** (223 msgs) — 100% of measured output (no spawns to split
against)
- whole-session tool profile: 119 calls / 119,587 bytes (Read 17, Bash 64, Skill 1, ToolSearch 1,
TaskCreate 5, TaskUpdate 9, Edit 20, Write 2)
- longest direct run: **119 calls = the entire session** (no spawn boundary at all). Sampled the
64 Bash commands directly: this is a scripted headless-runner loop — `bin/run P1/P2/P3...` /
`bin/check` invocations against `eval/scenarios/`, `sleep N; wc -l results.tsv`
polling of background task output, `awk`/`sort` aggregation of `results.tsv`, and git
commit/push at each iteration boundary. **Classify as justified scripted-bulk-op / polling
work**, not a delegation miss — matches the ORCHESTRATION.md scripted-bulk-edit carve-out; a
subagent adds no value polling a script's own stdout.
### 3. `5f53e0c0` — cc-os — `/opsx:apply add-os-adr-plugin`
- 222 turns, 4 human prompts, 506 jsonl lines, 2026-07-03 17:1517:43
- **0 Agent spawns**
- main-loop output tokens: **314,899** (222 msgs, highest of the 6) — 100% of measured output
- whole-session tool profile: 128 calls / 129,924 bytes (Bash 39, Read 16, Write 35, Edit 38)
- longest direct run: **128 calls = the entire session**. Contains three flagged sub-runs from
the extractor: Read×10 (design docs, lines 2752 — reasonable orientation), **Write×13 (lines
96137, 13 distinct new files: `lib/adr.rb`, `lib/adr/record.rb`, `repository.rb`,
`index.rb`, `template.rb`, `bin/adr-new`, …)**, and Edit×10 (lines 326353, fixing 5 files
post-review). **Genuine miss candidate**: the Write×13 run is scaffolding independent Ruby
class files against an *already-fixed* `design.md` (read in the first 10 calls) — a
parallelizable implementation task that ran entirely in the main loop and is a large share of
this session's 315K output tokens.
### 4. `3fc7bb8c` — servers — backup verification + vault write
- 90 turns, 5 human prompts, 236 jsonl lines, 2026-07-04 17:2018:04
- **0 Agent spawns**
- main-loop output tokens: **63,607**
- whole-session tool profile: 44 calls / 32,250 bytes (Read 3, Bash 27, Write 4, ToolSearch 2,
ExitPlanMode 1, Edit 6, Skill 1)
- longest direct run: **44 calls = whole session** — interactive backup-system investigation
("Are we confident backups will work as expected now?") ending in a vault write. Judgment-
heavy, sequential-dependent (each Bash result determines the next check). **Justified direct
work**, no clean miss shape.
### 5. `7bc0dda4` — servers — Proxmox HAOS install troubleshooting
- 82 turns, 15 human prompts (highest interaction density of the 6), 249 jsonl lines,
2026-07-03 19:4920:42
- **0 Agent spawns**
- main-loop output tokens: **39,513**
- whole-session tool profile: 39 calls / 6,124 bytes (Bash 27, Edit 8, Read 2, Skill 1, Write 1)
- longest direct run: **39 calls = whole session** — live interactive install/debug loop (disk
space checks, image download, phase-2 error triage against user-supplied screenshots).
**Justified direct work**: 15 human turns in 82 total means the human is in the loop almost
every other turn; delegation overhead would exceed any savings.
### 6. `df12b180` — servers/desktop — Remote Control OAuth scope troubleshooting
- 24 turns, 6 human prompts, 90 jsonl lines, 2026-07-06 23:1323:35
- 1 Agent spawn (`claude-code-guide`, `model` param `sonnet`, resolved `claude-sonnet-5`,
foreground, prompt 1,008 chars → result 5,689 chars)
- main-loop output tokens: **24,051**; proxy subagent output ≈1,422 tokens (5,689 chars/4) →
**main-loop ≈94.4% of proxy-measured output**
- pre-spawn: 4 Bash calls / 3,154 bytes (credential/scope investigation)
- post-spawn: 3 calls (Read 1, Write 2 — writing up the answer)
- longest direct run: 4 calls (the pre-spawn investigation). **Good delegation example**: a
bounded doc-lookup ("Remote Control usage") was correctly routed to the docs-specialist
subagent instead of the main loop reading source/docs itself.
## Summary table
| session | project | turns | spawns | main-loop out tok | % main-loop (proxy, see caveat) | pre-spawn calls/bytes | longest direct run | classification |
|---|---|---|---|---|---|---|---|---|
| 9f45afcc | cc-os | 255 | 5 | 237,679 | ~98.6% | 19 / 23,658 | 48 | mixed: agent-monitoring + mechanical cache-refresh edits |
| eba26343 | cc-os | 223 | 0 | 216,019 | 100% | 119 / 119,587 (whole session) | 119 (whole session) | scripted headless-eval polling loop — justified |
| 5f53e0c0 | cc-os | 222 | 0 | 314,899 | 100% | 128 / 129,924 (whole session) | 128 (whole session) | OpenSpec apply — Write×13 independent files = **miss candidate** |
| 3fc7bb8c | servers | 90 | 0 | 63,607 | 100% | 44 / 32,250 (whole session) | 44 (whole session) | interactive investigation — justified |
| 7bc0dda4 | servers | 82 | 0 | 39,513 | 100% | 39 / 6,124 (whole session) | 39 (whole session) | interactive troubleshooting (15 human turns) — justified |
| df12b180 | servers/desktop | 24 | 1 | 24,051 | ~94.4% | 4 / 3,154 | 4 | pre-spawn investigation, correct delegation of doc lookup |
## Caveats
- 4 of the 6 sessions are from `cc-os` (matches the actual population: 19 of 21 candidate
sessions in the last 10 days were `cc-os`) — the sample is not representative of all-client
usage, just of what exists in the last 10 days of transcripts.
- "% main-loop" is a **proxy** built only from what subagents returned to the main loop
(tool_result/notification char count ÷4), not measured subagent token spend — real subagent
cost is invisible in every transcript examined (0/6 have `isSidechain:true` lines). Any
economics conclusion about spawn cost-effectiveness needs a different data source (e.g. Task
output files under `tasks/`, if retained) — not attempted here.
- "Longest direct run" for 4 of 6 sessions equals the *entire session* because zero spawns
occurred; this collapses "pre-spawn segment" and "longest run" into the same number for those
rows — noted in the table rather than hidden.
- Miss/justified classification is a single-auditor read of tool-call sequences, not a rubric
score; treat as a directional signal for the eval plan, not a verdict.
## Miss-shape summary
- **The only clean miss candidate found is `5f53e0c0`'s Write×13 run**: scaffolding independent
Ruby class files against an already-fixed design doc, done entirely in the (most expensive)
main loop across a 222-turn, 314,899-output-token session with zero spawns.
- **Scripted/polling loops are not misses even when very long** (`eba26343`, 119 consecutive
direct calls): driving `bin/run`/`sleep`/`wc -l results.tsv` from the main loop is the correct
shape per the existing scripted-bulk-op carve-out — a subagent adds no value polling a script's
own output.
- **Interactive/judgment-heavy sessions correctly stayed direct** (`3fc7bb8c`, `7bc0dda4`): both
have no spawns and no flagged miss runs; `7bc0dda4`'s 15 human prompts in 82 turns make
delegation overhead a net loss.
- **Subagent economics are structurally unmeasurable from transcripts as configured**: 0 of 6
sessions logged sidechain entries even where Agent spawned; only a lossy char-count proxy
exists via task-notification payloads. This is itself an eval-plan-relevant finding — any eval
claiming to measure delegated-vs-direct token spend needs an instrumentation change (capture
Task output, or read `tasks/*.output` files) before it can trust a token-economics number.
- **Where spawns did happen, the main loop still did substantial direct work afterward**
(`9f45afcc`: 4348-call runs after spawns 3 and 5) rather than delegating a second time —
worth checking in future audits whether that's justified (synthesis/judgment) or another miss
shape.
- **No over-delegation observed anywhere** — zero ≤2-call trivial ops routed to a subagent in any
of the 6 sessions.