Skip to content

Observability ​

Every spexso session leaves a durable, greppable trace — and a one-command latency report. Adopted from the Flex Lightweight Harness research (nicoharness): spexso's classic pain is "a small task silently took an hour" with nothing measured; this page is the fix.

How it works ​

.claude/settings.json (shipped by spexso init) registers fail-open, async hooks on SubagentStart, PostToolUse, SubagentStop, and Stop. Each one pipes the hook payload to:

bash
node "${CLAUDE_PROJECT_DIR}/node_modules/@flexso/spexso/bin/spexso.js" observe

which appends one JSON line per event to .spexso/observability/runs/<session-id>.jsonl (gitignored):

json
{"t":1720512345678,"event":"SubagentStart","agent":"spexso-builder"}
{"t":1720512349999,"event":"PostToolUse","tool":"Bash","command":"npm test -- srv/x.test.js"}

Fail-open means: any parse error, missing directory, or crash in the logger exits 0 and never blocks the work it observes.

The hooks call the locally installed @flexso/spexso devDependency's entry script directly with node — deliberately not via npx. The observe hook fires on every tool call and the doctrine hook blocks every subagent spawn; npx adds hundreds of milliseconds of resolution overhead per invocation (notably on Windows), which would add up to minutes of dead time per issue. The direct path requires the package to be installed: always run npm install before working in a spexso project, and treat a missing-devDep warning from spexso init as a blocker (without it, hooks fail — fail-open, so work continues but nothing is observed and no doctrine is injected).

The latency report ​

bash
npx spexso observe report            # latest run
npx spexso observe report <file>     # a specific .jsonl run log
npx spexso observe report --json     # the same numbers as JSON (marathon dashboard)

