zuvo:profile-session — Where a session's wall-clock actually went

Sessions get slow for boring, measurable reasons: a full suite re-run per task, four-minute adversarial passes that fired ten times, a sub-agent nobody was waiting on, an API stall. Guessing at which one is expensive — the 2026-07 pipeline forensics measured 28 sessions and found the dominant cost (thread-polling dead-air, ~88h) was not the one everyone blamed (adversarial review, 38 minutes total across all 28).

This skill measures instead of guessing. It reads the transcript's timestamps, charges each gap to the activity that preceded it, and reports the ranked truth.

Scope: wall-clock attribution for a single session, or a comparison of two, plus the token totals the profiler computes (tokens block). Out of scope: per-file / per-include context budgeting (zuvo:context-audit), skill quality (zuvo:skill-eval), fleet-wide trends (~/.zuvo/runs.log + zuvo:retro).

Tokens come from the script or they do not get reported

This line used to read "Out of scope: token cost", and the profiler computed none — so every run asked for a token breakdown produced one by hand. Five profiles of the SAME Codex session then reported gross 202,362,002 vs 203,519,738, model calls 1,395 vs 1,406, and a "strict lower bound" for polling of 45 / 55 / 83 / 396 / 400 calls — a 9x spread, each figure labelled [M] MEASURED.

The trap is not carelessness, it is the data: the two transcript formats define input_tokens with opposite cache semantics. Codex's last_token_usage.input_tokens already includes cached_input_tokens; Claude's message.usage.input_tokens excludes both cache fields. A reader who aliases the key names together under-counts every Claude session by nearly its entire volume.

So:

• Report only the tokens block the profiler emits. It handles each format explicitly and is reproducible — same file in, same numbers out.
• If tokens.model_calls is 0, the answer is UNKNOWN. The transcript carries no usage records. Say that. Do not estimate from message sizes, character counts, or gap durations.
• Never label a hand-derived figure MEASURED. If you computed it yourself rather than reading it out of the profiler JSON, it is [E] ESTIMATE and the method belongs next to it.
• polling is a fixed regex (tokens.classifier), not a per-run judgement about which calls felt like waiting. Quote the classifier when you quote the number. Widening it is a code change to profile-session.py, reviewed once — not a decision re-made each run.
• gross vs fresh: gross is everything billed on the way in (cache reads included) plus output — the quota-shaped number. fresh excludes cache reads. Sub-agent spend is reported separately under tokens.subagents and is deliberately NOT folded into gross.

Argument Parsing

Non-interactive environments: no arguments defaults to --last.

Mandatory File Loading

CORE FILES LOADED:
  1. ../../shared/includes/run-logger.md       -- READ
  2. ../../shared/includes/retrospective.md    -- READ
  3. ../../shared/includes/test-metrics.md     -- READ (frozen COST/SPEED formulas: FRESH_TOKENS, POLLING_CALL, TASK_WINDOW, ACTIVE_MIN — cite, never re-derive)

Prerequisite

The profiler is ~/.zuvo/profile-session.py, installed by scripts/install.sh. Resolve it the same way every zuvo helper is resolved, and if it is absent say so and STOP — do not hand-roll a timestamp analysis, because an ad-hoc one will not use the same attribution rules and its numbers will not be comparable to any other run.

PS="$(command -v profile-session 2>/dev/null || ls ~/.zuvo/profile-session.py 2>/dev/null | head -1)"
[ -n "$PS" ] || { echo "profile-session.py not installed — run scripts/install.sh"; exit 1; }

Phase 0: Locate the transcript

Transcripts are per-host, and the path encodes the project directory:

# Claude Code — directory name is the project path with / replaced by -
CC_DIR="$HOME/.claude/projects/$(pwd | sed 's|/|-|g')"
ls -t "$CC_DIR"/*.jsonl 2>/dev/null | head -5

# Codex — rollouts are not project-scoped; pick by mtime and confirm from the content
ls -t "$HOME"/.codex/sessions/**/rollout-*.jsonl 2>/dev/null | head -5

The newest file is often not the interesting one. A fresh session that just started is the newest and has nine events in it. When the user says "that run was slow", rank by SIZE or by span, not by mtime, and say which file you picked and why. ls -tS gives you the largest-first order.

If the transcript cannot be found, say so plainly and ask for the path — do not profile an arbitrary file and present it as theirs.

Phase 0.5: Refuse to profile the same transcript twice

Do this BEFORE the analysis, not after it. The check is one hash of a path; the analysis is 25-45 minutes of agent work.

ZUVO_DIR="${ZUVO_OUTPUT_DIR:-$(git rev-parse --show-toplevel 2>/dev/null || pwd)/zuvo}"
KEY="$(python3 "$PS" --run-key "$TRANSCRIPT" ${SINCE:+"$SINCE"} ${UNTIL:+"$UNTIL"})"
REPORT="$ZUVO_DIR/reports/profile-session-$KEY.md"

if [ -s "$REPORT" ] && [ "${FORCE:-0}" != "1" ]; then
  echo "ALREADY PROFILED — $REPORT"
  echo "  transcript: $TRANSCRIPT"
  echo "  Re-run with --force to profile it again."
  exit 0
fi

Write the report to $REPORT. A report is an artifact with a path, so the early exit can hand the caller the actual file instead of telling them a matching retro "exists" somewhere.

Why the key is the transcript and not the caller. The retro layer deduplicates on skill + project + sha7, and project is the directory the skill was INVOKED in. For most skills that is correct — a review of repo A is not a review of repo B. Here it is wrong: the artifact being analysed is a TRANSCRIPT, and a transcript is the same transcript whichever worktree the agent happened to sit in.

