|
| 1 | +# PerfTrace attribution guide |
| 2 | + |
| 3 | +How to capture a slow session, dump local spans, and run the offline attribution |
| 4 | +report. No OTEL collector, no PostHog, no network. |
| 5 | + |
| 6 | +See also: [`PERFTRACE.md`](./PERFTRACE.md) for the span model, dump schema, and |
| 7 | +`jq` recipes. |
| 8 | + |
| 9 | +## Why this exists |
| 10 | + |
| 11 | +When a session feels slow, the first question is **where the wall time went**: |
| 12 | + |
| 13 | +| Category | Meaning | |
| 14 | +|---|---| |
| 15 | +| `inference` | Model call wall (`inference` spans). Nested `inference.ttft` vs `inference.stream` show wait-for-first-token vs rest of stream. | |
| 16 | +| `tools` | Tool invocations under the turn. | |
| 17 | +| `permission.wait` | Ask-gate / approval idle time (when instrumented). | |
| 18 | +| `subagent` | Child agent lifetimes (fanout cost). | |
| 19 | +| `other` | Turn wall not covered by the above — scheduling, TUI, un-instrumented work, gaps between phases. | |
| 20 | + |
| 21 | +Shares are **exclusive** over completed turn wall. Nested TTFT/stream and |
| 22 | +`adapter.transport` are diagnostic splits (they are not added on top of |
| 23 | +`inference` in the exclusive table). |
| 24 | + |
| 25 | +## Capture a real slow session |
| 26 | + |
| 27 | +1. Prefer a repro that exercises the pain: high reasoning, several tools, and |
| 28 | + (if relevant) subagents or permission prompts. |
| 29 | +2. Run Corbits Code normally. PerfTrace is always-on in-process; there is no |
| 30 | + settings toggle. |
| 31 | +3. When the session stalls or finishes slowly, dump the ring next to session |
| 32 | + artifacts. |
| 33 | + |
| 34 | +```ts |
| 35 | +import { snapshot } from "../src/perf/index.js"; |
| 36 | +import { dumpSpans } from "../src/perf/dump.js"; |
| 37 | + |
| 38 | +const path = await dumpSpans(snapshot(), { |
| 39 | + dir: ".agent-state/<sessionId>", |
| 40 | + sessionId: "<sessionId>", |
| 41 | +}); |
| 42 | +// → .agent-state/<sessionId>/perftrace-<sessionId>.json |
| 43 | +``` |
| 44 | + |
| 45 | +The dump is privacy-strict (allowlisted tags only). Safe to keep offline or |
| 46 | +share with teammates without prompts/paths. |
| 47 | + |
| 48 | +## Run the attribution report |
| 49 | + |
| 50 | +From a local dump file alone: |
| 51 | + |
| 52 | +```bash |
| 53 | +bun scripts/perf-report.ts .agent-state/<sessionId>/perftrace-<sessionId>.json |
| 54 | +``` |
| 55 | + |
| 56 | +Machine-readable JSON: |
| 57 | + |
| 58 | +```bash |
| 59 | +bun scripts/perf-report.ts --json .agent-state/<sessionId>/perftrace-<sessionId>.json |
| 60 | +``` |
| 61 | + |
| 62 | +Golden multi-tool demo (no dump file needed — uses |
| 63 | +`src/perf/fixtures/multi-tool-turn.ts`): |
| 64 | + |
| 65 | +```bash |
| 66 | +bun scripts/perf-report.ts --fixture |
| 67 | +``` |
| 68 | + |
| 69 | +Example fixture output (nanosecond fixture times print as `ns` / sub-ms): |
| 70 | + |
| 71 | +``` |
| 72 | +PerfTrace attribution report |
| 73 | +============================ |
| 74 | +Session wall (completed turns): 5000ns turns=1 completed=1 |
| 75 | +
|
| 76 | +Exclusive phase shares (of session wall) |
| 77 | + inference 40.0% 2000ns |
| 78 | + tools 24.0% 1200ns n=2 |
| 79 | + permission.wait 8.0% 400ns |
| 80 | + subagent 0.0% 0ms |
| 81 | + other 28.0% 1400ns |
| 82 | +... |
| 83 | +``` |
| 84 | + |
| 85 | +## How to read the report |
| 86 | + |
| 87 | +1. **Session exclusive shares** — which bucket ate the turn wall. A large |
| 88 | + `inference` share with high `ttft` points at model queueing / cold start. A |
| 89 | + large `tools` share with high `n=` points at tool work. A large |
| 90 | + `permission.wait` share is human/ask-gate idle, not model or tool code. |
| 91 | +2. **`other` large** — either real un-instrumented cost (TUI, scheduling) or |
| 92 | + gaps between instrumented phases. If `other` dominates a pain session, add |
| 93 | + spans before optimizing transport. |
| 94 | +3. **TTFT vs stream** — of `ttft + stream` only. High TTFT share → time-to-first-token |
| 95 | + problem. High stream share → long generation or slow token delivery. |
| 96 | +4. **Transport signal** — `adapter.transport / inference`. When transport is a |
| 97 | + large fraction of inference wall, prioritize transport work (WebSocket / |
| 98 | + incremental input). When it is small, transport is not the bottleneck. |
| 99 | +5. **Per-turn rows** — find the outlier turn when the session average looks fine |
| 100 | + but one turn felt stuck. |
| 101 | +6. **Subagent count + share** — fanout cost. High subagent share means child |
| 102 | + agents, not the parent inference path. |
| 103 | + |
| 104 | +### What “large transport share” looks like |
| 105 | + |
| 106 | +| transportShareOfInference | Reading | |
| 107 | +|---|---| |
| 108 | +| ≈ 0 or missing | Adapter did not emit `adapter.transport`, or transport was negligible. Do not prioritize WebSocket/incremental input on this evidence alone. | |
| 109 | +| Low (e.g. < 10–15%) | Most inference wall is model/server time, not client transport. Prefer model/TTFT or tool work. | |
| 110 | +| High (e.g. > 25–30% of inference, sustained across turns) | Client transport is a meaningful slice of inference wall — candidate for WebSocket / incremental input priority. | |
| 111 | + |
| 112 | +Always pair with absolute ms: a 40% share of a 50ms inference is noise; 40% of a |
| 113 | +8s inference is a product decision. |
| 114 | + |
| 115 | +## Decision note template (transport prioritization) |
| 116 | + |
| 117 | +Copy into a Linear issue or PR when a pain dump suggests transport investment. |
| 118 | + |
| 119 | +```markdown |
| 120 | +## Decision: WebSocket / incremental input priority? |
| 121 | + |
| 122 | +**Session / dump:** <path to perftrace-*.json> |
| 123 | +**Report command:** `bun scripts/perf-report.ts <path>` |
| 124 | + |
| 125 | +### Evidence |
| 126 | +- Session wall: <ms> |
| 127 | +- Exclusive shares: inference <%> · tools <%> · permission.wait <%> · subagent <%> · other <%> |
| 128 | +- TTFT share of (ttft+stream): <%> |
| 129 | +- Stream share of (ttft+stream): <%> |
| 130 | +- `adapter.transport` ns: <ms> · share of inference: <%> |
| 131 | +- Turns examined: <n>; outlier turn id: <id> |
| 132 | + |
| 133 | +### Reading |
| 134 | +- [ ] Transport share is **high** and absolute transport ms is user-visible |
| 135 | + → prioritize WebSocket / incremental input (or adapter transport work). |
| 136 | +- [ ] Transport share is **low / missing**; inference TTFT or tools dominate |
| 137 | + → do **not** prioritize transport; focus on <TTFT | tools | permission | other>. |
| 138 | +- [ ] `other` or missing instrumentation dominates |
| 139 | + → instrument first; decide after a second dump. |
| 140 | + |
| 141 | +### Decision |
| 142 | +- Priority: <raise | hold | drop> transport work this cycle |
| 143 | +- Owner: <name> |
| 144 | +- Follow-up: <issue link or none> |
| 145 | +``` |
| 146 | + |
| 147 | +## API (programmatic) |
| 148 | + |
| 149 | +```ts |
| 150 | +import { |
| 151 | + attributionFromSpans, |
| 152 | + attributionFromDump, |
| 153 | + formatAttributionReport, |
| 154 | +} from "../src/perf/attribution-report.js"; |
| 155 | +import { snapshot } from "../src/perf/index.js"; |
| 156 | + |
| 157 | +const report = attributionFromSpans(snapshot()); |
| 158 | +console.log(formatAttributionReport(report)); |
| 159 | +// or: attributionFromDump(JSON.parse(await readFile(path, "utf8"))) |
| 160 | +``` |
| 161 | + |
| 162 | +Pure functions — safe in tests and evals. The multi-tool golden fixture locks |
| 163 | +expected ns values in `src/perf/fixtures/multi-tool-turn.ts` and |
| 164 | +`src/perf/attribution-report.test.ts`. |
| 165 | + |
| 166 | +## Related |
| 167 | + |
| 168 | +- `src/perf/rollup.ts` — phase / turn / session totals |
| 169 | +- `src/perf/dump.ts` — `dumpSpans` / `buildDump` |
| 170 | +- `src/perf/attribution-report.ts` — exclusive shares + formatter |
| 171 | +- `scripts/perf-report.ts` — CLI entrypoint |
0 commit comments