Deterministic aggregation (no LLM involved):

  • Wall clock — first event to last, flagged ⚠️ over budget when it exceeds budgets.perTaskMinutes from .spexso/config.json (default 30 — budgets is default-seeded by resolveConfig/buildInitialConfig in lib/config.js, so the flag fires out of the box)
  • Phases + glue time — subagent time attributed to plan (planner) / build (tester+builder) / review (reviewer) / other, plus glue: wall-clock time spent outside every subagent span (overlapping spans are interval-merged first). Glue is where CLI cold starts and tracker round-trips hide — the report's most important line when a run "felt slow but the subagents look fine".
  • Subagent hops — one line per dispatch with its duration. Repeated agent types are numbered (spexso-builder #1 … #5), matched by subagent id when the hook payload carries one and FIFO per type otherwise — so task-1's builder and task-5's builder never alias. Spans that never received a SubagentStop are flagged instead of silently corrupting the next span.
  • Test runs — how many test-command invocations the run needed
  • Tool calls — counts per tool
  • CLI calls — how many Bash commands invoked spexso (npx / direct spexso.js) and glab — the tooling-glue counters
  • Re-read files (top 5) — files Read more than once across the run, with size and a ≈token estimate (bytes/4) — exposes the per-spawn rulebook re-read cost (e.g. ux.md loaded by every builder and the reviewer)

--json prints the full summarizeRun object plus file and tokens: the run log file, totalWallMs, phases, spans (each with agent, ms, start, end), issues (per issue size, start, end, ms, status from the marathon notes, and phases: its plan/build/review/finish split), notes (every marathon note in time order), waves, fence, toolCounts, cliCounts, testRuns, glueMs, reads, sizeStats, suggestedSizeScores, unclosedSpans and tokens (totals and buckets by role, model, issue and size). The top-level phases stay agent-based and are not attributed per issue (parallel issues overlap in time); the phase notes are what split each issue. In a run report (--run), a dead issue's last phase is capped at the run's end. Live token counts per issue lag: a runner's and its subagents' transcripts only count from their SubagentStop.

When the run log carries marathon notes (below), the report adds four sections:

  • Issue wall clock by size — median duration + sample count per size:: label, from paired issue start/finish notes (unfinished issues are excluded; no size → m)
  • Suggested sizeScores — each size's median relative to the m median, scaled so m keeps its default score of 2 (budget 6 ≈ three M issues stays true) and rounded to integers (min 1). Printed only when ≥2 sizes (including m, the anchor) have ≥2 finished issues each — otherwise insufficient samples, never a guess from one data point
  • Waves — per wave the wall clock, the slowest sibling, and barrier idle: the sum over siblings of (wave wall clock − sibling duration) — the documented cost of mixed-size waves waiting at the merge-train barrier, now measurable
  • Fence hits — how often the merge train's actual-diff fence tripped, and which issues were deferred

Use it when a task felt slow: the report tells you whether the time went to subagent hops, glue between them, repeated test runs, or context re-reads — before anyone reads a transcript.

Token usage and cost ​

The hooks also record where Claude Code keeps its transcripts: transcript_path (the main session) on SubagentStart/SubagentStop/Stop, and agent_transcript_path (the subagent's own transcript) on SubagentStop. PostToolUse lines skip it — they fire per tool call and the path never changes. At report time spexso reads those JSONL transcripts and sums the usage block of every assistant message. A streamed message repeats its id across several lines, so usage is deduped per message id (max per field — the last line carries the final output count).

text
- Tokens (212 API messages): in=48.1K out=96.3K cache-read=14.2M cache-write=1.1M · €31.40
- Tokens by role:
  - spexso-builder: in=20.4K out=51.0K cache-read=6.9M cache-write=402.0K · €15.10
  - orchestrator: …
- Tokens by model: …
- Tokens by issue: …
- Tokens by size: …
  • Cache tokens are separate — cache-read (prompt-cache hits) and cache-write (cache creation) are priced very differently from fresh input, and on spexso they are usually the bulk: every fresh subagent re-reads the rulebooks. That is where token optimisation pays off.

  • By role — the main session is orchestrator; each subagent transcript is attributed to its agent type (spexso-tester, spexso-builder, …).

  • By issue / size — only when the run carries marathon issue notes. Messages are attributed by timestamp to the issue whose start/finish window contains them. Exact for sequential runs; with parallel.budget > 1 issue windows overlap, and those messages land in (overlap) rather than being guessed. Messages between issues land in (outside issues). An issue with a start but no finish yet (still running) keeps its window open, so a finished sibling never takes its messages.

  • € only with pricing — spexso ships no price table. Add prices per million tokens to .spexso/config.json and the report adds a cost per line (see storage):

    json
    "pricing": {
      "opus":   { "input": 5, "output": 25, "cacheRead": 0.5, "cacheWrite": 6.25 },
      "sonnet": { "input": 3, "output": 15, "cacheRead": 0.3, "cacheWrite": 3.75 }
    }

    The numbers above are placeholders — take current prices from your contract. A model with no matching key (or a key missing one of the four fields) is counted and flagged (n msg(s) without a price), never silently priced at zero.

  • Missing transcripts (moved, deleted, other machine) are skipped; the report says how many and marks the totals as partial.

  • Claude Code only — Codex and opencode transcripts carry no Claude-shaped usage, so the report prints Tokens: n/a for their runs.

Marathon notes — the sizeScores sensor ​

Hooks capture that tools ran; they cannot see marathon semantics (which issue, what size, which wave). /spexso-marathon and spexso-issue-runner therefore fire typed notes at their natural steps — one fire-and-forget CLI call each, never reading the log back:

bash
npx spexso observe note '{"type":"issue","id":"45","size":"m","started_at":"now"}'
npx spexso observe note '{"type":"issue","id":"45","finished_at":"now","status":"ready_to_merge"}'
npx spexso observe note '{"type":"wave","n":1,"issue_ids":["45","47"],"started_at":"now"}'
npx spexso observe note '{"type":"fence","issue_id":"47","overlap":["srv/a.js"],"action":"deferred"}'
npx spexso observe note '{"type":"phase","id":"45","phase":"build"}'

Each note is validated (unknown type, missing id, both/neither of started_at/finished_at, a finish without status, a fence action outside deferred|proceeded → exit 1 with ✗ invalid observe note: <detail>) and appended to the current run log as a {"t":…,"event":"Note",…} line — same file the hook events land in. "now" timestamps are stamped by the CLI. Unlike the hook channel this one fails loud: a malformed note means the emitting prose is broken, and silence would starve the calibration data.

The issue-runner fires a phase note (plan, build, review, finish) before each phase; observe report --json returns them as issues[id].phases (each until the next phase or the issue's end) and every note as notes.

Emission points: the runner notes issue start (after /spexso-start, with the size:: label) and issue finish (with the final status, regardless of outcome); the marathon notes wave start (before batch-spawning runners) and wave finish (all summaries returned); the merge train notes every fence hit with its overlap and deferred/proceeded decision.

One marathon run ​

bash
npx spexso observe report --run <id|latest>

JSON only: the run's observe log cut to the run window, tokens included and also cut to it. The run record comes from .spexso/marathon-runs/ (see Storage).

The calibration loop ​

parallel.sizeScores promised "check against observe data" — this closes the loop:

  1. Run a marathon (/spexso-marathon with parallel.budget > 1)
  2. npx spexso observe report — read the per-size medians and the suggested block
  3. Copy the suggestion into parallel.sizeScores in .spexso/config.json (keep m at 2; the numbers are per-project — a CAP monolith's l is not a UI5 app's l)

Repeat occasionally; medians sharpen as more sized issues finish.

Run logs centralize at the project root: hooks resolve CLAUDE_PROJECT_DIR and always write to .spexso/observability/runs/ there, regardless of which subdirectory a subagent is working in. Run npx spexso observe report from the project root — from inside a .spexso/worktrees/ worktree it will report "no run logs found".

Harness support ​

Observability and doctrine injection are declared per harness through its native mechanism — never emulated (see Harness targets). Where a harness has no mechanism, the rail is a documented gap and spexso init prints one rails line per harness saying what is active vs unavailable — a degraded rail is announced, never silent.

RailClaude CodeopencodeCodex
Doctrine injection✓ SessionStart + every SubagentStart hook (stdout envelope)✓ instructions: [".spexso/rules/doctrine.md"] in opencode.json — the live file loads into every session, so a tuned doctrine applies immediately; subagents get no re-injection✓ same hook events in .codex/hooks.json (spexso doctrine --hook <event>)
Observe: tool events✓ PostToolUse hook✓ .opencode/plugins/spexso-observe.js on tool.execute.before — pipes a Claude-shaped payload to spexso observe, same JSONL log and report✓ PostToolUse hook
Observe: subagent spans / phases / glue✓ SubagentStart/SubagentStop/Stop✗ gap — opencode plugins expose no subagent lifecycle events; the report shows tool counts and re-reads but no spans, phases, or glue time✓ same events; spans need agent_type in the payload — events log either way
Observe: token usage / cost✓ transcripts via transcript_path / agent_transcript_path✗ n/a✗ n/a — no Claude-shaped usage in the transcript
Deny rail✓ permissions.deny✓ permission map (deny last, last-match-wins)✓ spexso guard PreToolUse hook (exit 2 blocks)

Codex runs Claude-style command hooks from .codex/hooks.json (same event names, same stdin payload, same stdout injection envelope) — but hooks are trust-gated: run /hooks once and trust the spexso commands, or every rail silently stays off. On opencode the doctrine rail trades the per-subagent re-injection for zero staleness; the observe gap (no spans) is the price of no lifecycle hooks — revisit when opencode plugins grow agent events.

Existing installs ​

spexso init never overwrites an existing .claude/settings.json. If yours predates the hooks block, init prints a warning; merge the "hooks" object from node_modules/@flexso/spexso/dist/claude-code/settings.json into your settings file once. Hooks added in later releases (such as the UserPromptSubmit session-title hook) are not merged automatically either — copy the missing entries from the same file. The same pattern covers Codex: an existing .codex/hooks.json without the spexso rails is kept but warned about — merge from node_modules/@flexso/spexso/dist/codex/hooks.json.