Measured 2026-08-18: ONE Codex rollout was profiled at least eight times in a day, logged under five different "projects" (mutation-data-flush-final, rs_be, tgm-survey-platform, ResearchShieldNew, mutation-data-flush-profile-detailed), so the key never matched and every run looked new — 12 profile-session runs that day, hours of duplicated analysis. It also explains the contradictory self-reports: some runs printed "append-retro correctly performed an idempotent no-op", others did the full analysis, purely by invocation site.

--run-key hashes the transcript's REALPATH plus the window bounds — the inputs that determine the answer — and nothing about the caller. It reads none of the transcript, which is what makes it cheap enough to run here. Keep project as a display field; it is a property of the invocation site, never of the artifact's identity.

Phase 1: Run the profiler

python3 "$PS" <transcript> [window_start_iso] [window_end_iso]

Output is JSON:

Thresholds are tunable when a project's shape demands it — ZUVO_PROFILE_LONG_GAP_S (default 1800) and ZUVO_PROFILE_MAX_GAP_S (default 14400). Say so in the report if you change them; the numbers are not comparable across different thresholds.

Phase 2: Read the categories honestly

A gap is charged to whatever ran immediately before it, which is sound only while that activity could plausibly still be running. The profiler bounds this, and you must read the result with the same care:

Dispatch follows ../../shared/includes/execution-policy.md through env-compat. Reuse existing authorization within that policy; session restrictions take precedence. Run each required gate and report its actual independence or an unmet requirement.

Report the span three ways, not one: total span, span minus session boundaries (the real working time), and the top three attributable categories. A single "the session took 83 hours" number is true and useless.

Phase 3: Name the specific cause

categories_min says what kind; top_gaps says which one. Always go to the rows — a category total of 200 minutes means something different when it is one 200-minute gap versus forty 5-minute ones.

For each of the top 3 attributable gaps, state: the minutes, the timestamp, and the exact command or agent prompt from the what field. "adversarial-review: 4 min × 11 calls on the same task" is actionable; "adversarial-review: 47 minutes" is not.

Cross-check the count fields against the categories. adversarial_calls: 11 on a single task is a finding regardless of the minutes — it means a re-run loop, which adversarial-loop.md caps at 2.

Phase 4: Report

SESSION PROFILE — <file>
────────────────────────────────────────────────
Span:            <N>h total  |  <M>h working (boundaries excluded)
Events:          <N>  (tools <N>, sub-agents <N>, adversarial <N>)

Where the working time went
  <mins>  <category>     <one-line reading>
  ...

Biggest single gaps
  1. <mins>  <at>  <category>
     <the command or prompt>
  2. ...

What to change
  1. <specific, measurable change> — expected saving <N> min/session, based on <the row above>
  2. ...

Not the problem (measured, so nobody re-litigates it)
  <category>: <mins> — <why this is fine>

The last block matters as much as the first. The 2026-07 forensics' most useful output was proving adversarial review was innocent, which stopped an optimization that would have removed a quality gate for no gain. If a suspected cause turns out to be cheap, say so explicitly.

Every recommendation must cite a row from top_gaps. A suggestion with no measurement behind it is exactly the guessing this skill exists to replace — leave it out.

--compare mode

Profile both, then print the categories side by side with deltas. State plainly whether the change moved the category it was supposed to move; a total that dropped while the target category did not means something else changed (different work, different day), not that the fix worked.

Completion Gate Check

COMPLETION GATE CHECK
[ ] Transcript identified, and WHY that file was chosen is stated
[ ] Profiler ran (never a hand-rolled timestamp analysis)
[ ] Session boundaries excluded from the working-time figure
[ ] Every recommendation cites a specific top_gaps row
[ ] Cheap-but-suspected causes reported explicitly as not-the-problem
[ ] Run: line printed and appended to log

Completion

PROFILE COMPLETE
-----
Transcript: <file>
Span: <N>h total / <M>h working
Top cost:  <category> <mins>
Run: <ISO-8601-Z>	profile-session	<project>	-	-	<VERDICT>	-	<mode>	<NOTES>	<BRANCH>	<SHA7>	<INCLUDES>	<TIER>
-----

Retrospective (REQUIRED)

Follow the retrospective protocol from retrospective.md. Gate check → structured questions → TSV emit → markdown append. If gate check skips: print "RETRO: skipped (trivial session)" and proceed.

Append via wrapper (REQUIRED). Never >> directly to ~/.zuvo/runs.log — the wrapper is the gate that verifies a retro entry exists for this run. Order: retro bash executed → wrapper invoked → completion claimed.

printf '%b\n' "$RUN_LINE" | ~/.zuvo/append-runlog

Expected stdout: OK: appended to runs.log (retro verified for <skill> on <project>). If exit 2 with RETRO_REQUIRED — go execute the retro bash from retrospective.md first; never bypass with ZUVO_SKIP_RETRO_GATE=1. After the wrapper succeeds, print a Logs: evidence line (tail -1 ~/.zuvo/retros.log, grep -c "^<!-- RETRO -->" ~/.zuvo/retros.md, tail -1 ~/.zuvo/runs.log) before claiming completion.

<mode>: the mode label (last, path, skill, compare).

Principles

1. Measure, then cut. Every session-speed change in this repo's history that was made without a measurement first either did nothing or removed a gate that was not the problem.
2. A total is not a finding. Attribute it, then name the command.
3. Exonerate as loudly as you accuse. "This is not the bottleneck" is a result worth reporting.