feat(cli): wait_loop finding, API-time metrics, longest-turn inventory

[axisrow]

What

Token-economics layer for the session CLIs, based on a corpus audit (1266 sessions): 47.5% of all billed tokens were "sleep" — rounds that re-read the whole context while producing ≤300 output tokens (orchestrator night-watches, poll loops like Bash true ×114).

wait_loop finding (analyze:session)

• A round billing ≥50k context with ≤300 output = a tick; a turn with ≥5 ticks is a wait_loop (high at ≥20 ticks). tokensWasted = Σ tick context — "what the sleep cost".
• Retry copies (Doubled findings from identical provider entries (different requestIds) #15) are excluded; tick thresholds are exported consts calibrated on the corpus; the ≥20 high-severity cutoff is inline.

API time instead of wall-clock

• TurnRow.activeMinutes / ledger.activeMinutes (analyze:session) and activeMs / longestTurnMs (inventory): inter-round gaps capped at 10 min (TURN_IDLE_GAP_CAP_MINUTES) — hours of orchestrator idle count as zero. Negative gaps clamp to 0.
• Gap anchors are request-deduplicated on both sides: one anchor per requestId, anchored at the last streaming snapshot — inventory parity with analyze:session is structural, not coincidental.
• analyze:session: active: Xh Ym (wall …) session line, dur column in BY TURN, longest turn line, totals.longestTurn in JSON.
• analyze:sessions: active / wall / max turn / cycle columns, --sort active|turn|streak, new --min-turn-minutes / --min-streak filters. --min-streak help states the 3x recording floor (runs < 3x are never recorded — 1–2 aren't silent no-ops).
• --min-minutes semantics change: it now filters on active time, not wall-clock duration (results of old invocations change silently — README/skills doc update is a known follow-up).

long_turn + loop_streak findings

• long_turn (≥45 active minutes): severity high, but tokensWasted is 0 — it is an observation, not waste; the summary carries the activity numbers, so JSON consumers summing tokensWasted are unaffected.
• loop_streak: back-to-back identical calls via normalizeCallKey (full input), no-op vs env-loop flavor by result errors. Cross-validated live: found the 4×Bash|true streaks (×44/×27/×25/×14) in srouter-177.

Inventory turn tracking (light scan)

• Turn boundaries go through the same isParsedUserChunkMessage guard as buildLedger (cast shim over the raw line's type/isMeta/content; !isSidechain stays local — sidechain never splits main-chain turns). Array-content user messages split turns; <local-command-stdout>/caveat/<system-reminder> lines don't — the inventory turn model cannot drift from analyze:session.
• Cross-check (direct-cli orchestrator session): inventory max turn 217 min vs analyze:session 218 min — same turn model, difference is per-turn rounding.

Review follow-ups included

• 6273102 — long_turn.tokensWasted → 0, activeMs request-snapshot parity (one anchor per requestId), honest --min-streak help.
• 48fe08f — faithful turn-boundary guard + tests for array-content and local-command-stdout lines.

Validation checklist

• pnpm typecheck
• pnpm lint (0 errors, 5 pre-existing warnings)
• pnpm test (780 passed — new coverage: wait_loop tick gating, loop_streak flavors, activeMinutes + caps + date-window recompute, longestTurnMs boundaries incl. array-content and stdout lines, flag parsing)
• Live: srouter-177 → wait_loop 242 ticks / 74.5M tok + 4 Bash|true streaks; wordstat orchestrator → no long_turn (idle excluded); direct-cli max turn 217/218 min consistent across both CLIs

🤖 --json contracts stayed additive: ledger.activeMinutes, totals.longestTurn, activeMs / longestTurnMs / cycles — no renames or removals.

[axisrow]

Review: wait_loop / API-time / longest-turn

Verified on the PR branch: pnpm typecheck ✅, pnpm lint ✅ (0 errors, 5 pre-existing warnings), pnpm test ✅ (778 passed). Live runs against the local corpus confirm the inventory numbers (direct-cli 5d9d6828 max turn 3h38m) and the feature generally works as described. Findings below, most severe first. Overall: the plumbing (capped gaps, filterLedgerByDate recompute, additive JSON fields, retry-copy exclusion from ticks) is solid; the two heuristics' labels and waste accounting need tightening before this becomes the headline "47.5% sleep" metric.

---

1. [high] wait_loop cannot distinguish cheap productive rounds from sleep ticks

src/cli/analyzeSession.ts:722-733 — a tick is any round with contextSize ≥ 50k && outputTokens ≤ 300. That token signature matches every small tool-call round of any big-context session (a Bash call + one-line text generates 50–300 output tok), not just polling. There is no no-progress discriminator (no tool call, zero contextDelta, repeated call — nothing).

Empirical check on an ordinary dev session (6321fccb, tg-content-factory, anthropic-style, real work): 9 wait_loop findings across 24 turns, e.g. turn 16 — 13 "ticks", all Bash, outputs 86–296 tok, ctx ~140–150k, while the surrounding hour shows 188 Bash calls + Edits + Reads. The summary ("quiet rounds re-read ~X tok") counts the full context per tick as wasted → ~19M tok of a working session gets labeled sleep. The gh run view ×54 polling in the same session is genuinely caught, so the signal isn't vacuous — but per-turn aggregation turns "many rounds were cheap" into a "wait-loop" verdict for turns that were mostly real work.

Suggestions (any one helps): require the turn to show no counter-evidence (e.g. fire only when ticks dominate the turn's rounds, or when tick rounds have no tool call / zero context growth); and/or reframe the summary to report ticks vs total rounds of the turn so a reader can judge. Same for tokensWasted: summing whole contextSize per tick overstates "what the sleep cost" — cache-read price is ~5% of input, and part of the re-read is the unavoidable cost of any round.

2. [medium] --min-minutes semantics change contradicts the documented contract; skills/README not updated

src/cli/sessionInventory.ts:508 — the flag silently switches from wall-clock to active time. README.md:236 explicitly promises --min-minutes among "Existing per-command flags, unchanged" (and README.md:224 shows an example invocation whose result now changes), while both shipped skills document the old behavior: skills/sessions-inventory/SKILL.md ("only sessions running at least N minutes", old column/sort list) and skills/audit-session/SKILL.md (findings table lacks wait_loop/long_turn/loop_streak; the plugin ships these files). Any existing --min-minutes 120 invocation now returns fewer rows with no error.

Options: update README + both SKILL.md in this PR (cheapest), or keep the old filter and add --min-active-minutes. Also consider whether default --sort duration (wall) paired with active-time filtering is the right default pairing.

3. [medium] Inventory turn boundary is not a faithful mirror of isParsedUserChunkMessage

src/cli/sessionInventory.ts:181-191 — the cheap mirror (string content, !isMeta, !isSidechain, no <teammate-message) diverges from the guard used by buildLedger:

• <local-command-stdout> / <local-command-caveat> / <system-reminder> user lines have falsy isMeta and string content (verified in real session data), and isParsedUserChunkMessage excludes them via SYSTEM_OUTPUT_TAGS — the mirror does not, so every bash-mode/! command output splits a turn in the inventory → longestTurnMs underestimates vs analyze:session's longestTurn, and --min-turn-minutes / --sort turn are built on a different turn model than the one cross-checked in the PR description.
• Array-content user messages with text blocks (newer format, accepted by the guard) are not boundaries in the mirror (typeof content === 'string') → the opposite divergence, merging turns.
• includes('<teammate-message') vs isParsedTeammateMessage — a user literally quoting the tag string is excluded.

The one-session cross-check (3h38m = 218 min) passed only because that session has no such lines. Cheap fix: apply the same SYSTEM_OUTPUT_TAGS prefix checks and accept array content with a text/image block.

4. [medium] long_turn books the entire turn's billing as tokensWasted, always high

src/cli/analyzeSession.ts:706-719 — every pre-existing finding type counts the wasted portion; long_turn sets tokensWasted: sumBilled(all rounds of the turn). A 45-min turn of genuine work → high-severity finding claiming tens of M "wasted" tokens; it then floats to the top of the severity/tokensWasted sort, and any consumer summing tokensWasted inflates total waste (and double-counts turns that also carry wait_loop). The summary line ("active N min, X tool calls …") is the useful part — consider tokensWasted: 0 (observation, not waste) or severity: 'medium' unless a loop/wait signal co-fires on the turn.

5. [low→medium] loop_streak false positives from file-tool keys; hardcoded cutoffs

src/cli/analyzeSession.ts:418 — Read/Write/Edit keys are name|file_path (offset/limit/old_string ignored), so chunked reads or successive edits of one file form a "streak". Real occurrence in 6321fccb turn 4: Read|… x3 back-to-back (no-op loop) — that's a mislabel for ordinary file work. Suggest including offset in Read keys (or not labeling file-tool streaks "no-op loop"), and/or raising loopStreakMin. Also the severity cutoffs (>= 5 → high in flushStreak, >= 20 for wait_loop at analyzeSession.ts:732) are inline magic numbers while sibling thresholds are exported consts — export them with the others.

6. [low] Inventory cycles counts router-retry copies

src/cli/sessionInventory.ts:129-152 — countCalls walks all main-chain assistant lines deduping only by requestId|toolUseId; retry copies (#15) re-log with a new tool_use id and no requestId, so each copy inflates the streak by one. analyze:session's loop_streak skips retry copies, so the two CLIs disagree on streak counts for router sessions (the comment documents the bashStem divergence but not this one). At minimum worth a comment; filtering copies streaming-side is harder, so maybe just document it.

7. [low] Test gaps for the new branches

Covered well overall, but untested: wait_loop high branch (≥20 ticks); long_turn summary content (tool top-5); bashStem as a unit (the documented quoted-pipe merge has no test); teammate ping not splitting an inventory turn (asserted in a comment, no test); --min-turn-minutes/--min-streak filter effects (only parsing is tested); retry-copy inflation from #6; non-monotonic timestamps through turnActiveMinutes (negative-gap clamp).

---

Not broken, checked explicitly: existing finding types and their severities unchanged; --json contracts only gain additive fields (ledger.activeMinutes, totals.longestTurn, activeMs/longestTurnMs/cycles) — no renames/removals; no new low findings so --min-severity filtering behavior is stable; ghosts and retry copies correctly excluded from wait_loop ticks; negative timestamp gaps clamped; filterLedgerByDate recomputes activeMinutes correctly (tested).

Verdict: close — #1 (wait_loop framing/waste accounting) deserves a follow-up before the "47.5% sleep" number is quoted anywhere; #2–#4 are small diffs worth doing in this PR.

[axisrow]

Approving — non-blocking consistency notes below; nothing here blocks merge.

Reviewed the diff against main: wait_loop / long_turn / loop_streak findings, capped-gap active time (turnActiveMinutes, activeMs, longestTurnMs), inventory cycles, and the 12 new tests. The core logic is sound: window-filtered ledgers recompute activeMinutes from kept rounds only; wait_loop ticks exclude ghost rounds and retry copies by construction; the streak walk skips retry copies and counts repeats-only tokens; inventory boundary resets and the final flush order are correct. The --min-minutes wall-to-active semantic change is documented in help text and the summary note.

Findings (inline): (1) the inventory turn boundary covers only the string-content branch of isParsedUserChunkMessage — array-content user prompts never split turns; (2) activeMs counts intra-request streaming gaps the analyze CLI does not; (3) long_turn books full turn billing as tokensWasted, which dominates findings sort order; (4) --min-streak below 3 is a silent no-op.

[axisrow]

Approving — follow-up verified; one earlier note remains open (non-blocking).

Checked the follow-up commit against the previous review:

• long_turn now books tokensWasted: 0 with a rationale comment and a test assertion — sort order no longer rewards healthy turns over real waste.
• activeMs parity: streaming snapshots of an already-seen requestId add no gap but still advance the anchor — this matches analyze:session keeping one round per request anchored at its last line. Verified the ordering: usageByRequestId.set happens after the snapshot check on the same iteration, so the first line of a request still counts its gap, and a falsy requestId never enters the map, so it never reads as a snapshot. Updated fixture test (120000 → 60000) documents the semantics.
• --min-streak help text now states the 3x floor in both the header comment and the flags listing.
• No leftover references to the removed sumBilled helper.

Still open from the previous review (unchanged, fine to defer): the inventory turn boundary at src/cli/sessionInventory.ts:185 mirrors only the string-content branch of isParsedUserChunkMessage — array-content user messages (the newer session format) never split inventory turns, and local-command-stdout strings split where buildLedger does not. Harmless on the current string-content corpus; flagging again so the approximation stays a known one. If it is deliberately deferred, a one-word note in the boundary comment (same as the existing ≈ remark) naming the array-content gap would make that explicit.

[axisrow]

Approving — boundary finding resolved.

Verified 48fe08f: the hand-rolled mirror is gone — the scan now calls the real isParsedUserChunkMessage through a minimal shim (type/isMeta/content, the only fields the guard reads), so inventory turn boundaries match buildLedger by construction instead of by copy. The shim object is only allocated for user lines thanks to condition ordering, the falsy-isMeta case moved into the guard correctly, and the local !isSidechain exclusion is kept as a documented deliberate difference. The two new tests pin both halves of the old divergence: array-content user messages now split turns, and local-command-stdout strings no longer do.

That closes all findings from this review thread (long_turn waste, activeMs request-parity, --min-streak floor, and the turn boundary). Nothing further from me — LGTM.

[axisrow]

Approving — final state of the PR verified at head 48fe08f; no new changes since the last review pass.

Cumulative verification across the review cycle:

• wait_loop / long_turn / loop_streak findings: thresholds exported, ghosts and retry copies excluded by construction, repeats-only token accounting, env vs no-op flavor — sound, covered by tests.
• long_turn books tokensWasted: 0 (observation, not waste) with a rationale comment and a test assertion.
• activeMs request-parity: streaming snapshots of an already-seen requestId add no gap but advance the anchor — matches analyze:session keeping one round per request; ordering of the map write verified against the snapshot check.
• --min-streak 3x floor documented in the header comment and flags listing.
• Turn boundary: the hand-rolled mirror was replaced with the real isParsedUserChunkMessage called on a minimal shim (type/isMeta/content — the only fields the guard reads), so inventory turns match buildLedger by construction. Local !isSidechain kept as a documented difference. Tests pin both halves of the old divergence: array-content user messages split turns, local-command-stdout strings do not. Live cross-check: inventory max turn 217 min vs analyze:session 218 min — rounding only.

All findings from all review threads are addressed. Nothing further — LGTM.