Skip to content

Run-friction analyzer

OpenSwitchboard can diagnose what cost a run time or made it stumble from its own run-event stream — slow model turns, slow or failed tool calls, retries, setup/install time, wrap-up, budget hits, and exec-infrastructure failures — as a structured, deterministic diagnosis. This is the observe → diagnose half of the self-improvement loop. Everything in this feature is read-only analysis; the propose half — clustering these diagnoses across recent runs and filing deduped issue proposals — is self-improvement.md.

Pure and deterministic (locked design). analyzeRunFriction(events, opts?) is a function of the event stream alone — no clock, no I/O, no mutation of its input. The same events always yield a deep-equal diagnosis, so it runs identically over a live backlog, a saved capture, or a test fixture. That property is what will later let a fix-proposer be tested against recorded runs.

Signals ride the existing stream (locked design). Rather than a second telemetry channel, the run-visibility RunEvent stream (run-visibility.md) was extended additively: every event may carry at (epoch ms, from the runner's injectable clock); a tool_result may carry infra: true when the failure was an ExecInfraError (the sandbox/transport, not the command); and a new run_note variant carries the runner's lifecycle notices as typed kinds — wrap_up, time_budget_exhausted, turn_budget_exhausted, sandbox_dead — alongside the unchanged free-text onProgress. Consumers that only know tool_call/tool_result keep working; the Slack card and live page render notes as a line. Redaction is unchanged: findings derive only from already-redacted summaries.

Behavior

  1. Categories. Each finding has exactly one FrictionCategory: slow_tool (a tool.* span taking ≥ slowToolMs, default 30 s; high at ≥ 2×), slow_model_turn (a model.turn span taking ≥ slowModelTurnMs, default 60 s; high at ≥ 2×; anchored to the turn's own span_end and naming what it produced, e.g. model turn took 3m 42s before: $ grep …, (narration), (answer); a 31-min run with 50 s of tool time and 35 one-line greps must not diagnose as no friction detected), failed_tool (ok:false, incl. an unknown tool; medium, or high when the failure also took ≥ slowToolMs), retry (the same tool + call summary re-issued after that exact call previously failed; counted per re-issue), setup_install (a bash command that is a package-manager install / git clone / similar — incl. python -m pip install and corepack <pm> wrappers — matched at the start of a shell segment with the subcommand word ending there and quoted strings blanked first, so cd x && npm install counts while echo npm install, echo "cd x && npm install", npm ci-lockfile-report, and npm test do not), wrap_up (the runner's wrap-up note; its extent is from the note to the end of the window), budget_hit (time- or turn-budget exhaustion note, high; no extent), infra_failure (an infra:true result — the finding names the command that was running — the sandbox_dead and fleet_busy notes (no extent), or — in a finished stream — a tool_call with no result, i.e. the run died mid-tool, whose extent is the open tool span's; all high but fleet_busy). Every duration comes from ONE span set (tracing.md item 14): the stream normalized by normalizeSpans — a tool pair whose twin span the record budget dropped gets it back from the pair's own stamps — so a finding carries the duration of the span it is about, and a stream with no model.turn spans has no model time and no slow_model_turn, whatever the gaps between its content events.
  2. Precedence — one finding per event. infra beats everything (a dead sandbox is not a failing command); setup_install beats failed_tool/slow_tool (a slow or failed install is still setup cost, so the category total is the true install bill; a failed install is high); then failed_tool; then slow_tool. retry is anchored to the re-issued call and is additional to whatever its result yields.
  3. Timings are optional, and there is one code path. A stream is timed when a content event carried at or a window was given: runMs — the run's window (receivedAtfinishedAt, or now while live) when the caller passes one, else first→last content stamp (a stdin capture); toolTimeMs (the sum of the tool.* spans); modelTimeMs (the sum of the model.turn spans, present only when the stream had a turn); per-finding durationMs; per-category durationMs — the sum of the findings' durations for the tool-denominated categories and slow_model_turn (its turns are disjoint, so the sum is the union), the union of the findings' intervals for wrap_up, budget_hit and infra_failure (three calls of one batch dying together are one interval, not three). DENOMINATOR_OF names what each category's time is a share of — tool time for slow_tool/failed_tool/retry/setup_install, run time for the rest — so no share can exceed 100 %. For an agent run thinking ≤ model time and tools ≤ tool time hold by construction (a union is at most a sum over the same span set); a command run's tools bucket is the command's own work and the report prints no tool calls/tool time/model time line for it. Without timings — a hand-written capture, a record from before spans — nothing is special-cased: the same classification, and every timed field is simply absent (a pair without a stamp gets no span, so no duration; runMs, toolTimeMs, modelTimeMs are absent; the report prints - in the time column and no run/tool time/model time totals). The shape (tracing.md item 5): with a window and finished, the diagnosis carries shape — the window's seven terms from partition over the same span set (windowMs, gettingReadyMs, thinkingMs, toolsMs, finishingUpMs, overheadMs, notRecordedMs, notLoadedMs), owner deciding whether run.command is tools (a command run) or getting ready; the finish-site diagnosis is what the run record stores and the closed Slack card's shape line reads, so the card, the record and the report agree. Live, or without a window, there is no shape. Every duration surface prints through formatDuration (report style, hours included).
  4. Verdict. One line naming the dominant cause: the category with the most attributed time (ties → most findings → category order), with its share of its denominator (DENOMINATOR_OF: … (60% of run time) for the run-denominated categories, of tool time for the tool ones); without timings, the category with the most findings; no friction detected when there are no findings. The verdict names the dominant friction category and the shape names the dominant bucket — two lenses on one span set, printed one under the other. Labels are one vocabulary: slow tool calls, slow model turns, failed tool calls, retries, the repo's setup/install, agent wind-down, budget hits, infra failures — the verdict, the report's category table (column sized to the longest), its finding lines and the friction proposals' titles all print them, never the category ids. byCategory always contains every category (zeroed), so consumers need no undefined checks. Findings are in stream order, each anchored to an eventIndex. The text report prints events, then tool calls and tool time only when a tool ran, run when timed, model time only when the model turned, (input truncated — some records were dropped before analysis) when the input lost records, and shape: <line> beneath the totals when the diagnosis has one (<total> (one bucket) when fewer than two buckets are informative).
  5. Mid-run vs finished. opts.finished (default true) controls whether a trailing unpaired tool_call is friction: in a finished stream it is an infra_failure ("no result … run ended mid-tool"); in a live one it is simply still running.
  6. Read-only surfaces. GET /runs/:id/friction?t=<token> returns { id, finished, diagnosis } as JSON (no-store, GET-only → 405) for any run still in the registry — live or finished within the TTL — behind the same constant-time capability-token gate as the page and stream (wrong/missing token or unknown run → 404, existence never revealed). npx tsx src/cli.ts friction analyze [source] [--slow-ms n] [--in-progress] [--json] (CLI only; stdin for -) analyzes a saved stream: JSON lines of RunEvents, or a raw SSE capture of /runs/:id/events (curl output — data: frames; retry:/event:/comment lines and the end payload are skipped). Input is external, so each line is shape-checked (string tool/summary, boolean ok, known kind, numeric at when present) — a recognized type alone is not enough; malformed lines are skipped and counted, never fatal (the analyzer itself also tolerates a non-string summary); zero events → exit 1. --in-progress marks a mid-run capture (finished:false) so a trailing unpaired call is not misread as a dead run; without the flag, a stream that ends on an unpaired call gets a stderr hint pointing at --in-progress. Neither surface mutates anything.

Validation criteria

CriterionEvidence
Empty stream → zeroed diagnosis, no findings, no friction detected[unit] src/core/runFriction.test.ts::analyzeRunFriction — empty / untimed input::an empty stream yields a clean, zeroed diagnosis…
Clean fast run → no findings; runMs/toolTimeMs computed[unit] ::a clean, fast run has no findings and a no-friction verdict
Untimed stream (no stamps) still classifies, with no durations and no timed fields[unit] ::untimed events (a hand-written capture) still classify failures/retries, with no durations
Deterministic; input not mutated[unit] ::is deterministic: the same stream yields a deep-equal diagnosis, ::does not mutate its input
slow_tool at threshold, high at 2×, not flagged under[unit] ::slow_tool: a tool call whose result arrives past the slow threshold, ::slow_tool: ≥2× the threshold is high severity; under the threshold is not flagged
slow_model_turn at threshold (default 60 s, configurable), high at 2×, not flagged under; anchored to its model.turn span end and naming the produced event; modelTimeMs summed[unit] analyzeRunFriction — slow_model_turn…::flags a model turn at or past the threshold…, ::≥2× the threshold is high severity; the threshold is configurable
A narrating completion is one turn naming (narration); the answer is the last turn's product; a stream without model.turn spans has no model time and no slow turn whatever its gaps[unit] ::a narrating completion is one turn…, ::the final answer is the last model turn's product…
Untimed streams: no slow_model_turn, no modelTimeMs[unit] ::untimed streams never produce slow_model_turn and carry no modelTimeMs
Verdict share for dominant model time is of run time, never tool time[unit] ::the verdict for dominant model time is a share of RUN time (tool time would exceed 100%)
failed_tool incl. unknown tool; high when the failure was also slow[unit] ::failed_tool: an ok:false result (including an unknown tool), ::failed_tool severity scales with how long the failure took
Analyzer tolerates a non-string summary from an external capture[unit] ::tolerates malformed field types from an external capture (non-string summary/tool) without throwing
infra_failure finding names the command that was running[unit] ::infra_failure: an infra-flagged tool result is an infra failure (asserts the call summary is in the finding)
retry only after a failure of the same call; repeats without failure are not retries[unit] ::retry: the same call re-issued after it failed…, ::retry: a repeated call that never failed is NOT a retry (red-verified: disabling the failed-call check fails these)
setup_install classification, totals, precedence over slow/failed, package-manager coverage, segment-start matching[unit] ::setup_install: install/clone commands are classified with their total time…, ::setup_install: a FAILED install is classified as setup (high)…, ::setup_install: recognizes the common package managers… (red-verified: disabling the install branch fails these)
wrap_up with wind-down duration; budget_hit for both budget kinds; infra_failure for infra:true and sandbox_dead[unit] ::wrap_up: …, ::budget_hit: …, ::infra_failure: an infra-flagged tool result…, ::infra_failure: the sandbox_dead note…
Finished stream: unpaired trailing call → infra_failure; unfinished: not flagged[unit] ::an unpaired trailing tool_call (run died mid-tool) is reported as an infra failure, ::an unpaired trailing tool_call in an UNFINISHED stream (finished:false) is not flagged
Verdict = most time (with share) / most findings without timings; byCategory complete[unit] ::the verdict names the category that cost the most time…, ::with no timings the verdict falls back…, ::byCategory always lists every category
Text report renders verdict, totals (incl. model time), category table, findings[unit] formatFrictionReport::*
Runner stamps at from its clock on every event[unit] src/runner.test.ts::run-friction signals…::stamps every event with \at`…`
Runner marks ExecInfraError results infra:true and nothing else[unit] ::marks an ExecInfraError result with infra:true; an ordinary tool error is NOT marked
Runner emits run_note for wrap-up, turn/time budget exhaustion, sandbox death[unit] ::emits a run_note for the wrap-up warning and for turn-budget exhaustion, ::emits time_budget_exhausted…, ::emits sandbox_dead…
Existing consumers unaffected: card + registry receive notes; page renders them[unit] src/core/dispatcher.test.ts::live run-view wiring…::registers the run, publishes its events, and finishes it (asserts the note reaches the registry)
snapshot is token-gated, returns a copy + finished flag[unit] src/core/runRegistry.test.ts::snapshot — token-gated read of a run's backlog …::*
/runs/:id/friction: route parsed; 404 on bad/missing token; JSON diagnosis (no-store, 405 non-GET); mid-run finished:false[unit] src/channels/liveView.test.ts::GET /runs/:id/friction…::*
parseRunEventLines parses JSONL and raw SSE captures, skips garbage AND wrong-shaped events; friction analyze [source] [--slow-ms n] [--in-progress] reads a file or stdin, renders the report + skipped count, --slow-ms/--in-progress reach the analyzer, a missing file is not_found, a stream without events invalid_input, and the command is CLI-only[unit] src/core/runEventLines.test.ts::*, src/core/commands/friction.test.ts::friction.analyze (CLI only) — the former frictionCli::*
The --in-progress hint appears only when a default analysis blames a trailing unpaired call[unit] src/core/commands/friction.test.ts::friction.analyze (CLI only)…::--slow-ms and --in-progress reach the analyzer…
CLI end-to-end over a saved SSE capture prints a report[agent] npx tsx src/cli.ts friction analyze <capture.sse> on a curl-saved /runs/:id/events stream → a verdict: line, totals, category table, findings.
Friction JSON of a real deployed run via the live link[gap] Open <live link> with /events replaced by /friction on a finished run within the TTL → 200 JSON with a plausible verdict.
3: with a finished window runMs is the window, model/tool time are the spans' sums, shape partitions the window and its identity holds; the slow turn anchors to its span end and names the call it produced[unit] src/core/runFriction.test.ts::analyzeRunFriction — the window, the shape and the span set (docs/reference/specs/tracing.md)::with a finished window…
3: no window (a capture) → no shape, runMs first→last; live with a window → no shape; an open turn on a live read counts to the window's end[unit] ::without a window (a stdin capture)…, ::a live read: an open model turn runs to the window's end…
3: a command run's run.command is its tools; the same stream as an agent run is getting ready[unit] ::a command run's window: \run.command` is its tools`
3–4: run-denominated categories take the union of their findings' intervals (a batch dying together is one interval), DENOMINATOR_OF covers every category, the share never exceeds 100 %; wrap-up runs to the window's end, a budget hit prints -[unit] ::run-denominated categories take the UNION…, ::wrap-up runs from the warning to the window's end…, ::every category names its denominator
4: the report's shape line, the gated totals lines, the labels[unit] ::the report: the shape line under the totals…, formatFrictionReport::renders the verdict, totals, a per-category table, and each finding on one line
1, 3: differential — a record whose tool.* twins the budget dropped is timed like the full stream (the pairs' own stamps); a record with no span records at all is a content stream: the window, the pairs' tool time, no model time; a model.turn span is not a step and never moves the clock[unit] ::differential: a record whose tool.* twins the budget dropped…, src/core/runFriction.test.ts::analyzeRunFriction — narrative events are not steps…::a \model.turn` span is not a step…`
3: the record's diagnosis is the finish-site one over the run's window and carries the shape; /runs/:id/friction and the service pass the window and the live schema[unit] src/core/dispatcher.test.ts::friction diagnosis reads the registry backlog …::the run record's diagnosis — what the friction ledger reads…, src/core/runsService.test.ts::RunsService.getRunFriction::passes the injected analyzer the live events and finished flag