From 44885f98cc3aec762c7ef5d7c1e845186c06c99b Mon Sep 17 00:00:00 2001 From: Sawyer Cutler Date: Tue, 4 Aug 2026 05:03:28 -0700 Subject: [PATCH 1/3] Add offline PerfTrace attribution report for slow sessions Pure attribution over dump JSON or live spans: exclusive shares for inference, tools, permission.wait, subagent, and other, plus TTFT/stream and adapter.transport diagnostics. CLI, methodology guide, and golden multi-tool fixture coverage. --- docs/PERFTRACE.md | 3 + docs/perftrace-attribution-guide.md | 171 ++++++++++ scripts/perf-report.ts | 94 ++++++ src/perf/attribution-report.test.ts | 191 +++++++++++ src/perf/attribution-report.ts | 485 ++++++++++++++++++++++++++++ 5 files changed, 944 insertions(+) create mode 100644 docs/perftrace-attribution-guide.md create mode 100644 scripts/perf-report.ts create mode 100644 src/perf/attribution-report.test.ts create mode 100644 src/perf/attribution-report.ts diff --git a/docs/PERFTRACE.md b/docs/PERFTRACE.md index bb10d18e3..40af03637 100644 --- a/docs/PERFTRACE.md +++ b/docs/PERFTRACE.md @@ -13,9 +13,12 @@ PostHog usage events. - Offline dumps: `dumpSpans` + `rollupByPhase` / `rollupByTurn` / `sessionTotals` (`src/perf/dump.ts`, `src/perf/rollup.ts`) — same tag allowlist; never include OTEL auth headers +- Attribution report: `bun scripts/perf-report.ts ` — see + [`perftrace-attribution-guide.md`](./perftrace-attribution-guide.md) Local measurement does not require any settings or env vars. + ## OTEL export (opt-in) Export is **off** until an OTLP endpoint is configured. When enabled, traces go diff --git a/docs/perftrace-attribution-guide.md b/docs/perftrace-attribution-guide.md new file mode 100644 index 000000000..3fcb93e1d --- /dev/null +++ b/docs/perftrace-attribution-guide.md @@ -0,0 +1,171 @@ +# PerfTrace attribution guide + +How to capture a slow session, dump local spans, and run the offline attribution +report. No OTEL collector, no PostHog, no network. + +See also: [`PERFTRACE.md`](./PERFTRACE.md) for the span model, dump schema, and +`jq` recipes. + +## Why this exists + +When a session feels slow, the first question is **where the wall time went**: + +| Category | Meaning | +|---|---| +| `inference` | Model call wall (`inference` spans). Nested `inference.ttft` vs `inference.stream` show wait-for-first-token vs rest of stream. | +| `tools` | Tool invocations under the turn. | +| `permission.wait` | Ask-gate / approval idle time (when instrumented). | +| `subagent` | Child agent lifetimes (fanout cost). | +| `other` | Turn wall not covered by the above — scheduling, TUI, un-instrumented work, gaps between phases. | + +Shares are **exclusive** over completed turn wall. Nested TTFT/stream and +`adapter.transport` are diagnostic splits (they are not added on top of +`inference` in the exclusive table). + +## Capture a real slow session + +1. Prefer a repro that exercises the pain: high reasoning, several tools, and + (if relevant) subagents or permission prompts. +2. Run Corbits Code normally. PerfTrace is always-on in-process; there is no + settings toggle. +3. When the session stalls or finishes slowly, dump the ring next to session + artifacts. + +```ts +import { snapshot } from "../src/perf/index.js"; +import { dumpSpans } from "../src/perf/dump.js"; + +const path = await dumpSpans(snapshot(), { + dir: ".agent-state/", + sessionId: "", +}); +// → .agent-state//perftrace-.json +``` + +The dump is privacy-strict (allowlisted tags only). Safe to keep offline or +share with teammates without prompts/paths. + +## Run the attribution report + +From a local dump file alone: + +```bash +bun scripts/perf-report.ts .agent-state//perftrace-.json +``` + +Machine-readable JSON: + +```bash +bun scripts/perf-report.ts --json .agent-state//perftrace-.json +``` + +Golden multi-tool demo (no dump file needed — uses +`src/perf/fixtures/multi-tool-turn.ts`): + +```bash +bun scripts/perf-report.ts --fixture +``` + +Example fixture output (nanosecond fixture times print as `ns` / sub-ms): + +``` +PerfTrace attribution report +============================ +Session wall (completed turns): 5000ns turns=1 completed=1 + +Exclusive phase shares (of session wall) + inference 40.0% 2000ns + tools 24.0% 1200ns n=2 + permission.wait 8.0% 400ns + subagent 0.0% 0ms + other 28.0% 1400ns +... +``` + +## How to read the report + +1. **Session exclusive shares** — which bucket ate the turn wall. A large + `inference` share with high `ttft` points at model queueing / cold start. A + large `tools` share with high `n=` points at tool work. A large + `permission.wait` share is human/ask-gate idle, not model or tool code. +2. **`other` large** — either real un-instrumented cost (TUI, scheduling) or + gaps between instrumented phases. If `other` dominates a pain session, add + spans before optimizing transport. +3. **TTFT vs stream** — of `ttft + stream` only. High TTFT share → time-to-first-token + problem. High stream share → long generation or slow token delivery. +4. **Transport signal** — `adapter.transport / inference`. When transport is a + large fraction of inference wall, prioritize transport work (WebSocket / + incremental input). When it is small, transport is not the bottleneck. +5. **Per-turn rows** — find the outlier turn when the session average looks fine + but one turn felt stuck. +6. **Subagent count + share** — fanout cost. High subagent share means child + agents, not the parent inference path. + +### What “large transport share” looks like + +| transportShareOfInference | Reading | +|---|---| +| ≈ 0 or missing | Adapter did not emit `adapter.transport`, or transport was negligible. Do not prioritize WebSocket/incremental input on this evidence alone. | +| Low (e.g. < 10–15%) | Most inference wall is model/server time, not client transport. Prefer model/TTFT or tool work. | +| 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. | + +Always pair with absolute ms: a 40% share of a 50ms inference is noise; 40% of a +8s inference is a product decision. + +## Decision note template (transport prioritization) + +Copy into a Linear issue or PR when a pain dump suggests transport investment. + +```markdown +## Decision: WebSocket / incremental input priority? + +**Session / dump:** +**Report command:** `bun scripts/perf-report.ts ` + +### Evidence +- Session wall: +- Exclusive shares: inference <%> · tools <%> · permission.wait <%> · subagent <%> · other <%> +- TTFT share of (ttft+stream): <%> +- Stream share of (ttft+stream): <%> +- `adapter.transport` ns: · share of inference: <%> +- Turns examined: ; outlier turn id: + +### Reading +- [ ] Transport share is **high** and absolute transport ms is user-visible + → prioritize WebSocket / incremental input (or adapter transport work). +- [ ] Transport share is **low / missing**; inference TTFT or tools dominate + → do **not** prioritize transport; focus on . +- [ ] `other` or missing instrumentation dominates + → instrument first; decide after a second dump. + +### Decision +- Priority: transport work this cycle +- Owner: +- Follow-up: +``` + +## API (programmatic) + +```ts +import { + attributionFromSpans, + attributionFromDump, + formatAttributionReport, +} from "../src/perf/attribution-report.js"; +import { snapshot } from "../src/perf/index.js"; + +const report = attributionFromSpans(snapshot()); +console.log(formatAttributionReport(report)); +// or: attributionFromDump(JSON.parse(await readFile(path, "utf8"))) +``` + +Pure functions — safe in tests and evals. The multi-tool golden fixture locks +expected ns values in `src/perf/fixtures/multi-tool-turn.ts` and +`src/perf/attribution-report.test.ts`. + +## Related + +- `src/perf/rollup.ts` — phase / turn / session totals +- `src/perf/dump.ts` — `dumpSpans` / `buildDump` +- `src/perf/attribution-report.ts` — exclusive shares + formatter +- `scripts/perf-report.ts` — CLI entrypoint diff --git a/scripts/perf-report.ts b/scripts/perf-report.ts new file mode 100644 index 000000000..a9b670d6f --- /dev/null +++ b/scripts/perf-report.ts @@ -0,0 +1,94 @@ +#!/usr/bin/env bun +/** + * Offline PerfTrace attribution report. + * + * Reads a dump JSON written by dumpSpans() (or a bare spans array) and prints + * exclusive phase shares: inference / tools / permission.wait / subagent / other. + * No network, no OTEL, no PostHog. + * + * Usage: + * bun scripts/perf-report.ts + * bun scripts/perf-report.ts --json + * bun scripts/perf-report.ts --fixture # golden multi-tool demo + */ + +import { readFile } from "node:fs/promises"; +import { resolve } from "node:path"; +import { + attributionFromDump, + attributionFromSpans, + formatAttributionReport, + type AttributionReport, +} from "../src/perf/attribution-report.js"; +import { multiToolTurnFixture } from "../src/perf/fixtures/multi-tool-turn.js"; + +function printUsage(): void { + console.error(`Usage: + bun scripts/perf-report.ts + bun scripts/perf-report.ts --json # machine-readable AttributionReport + bun scripts/perf-report.ts --fixture # demo on multi-tool golden fixture +`); +} + +function emit(report: AttributionReport, asJson: boolean): void { + if (asJson) { + console.log(JSON.stringify(report, null, 2)); + } else { + process.stdout.write(formatAttributionReport(report)); + } +} + +async function main(argv: string[]): Promise { + const args = argv.slice(2); + if (args.length === 0 || args.includes("-h") || args.includes("--help")) { + printUsage(); + return args.length === 0 ? 1 : 0; + } + + const asJson = args.includes("--json"); + const useFixture = args.includes("--fixture"); + const pathArg = args.find((a) => !a.startsWith("-")); + + if (useFixture) { + const report = attributionFromSpans(multiToolTurnFixture()); + emit(report, asJson); + return 0; + } + + if (pathArg === undefined) { + printUsage(); + return 1; + } + + const filePath = resolve(pathArg); + let rawText: string; + try { + rawText = await readFile(filePath, "utf8"); + } catch (err) { + const msg = err instanceof Error ? err.message : String(err); + console.error(`perf-report: failed to read ${filePath}: ${msg}`); + return 1; + } + + let parsed: unknown; + try { + parsed = JSON.parse(rawText); + } catch (err) { + const msg = err instanceof Error ? err.message : String(err); + console.error(`perf-report: invalid JSON in ${filePath}: ${msg}`); + return 1; + } + + try { + const report = attributionFromDump(parsed); + emit(report, asJson); + return 0; + } catch (err) { + const msg = err instanceof Error ? err.message : String(err); + console.error(`perf-report: ${msg}`); + return 1; + } +} + +const code = await main(process.argv); +process.exit(code); diff --git a/src/perf/attribution-report.test.ts b/src/perf/attribution-report.test.ts new file mode 100644 index 000000000..97ccbf1fa --- /dev/null +++ b/src/perf/attribution-report.test.ts @@ -0,0 +1,191 @@ +import { describe, expect, test } from "bun:test"; +import { + attributionFromDump, + attributionFromSpans, + categoryShare, + deserializeDumpSpan, + formatAttributionReport, + spansFromDumpJson, +} from "./attribution-report.js"; +import { buildDump, serializeSpan } from "./dump.js"; +import { + MULTI_TOOL_TURN_GOLDEN, + multiToolTurnFixture, +} from "./fixtures/multi-tool-turn.js"; +import type { PerfSpan } from "./index.js"; + +function span(partial: { + id: string; + name: PerfSpan["name"]; + parentId?: string; + startNs: bigint; + endNs?: bigint; + tags?: PerfSpan["tags"]; +}): PerfSpan { + const s: PerfSpan = { + id: partial.id, + name: partial.name, + startNs: partial.startNs, + }; + if (partial.parentId !== undefined) s.parentId = partial.parentId; + if (partial.endNs !== undefined) s.endNs = partial.endNs; + if (partial.tags !== undefined) s.tags = partial.tags; + return s; +} + +describe("attributionFromSpans — multi-tool golden fixture", () => { + test("exclusive shares match locked fixture durations", () => { + const report = attributionFromSpans(multiToolTurnFixture()); + const g = MULTI_TOOL_TURN_GOLDEN; + + expect(report.session.turnCount).toBe(1); + expect(report.session.completedTurnCount).toBe(1); + expect(report.session.wallNs).toBe(g.turnNs); + expect(report.session.toolCount).toBe(g.toolCount); + + const inf = categoryShare(report.session.categories, "inference"); + const tools = categoryShare(report.session.categories, "tools"); + const perm = categoryShare(report.session.categories, "permission.wait"); + const sub = categoryShare(report.session.categories, "subagent"); + const other = categoryShare(report.session.categories, "other"); + + // turn 5000; inference 2000; tools 1200; permission 400 → other 1400 + expect(inf.ns).toBe(g.inferenceNs); + expect(tools.ns).toBe(g.toolNs); + expect(perm.ns).toBe(400); + expect(sub.ns).toBe(0); + expect(other.ns).toBe(1400); + + expect(inf.share).toBeCloseTo(2000 / 5000, 10); + expect(tools.share).toBeCloseTo(1200 / 5000, 10); + expect(perm.share).toBeCloseTo(400 / 5000, 10); + expect(other.share).toBeCloseTo(1400 / 5000, 10); + + const shareSum = report.session.categories.reduce((a, c) => a + c.share, 0); + expect(shareSum).toBeCloseTo(1, 10); + }); + + test("ttft vs stream split matches golden", () => { + const report = attributionFromSpans(multiToolTurnFixture()); + const g = MULTI_TOOL_TURN_GOLDEN; + expect(report.session.inference.ttftNs).toBe(g.ttftNs); + expect(report.session.inference.streamNs).toBe(g.streamNs); + expect(report.session.inference.ttftShare).toBeCloseTo(400 / 2000, 10); + expect(report.session.inference.streamShare).toBeCloseTo(1600 / 2000, 10); + }); + + test("per-turn row mirrors session for single-turn fixture", () => { + const report = attributionFromSpans(multiToolTurnFixture()); + expect(report.turns).toHaveLength(1); + const t = report.turns[0]!; + expect(t.turnId).toBe("t1"); + expect(t.turnNs).toBe(5000); + expect(t.open).toBe(false); + expect(categoryShare(t.categories, "inference").ns).toBe(2000); + expect(categoryShare(t.categories, "tools").ns).toBe(1200); + expect(categoryShare(t.categories, "permission.wait").ns).toBe(400); + expect(categoryShare(t.categories, "other").ns).toBe(1400); + expect(t.toolCount).toBe(2); + expect(t.subagentCount).toBe(0); + }); +}); + +describe("attributionFromSpans — subagent + transport", () => { + test("attributes subagent fanout and transport share of inference", () => { + const spans: PerfSpan[] = [ + span({ id: "t1", name: "turn", startNs: 0n, endNs: 10_000n }), + span({ + id: "i1", + name: "inference", + parentId: "t1", + startNs: 0n, + endNs: 4000n, + }), + span({ + id: "ttft1", + name: "inference.ttft", + parentId: "i1", + startNs: 0n, + endNs: 1000n, + }), + span({ + id: "stream1", + name: "inference.stream", + parentId: "i1", + startNs: 1000n, + endNs: 4000n, + }), + span({ + id: "tr1", + name: "adapter.transport", + parentId: "i1", + startNs: 0n, + endNs: 800n, + tags: { transport: "http_sse" }, + }), + span({ + id: "sa1", + name: "subagent", + parentId: "t1", + startNs: 4000n, + endNs: 7000n, + }), + span({ + id: "k1", + name: "tool", + parentId: "t1", + startNs: 7000n, + endNs: 8000n, + }), + ]; + + const report = attributionFromSpans(spans); + expect(categoryShare(report.session.categories, "inference").ns).toBe(4000); + expect(categoryShare(report.session.categories, "subagent").ns).toBe(3000); + expect(categoryShare(report.session.categories, "tools").ns).toBe(1000); + // other = 10000 - 4000 - 1000 - 0 - 3000 = 2000 + expect(categoryShare(report.session.categories, "other").ns).toBe(2000); + expect(report.session.subagentCount).toBe(1); + expect(report.session.transportNs).toBe(800); + expect(report.session.transportShareOfInference).toBeCloseTo(800 / 4000, 10); + }); +}); + +describe("dump round-trip", () => { + test("attributionFromDump matches live spans", () => { + const spans = multiToolTurnFixture(); + const dump = buildDump(spans, "fixture-multi", "2026-04-08T00:00:00.000Z"); + const fromDump = attributionFromDump(dump); + const live = attributionFromSpans(spans); + + expect(fromDump.session.wallNs).toBe(live.session.wallNs); + expect(fromDump.session.categories).toEqual(live.session.categories); + expect(fromDump.session.inference).toEqual(live.session.inference); + expect(fromDump.turns).toEqual(live.turns); + }); + + test("spansFromDumpJson accepts bare span arrays", () => { + const serialized = multiToolTurnFixture().map(serializeSpan); + const spans = spansFromDumpJson(serialized); + expect(spans).toHaveLength(7); + expect(spans[0]!.startNs).toBe(0n); + expect(deserializeDumpSpan(serialized[0]!).id).toBe("t1"); + }); +}); + +describe("formatAttributionReport", () => { + test("prints category labels and percentages for the golden fixture", () => { + const text = formatAttributionReport( + attributionFromSpans(multiToolTurnFixture()), + ); + expect(text).toContain("PerfTrace attribution report"); + expect(text).toContain("inference"); + expect(text).toContain("tools"); + expect(text).toContain("permission.wait"); + expect(text).toContain("subagent"); + expect(text).toContain("other"); + expect(text).toContain("40.0%"); // inference 2000/5000 + expect(text).toContain("24.0%"); // tools 1200/5000 + expect(text).toContain("turn t1"); + }); +}); diff --git a/src/perf/attribution-report.ts b/src/perf/attribution-report.ts new file mode 100644 index 000000000..b5d4c36f8 --- /dev/null +++ b/src/perf/attribution-report.ts @@ -0,0 +1,485 @@ +/** + * Offline attribution report over PerfSpan snapshots or PerfDump JSON. + * + * Pure functions: no I/O, no module state, no OTEL. Categories partition turn + * wall time into exclusive buckets so shares sum to ~1 (remainder → other). + */ + +import type { PerfSpan, SpanName } from "./index.js"; +import type { DumpSpan, PerfDump } from "./dump.js"; +import { DUMP_VERSION } from "./dump.js"; +import { spanDurationNs } from "./rollup.js"; + +/** Exclusive wall-time buckets used for session / turn share %. */ +export const ATTRIBUTION_CATEGORIES = [ + "inference", + "tools", + "permission.wait", + "subagent", + "other", +] as const; + +export type AttributionCategory = (typeof ATTRIBUTION_CATEGORIES)[number]; + +/** One exclusive category and its share of a denominator wall. */ +export type CategoryShare = { + category: AttributionCategory; + /** Total nanoseconds attributed to this category. */ + ns: number; + /** Share of denominator wall in [0, 1]. 0 when denominator is 0. */ + share: number; + /** Span count contributing to this category (0 for synthetic "other"). */ + count: number; +}; + +/** TTFT vs stream split inside inference wall (not exclusive of each other vs parent). */ +export type InferenceSplit = { + ttftNs: number; + streamNs: number; + /** Share of (ttft + stream). 0 when both are zero. */ + ttftShare: number; + streamShare: number; +}; + +/** Per-turn exclusive attribution. */ +export type TurnAttribution = { + turnId: string; + turnNs: number; + open: boolean; + categories: CategoryShare[]; + inference: InferenceSplit; + toolCount: number; + subagentCount: number; + /** + * Sum of `adapter.transport` under this turn (when instrumented). + * Compared to inference wall for the transport prioritization decision. + */ + transportNs: number; + /** transportNs / inferenceNs, or 0 when inference is 0. */ + transportShareOfInference: number; +}; + +/** Session-level attribution report. */ +export type AttributionReport = { + session: { + /** Denominator for shares: sum of completed turn walls (open turns excluded). */ + wallNs: number; + categories: CategoryShare[]; + inference: InferenceSplit; + toolCount: number; + subagentCount: number; + turnCount: number; + completedTurnCount: number; + transportNs: number; + transportShareOfInference: number; + }; + turns: TurnAttribution[]; +}; + +type ExclusiveBucket = { + inferenceNs: number; + toolNs: number; + permissionWaitNs: number; + subagentNs: number; + toolCount: number; + subagentCount: number; + ttftNs: number; + streamNs: number; + transportNs: number; +}; + +function emptyBucket(): ExclusiveBucket { + return { + inferenceNs: 0, + toolNs: 0, + permissionWaitNs: 0, + subagentNs: 0, + toolCount: 0, + subagentCount: 0, + ttftNs: 0, + streamNs: 0, + transportNs: 0, + }; +} + +function childrenOf(spans: readonly PerfSpan[]): Map { + const byParent = new Map(); + for (const span of spans) { + if (span.parentId === undefined) continue; + const list = byParent.get(span.parentId); + if (list === undefined) { + byParent.set(span.parentId, [span]); + } else { + list.push(span); + } + } + return byParent; +} + +function walkDescendants( + rootId: string, + byParent: Map, + visit: (span: PerfSpan) => void, +): void { + const stack = byParent.get(rootId); + if (stack === undefined) return; + const work: PerfSpan[] = stack.slice(); + while (work.length > 0) { + const span = work.pop()!; + visit(span); + const kids = byParent.get(span.id); + if (kids !== undefined) { + for (const k of kids) work.push(k); + } + } +} + +/** Accumulate exclusive + nested metrics from a descendant span. */ +function accumulate(bucket: ExclusiveBucket, span: PerfSpan): void { + const dur = spanDurationNs(span) ?? 0; + switch (span.name as SpanName) { + case "inference": + bucket.inferenceNs += dur; + break; + case "tool": + bucket.toolNs += dur; + bucket.toolCount += 1; + break; + case "permission.wait": + bucket.permissionWaitNs += dur; + break; + case "subagent": + bucket.subagentNs += dur; + bucket.subagentCount += 1; + break; + case "inference.ttft": + bucket.ttftNs += dur; + break; + case "inference.stream": + bucket.streamNs += dur; + break; + case "adapter.transport": + bucket.transportNs += dur; + break; + default: + break; + } +} + +function inferenceSplit(ttftNs: number, streamNs: number): InferenceSplit { + const split = ttftNs + streamNs; + return { + ttftNs, + streamNs, + ttftShare: split === 0 ? 0 : ttftNs / split, + streamShare: split === 0 ? 0 : streamNs / split, + }; +} + +function shareOf(ns: number, wallNs: number): number { + return wallNs === 0 ? 0 : ns / wallNs; +} + +/** + * Build exclusive category shares. `other` absorbs gaps and un-instrumented wall + * (scheduling, TUI, etc.) so shares sum to 1 when wallNs > 0. + */ +function categorySharesFromBucket( + bucket: ExclusiveBucket, + wallNs: number, + inferenceCount: number, + permissionWaitCount: number, +): CategoryShare[] { + const attributed = + bucket.inferenceNs + + bucket.toolNs + + bucket.permissionWaitNs + + bucket.subagentNs; + const otherNs = wallNs > 0 ? Math.max(0, wallNs - attributed) : 0; + + return [ + { + category: "inference", + ns: bucket.inferenceNs, + share: shareOf(bucket.inferenceNs, wallNs), + count: inferenceCount, + }, + { + category: "tools", + ns: bucket.toolNs, + share: shareOf(bucket.toolNs, wallNs), + count: bucket.toolCount, + }, + { + category: "permission.wait", + ns: bucket.permissionWaitNs, + share: shareOf(bucket.permissionWaitNs, wallNs), + count: permissionWaitCount, + }, + { + category: "subagent", + ns: bucket.subagentNs, + share: shareOf(bucket.subagentNs, wallNs), + count: bucket.subagentCount, + }, + { + category: "other", + ns: otherNs, + share: shareOf(otherNs, wallNs), + count: 0, + }, + ]; +} + +function countNameUnder( + rootId: string, + byParent: Map, + name: SpanName, +): number { + let n = 0; + walkDescendants(rootId, byParent, (s) => { + if (s.name === name) n += 1; + }); + return n; +} + +/** + * Attribute a PerfSpan snapshot into exclusive phase shares per turn and session. + * + * Exclusive categories (do not nest-double-count): + * inference | tools | permission.wait | subagent | other + * + * Nested diagnostics (not exclusive): + * inference.ttft / inference.stream shares of inference wall + * adapter.transport share of inference (transport prioritization signal) + */ +export function attributionFromSpans(spans: readonly PerfSpan[]): AttributionReport { + const byParent = childrenOf(spans); + const turnSpans = spans + .filter((s) => s.name === "turn") + .slice() + .sort((a, b) => (a.startNs < b.startNs ? -1 : a.startNs > b.startNs ? 1 : 0)); + + const turns: TurnAttribution[] = turnSpans.map((turn) => { + const bucket = emptyBucket(); + walkDescendants(turn.id, byParent, (child) => accumulate(bucket, child)); + + const turnDur = spanDurationNs(turn); + const turnNs = turnDur ?? 0; + const open = turnDur === undefined; + const inferenceCount = countNameUnder(turn.id, byParent, "inference"); + const permissionWaitCount = countNameUnder(turn.id, byParent, "permission.wait"); + + return { + turnId: turn.id, + turnNs, + open, + categories: categorySharesFromBucket( + bucket, + turnNs, + inferenceCount, + permissionWaitCount, + ), + inference: inferenceSplit(bucket.ttftNs, bucket.streamNs), + toolCount: bucket.toolCount, + subagentCount: bucket.subagentCount, + transportNs: bucket.transportNs, + transportShareOfInference: + bucket.inferenceNs === 0 ? 0 : bucket.transportNs / bucket.inferenceNs, + }; + }); + + // Session: sum completed turns only for wall denominator so open turns do not + // inflate "other". Category ns still include open-turn children (partial data). + const sessionBucket = emptyBucket(); + let wallNs = 0; + let completedTurnCount = 0; + let inferenceCount = 0; + let permissionWaitCount = 0; + + for (const turn of turnSpans) { + const turnDur = spanDurationNs(turn); + if (turnDur !== undefined) { + wallNs += turnDur; + completedTurnCount += 1; + } + walkDescendants(turn.id, byParent, (child) => { + accumulate(sessionBucket, child); + if (child.name === "inference") inferenceCount += 1; + if (child.name === "permission.wait") permissionWaitCount += 1; + }); + } + + // No turn roots (partial / orphan snapshot): fall back to flat exclusive sums + // and use attributed total as the wall denominator. + if (turnSpans.length === 0) { + for (const span of spans) { + accumulate(sessionBucket, span); + if (span.name === "inference") inferenceCount += 1; + if (span.name === "permission.wait") permissionWaitCount += 1; + } + wallNs = + sessionBucket.inferenceNs + + sessionBucket.toolNs + + sessionBucket.permissionWaitNs + + sessionBucket.subagentNs; + } + + return { + session: { + wallNs, + categories: categorySharesFromBucket( + sessionBucket, + wallNs, + inferenceCount, + permissionWaitCount, + ), + inference: inferenceSplit(sessionBucket.ttftNs, sessionBucket.streamNs), + toolCount: sessionBucket.toolCount, + subagentCount: sessionBucket.subagentCount, + turnCount: turnSpans.length, + completedTurnCount, + transportNs: sessionBucket.transportNs, + transportShareOfInference: + sessionBucket.inferenceNs === 0 + ? 0 + : sessionBucket.transportNs / sessionBucket.inferenceNs, + }, + turns, + }; +} + +/** Convert a dump span (string ns) back to an in-memory PerfSpan. */ +export function deserializeDumpSpan(span: DumpSpan): PerfSpan { + const out: PerfSpan = { + id: span.id, + name: span.name, + startNs: BigInt(span.startNs), + }; + if (span.parentId !== undefined) out.parentId = span.parentId; + if (span.endNs !== undefined) out.endNs = BigInt(span.endNs); + if (span.tags !== undefined) out.tags = span.tags; + return out; +} + +/** + * Parse a JSON value as PerfDump and return live spans. + * Accepts either a full dump document or a bare `{ spans: DumpSpan[] }` / array. + */ +export function spansFromDumpJson(raw: unknown): PerfSpan[] { + if (Array.isArray(raw)) { + return raw.map((s) => deserializeDumpSpan(s as DumpSpan)); + } + if (raw !== null && typeof raw === "object") { + const obj = raw as Record; + if (Array.isArray(obj.spans)) { + return (obj.spans as DumpSpan[]).map(deserializeDumpSpan); + } + } + throw new Error( + "attribution report: expected a PerfDump object with .spans, or a DumpSpan[] array", + ); +} + +/** Attribute a parsed PerfDump (or dump-like JSON) offline. */ +export function attributionFromDump(raw: unknown): AttributionReport { + if (raw !== null && typeof raw === "object") { + const obj = raw as Partial; + if (obj.version !== undefined && obj.version !== DUMP_VERSION) { + // Still attempt — schema may be forward-compatible on spans[]. + } + } + return attributionFromSpans(spansFromDumpJson(raw)); +} + +function pct(share: number): string { + return `${(share * 100).toFixed(1)}%`; +} + +function ms(ns: number): string { + if (ns === 0) return "0ms"; + const m = ns / 1e6; + if (m < 0.001) return `${ns}ns`; + if (m < 1) return `${m.toFixed(3)}ms`; + if (m < 1000) return `${m.toFixed(1)}ms`; + return `${(m / 1000).toFixed(2)}s`; +} + +function categoryLine(c: CategoryShare): string { + const count = + c.count > 0 && c.category !== "other" ? ` n=${c.count}` : ""; + return ` ${c.category.padEnd(18)} ${pct(c.share).padStart(7)} ${ms(c.ns).padStart(10)}${count}`; +} + +/** + * Human-readable multi-line report. Safe for terminals; no color codes. + */ +export function formatAttributionReport(report: AttributionReport): string { + const lines: string[] = []; + const s = report.session; + + lines.push("PerfTrace attribution report"); + lines.push("============================"); + lines.push( + `Session wall (completed turns): ${ms(s.wallNs)} turns=${s.turnCount} completed=${s.completedTurnCount}`, + ); + lines.push(""); + lines.push("Exclusive phase shares (of session wall)"); + for (const c of s.categories) { + lines.push(categoryLine(c)); + } + lines.push(""); + lines.push("Inference split (ttft vs stream of ttft+stream)"); + lines.push( + ` ttft ${pct(s.inference.ttftShare).padStart(7)} ${ms(s.inference.ttftNs).padStart(10)}`, + ); + lines.push( + ` stream ${pct(s.inference.streamShare).padStart(7)} ${ms(s.inference.streamNs).padStart(10)}`, + ); + lines.push(""); + lines.push("Transport signal (adapter.transport / inference)"); + lines.push( + ` transportNs ${ms(s.transportNs).padStart(10)} share_of_inference=${pct(s.transportShareOfInference)}`, + ); + lines.push( + ` tools=${s.toolCount} subagents=${s.subagentCount}`, + ); + + if (report.turns.length > 0) { + lines.push(""); + lines.push("Per-turn summary"); + for (const t of report.turns) { + const open = t.open ? " OPEN" : ""; + const byCat = Object.fromEntries( + t.categories.map((c) => [c.category, c]), + ) as Record; + lines.push( + ` turn ${t.turnId}${open} wall=${ms(t.turnNs)} ` + + `inf=${pct(byCat.inference.share)} tools=${pct(byCat.tools.share)} ` + + `perm=${pct(byCat["permission.wait"].share)} sub=${pct(byCat.subagent.share)} ` + + `other=${pct(byCat.other.share)} ` + + `ttft/stream=${pct(t.inference.ttftShare)}/${pct(t.inference.streamShare)} ` + + `tools_n=${t.toolCount} sub_n=${t.subagentCount}`, + ); + } + } + + lines.push(""); + return lines.join("\n"); +} + +/** + * Lookup a category share from a report's session or turn categories list. + * Convenience for tests and scripts. + */ +export function categoryShare( + categories: readonly CategoryShare[], + name: AttributionCategory, +): CategoryShare { + const found = categories.find((c) => c.category === name); + if (found === undefined) { + throw new Error(`missing attribution category "${name}"`); + } + return found; +} + From 914819dca8ad8034d4298f442dddcabf0c08d433 Mon Sep 17 00:00:00 2001 From: Sawyer Cutler Date: Tue, 4 Aug 2026 06:34:35 -0700 Subject: [PATCH 2/3] Fix open-turn attribution wall for mid-stall dumps --- docs/perftrace-attribution-guide.md | 30 +++--- src/perf/attribution-report.test.ts | 137 ++++++++++++++++++++++++++++ src/perf/attribution-report.ts | 123 ++++++++++++++----------- 3 files changed, 223 insertions(+), 67 deletions(-) diff --git a/docs/perftrace-attribution-guide.md b/docs/perftrace-attribution-guide.md index 3fcb93e1d..53481d017 100644 --- a/docs/perftrace-attribution-guide.md +++ b/docs/perftrace-attribution-guide.md @@ -18,9 +18,12 @@ When a session feels slow, the first question is **where the wall time went**: | `subagent` | Child agent lifetimes (fanout cost). | | `other` | Turn wall not covered by the above — scheduling, TUI, un-instrumented work, gaps between phases. | -Shares are **exclusive** over completed turn wall. Nested TTFT/stream and -`adapter.transport` are diagnostic splits (they are not added on top of -`inference` in the exclusive table). +Shares are **exclusive** over turn wall. For **completed** turns, wall is +`end − start`. For **open** (still-running) turns — including mid-stall dumps — +wall is estimated as `max(completed-descendant endNs) − turn.startNs` so shares +stay meaningful. Nested TTFT/stream and `adapter.transport` are diagnostic +splits (they are not added on top of `inference` in the exclusive table). + ## Capture a real slow session @@ -66,22 +69,23 @@ Golden multi-tool demo (no dump file needed — uses bun scripts/perf-report.ts --fixture ``` -Example fixture output (nanosecond fixture times print as `ns` / sub-ms): +Example fixture output (fixture ns values are tiny — formatter prints sub-ms): ``` PerfTrace attribution report -============================ -Session wall (completed turns): 5000ns turns=1 completed=1 - -Exclusive phase shares (of session wall) - inference 40.0% 2000ns - tools 24.0% 1200ns n=2 - permission.wait 8.0% 400ns - subagent 0.0% 0ms - other 28.0% 1400ns +─────────────────────────── +Session wall: 0.005ms turns=1 (completed=1) + +Exclusive phase shares (of session wall): + inference 40.0% 0.002ms n=1 + tools 24.0% 0.001ms n=2 + permission.wait 8.0% 0.000ms + subagent 0.0% 0ms + other 28.0% 0.001ms ... ``` + ## How to read the report 1. **Session exclusive shares** — which bucket ate the turn wall. A large diff --git a/src/perf/attribution-report.test.ts b/src/perf/attribution-report.test.ts index 97ccbf1fa..e82fe232a 100644 --- a/src/perf/attribution-report.test.ts +++ b/src/perf/attribution-report.test.ts @@ -151,6 +151,143 @@ describe("attributionFromSpans — subagent + transport", () => { }); }); +describe("attributionFromSpans — open (stall) turns", () => { + test("open turn wall is max completed-descendant end minus turn start", () => { + // Mid-stall dump: turn still open; inference + tool completed; stream still open. + const spans: PerfSpan[] = [ + span({ id: "t1", name: "turn", startNs: 100n }), // open + span({ + id: "i1", + name: "inference", + parentId: "t1", + startNs: 100n, + endNs: 2100n, // 2000ns + }), + span({ + id: "ttft1", + name: "inference.ttft", + parentId: "i1", + startNs: 100n, + endNs: 500n, + }), + span({ + id: "stream1", + name: "inference.stream", + parentId: "i1", + startNs: 500n, // still open — contributes 0 to streamNs + }), + span({ + id: "k1", + name: "tool", + parentId: "t1", + startNs: 2100n, + endNs: 3100n, // 1000ns; max end → wall = 3100 - 100 = 3000 + }), + ]; + + const report = attributionFromSpans(spans); + expect(report.session.completedTurnCount).toBe(0); + expect(report.session.turnCount).toBe(1); + // wall = maxEnd(3100) - start(100) = 3000 + expect(report.session.wallNs).toBe(3000); + expect(report.turns[0]!.open).toBe(true); + expect(report.turns[0]!.turnNs).toBe(3000); + + expect(categoryShare(report.session.categories, "inference").ns).toBe(2000); + expect(categoryShare(report.session.categories, "tools").ns).toBe(1000); + // other = 3000 - 2000 - 1000 = 0 + expect(categoryShare(report.session.categories, "other").ns).toBe(0); + + const shareSum = report.session.categories.reduce((a, c) => a + c.share, 0); + expect(shareSum).toBeCloseTo(1, 10); + + const turnShareSum = report.turns[0]!.categories.reduce((a, c) => a + c.share, 0); + expect(turnShareSum).toBeCloseTo(1, 10); + }); + + test("mixed completed + open turns: session shares sum to ~1", () => { + const spans: PerfSpan[] = [ + // completed turn: wall 5000 + span({ id: "t0", name: "turn", startNs: 0n, endNs: 5000n }), + span({ + id: "i0", + name: "inference", + parentId: "t0", + startNs: 0n, + endNs: 3000n, + }), + span({ + id: "k0", + name: "tool", + parentId: "t0", + startNs: 3000n, + endNs: 4000n, + }), + // open stall turn: estimated wall 2000 (max end 7000 - start 5000) + span({ id: "t1", name: "turn", startNs: 5000n }), + span({ + id: "i1", + name: "inference", + parentId: "t1", + startNs: 5000n, + endNs: 6500n, // 1500 + }), + span({ + id: "k1", + name: "tool", + parentId: "t1", + startNs: 6500n, + endNs: 7000n, // 500; max end → wall 2000 + }), + span({ + id: "stream1", + name: "inference.stream", + parentId: "i1", + startNs: 5500n, // open child — 0 duration + }), + ]; + + const report = attributionFromSpans(spans); + expect(report.session.completedTurnCount).toBe(1); + expect(report.session.turnCount).toBe(2); + // wall = 5000 + 2000 = 7000 + expect(report.session.wallNs).toBe(7000); + // inference 3000+1500=4500; tools 1000+500=1500; other = 7000-6000=1000 + expect(categoryShare(report.session.categories, "inference").ns).toBe(4500); + expect(categoryShare(report.session.categories, "tools").ns).toBe(1500); + expect(categoryShare(report.session.categories, "other").ns).toBe(1000); + + const shareSum = report.session.categories.reduce((a, c) => a + c.share, 0); + expect(shareSum).toBeCloseTo(1, 10); + + const openTurn = report.turns.find((t) => t.turnId === "t1")!; + expect(openTurn.open).toBe(true); + expect(openTurn.turnNs).toBe(2000); + const openShareSum = openTurn.categories.reduce((a, c) => a + c.share, 0); + expect(openShareSum).toBeCloseTo(1, 10); + }); + + test("open turn with no completed descendants has zero wall and zero shares", () => { + const spans: PerfSpan[] = [ + span({ id: "t1", name: "turn", startNs: 0n }), + span({ + id: "i1", + name: "inference", + parentId: "t1", + startNs: 0n, // still open + }), + ]; + const report = attributionFromSpans(spans); + expect(report.session.wallNs).toBe(0); + expect(report.turns[0]!.open).toBe(true); + expect(report.turns[0]!.turnNs).toBe(0); + for (const c of report.session.categories) { + expect(c.share).toBe(0); + expect(c.ns).toBe(0); + } + }); +}); + describe("dump round-trip", () => { test("attributionFromDump matches live spans", () => { const spans = multiToolTurnFixture(); diff --git a/src/perf/attribution-report.ts b/src/perf/attribution-report.ts index b5d4c36f8..6e6591acd 100644 --- a/src/perf/attribution-report.ts +++ b/src/perf/attribution-report.ts @@ -3,6 +3,9 @@ * * Pure functions: no I/O, no module state, no OTEL. Categories partition turn * wall time into exclusive buckets so shares sum to ~1 (remainder → other). + * + * Open (still-running) turns use an estimated wall: max completed-descendant + * endNs − turn.startNs. That keeps mid-stall dumps usable for share %. */ import type { PerfSpan, SpanName } from "./index.js"; @@ -62,7 +65,10 @@ export type TurnAttribution = { /** Session-level attribution report. */ export type AttributionReport = { session: { - /** Denominator for shares: sum of completed turn walls (open turns excluded). */ + /** + * Denominator for shares: sum of turn walls (completed turns use end−start; + * open turns use estimated wall from max completed-descendant end). + */ wallNs: number; categories: CategoryShare[]; inference: InferenceSplit; @@ -134,6 +140,31 @@ function walkDescendants( } } +/** + * Wall for a turn span. Completed → end−start. Open → max completed-descendant + * end − turn.start (stall-dump estimate so shares stay meaningful mid-turn). + */ +export function turnWallNs( + turn: PerfSpan, + byParent: Map, +): { wallNs: number; open: boolean } { + const completed = spanDurationNs(turn); + if (completed !== undefined) { + return { wallNs: completed, open: false }; + } + + let maxEnd: bigint | undefined; + walkDescendants(turn.id, byParent, (child) => { + if (child.endNs === undefined) return; + if (maxEnd === undefined || child.endNs > maxEnd) maxEnd = child.endNs; + }); + if (maxEnd === undefined) { + return { wallNs: 0, open: true }; + } + const d = maxEnd - turn.startNs; + return { wallNs: d <= 0n ? 0 : Number(d), open: true }; +} + /** Accumulate exclusive + nested metrics from a descendant span. */ function accumulate(bucket: ExclusiveBucket, span: PerfSpan): void { const dur = spanDurationNs(span) ?? 0; @@ -182,7 +213,10 @@ function shareOf(ns: number, wallNs: number): number { /** * Build exclusive category shares. `other` absorbs gaps and un-instrumented wall - * (scheduling, TUI, etc.) so shares sum to 1 when wallNs > 0. + * (scheduling, TUI, etc.) so shares sum to 1 when wallNs > 0 and attributed ≤ wall. + * + * When attributed exceeds wall (rare parallel overlap), other is 0 and category + * shares still use wall as denominator (sum may exceed 1 — caller can detect). */ function categorySharesFromBucket( bucket: ExclusiveBucket, @@ -252,6 +286,9 @@ function countNameUnder( * Nested diagnostics (not exclusive): * inference.ttft / inference.stream shares of inference wall * adapter.transport share of inference (transport prioritization signal) + * + * Open turns: wall estimated from max completed-descendant end so mid-stall + * dumps still produce usable share percentages. */ export function attributionFromSpans(spans: readonly PerfSpan[]): AttributionReport { const byParent = childrenOf(spans); @@ -264,9 +301,7 @@ export function attributionFromSpans(spans: readonly PerfSpan[]): AttributionRep const bucket = emptyBucket(); walkDescendants(turn.id, byParent, (child) => accumulate(bucket, child)); - const turnDur = spanDurationNs(turn); - const turnNs = turnDur ?? 0; - const open = turnDur === undefined; + const { wallNs: turnNs, open } = turnWallNs(turn, byParent); const inferenceCount = countNameUnder(turn.id, byParent, "inference"); const permissionWaitCount = countNameUnder(turn.id, byParent, "permission.wait"); @@ -289,8 +324,8 @@ export function attributionFromSpans(spans: readonly PerfSpan[]): AttributionRep }; }); - // Session: sum completed turns only for wall denominator so open turns do not - // inflate "other". Category ns still include open-turn children (partial data). + // Session wall includes open-turn estimates so stall dumps keep shares ~1. + // Category ns include all turn descendants (open children contribute 0 duration). const sessionBucket = emptyBucket(); let wallNs = 0; let completedTurnCount = 0; @@ -298,11 +333,9 @@ export function attributionFromSpans(spans: readonly PerfSpan[]): AttributionRep let permissionWaitCount = 0; for (const turn of turnSpans) { - const turnDur = spanDurationNs(turn); - if (turnDur !== undefined) { - wallNs += turnDur; - completedTurnCount += 1; - } + const { wallNs: turnNs, open } = turnWallNs(turn, byParent); + wallNs += turnNs; + if (!open) completedTurnCount += 1; walkDescendants(turn.id, byParent, (child) => { accumulate(sessionBucket, child); if (child.name === "inference") inferenceCount += 1; @@ -408,78 +441,60 @@ function ms(ns: number): string { function categoryLine(c: CategoryShare): string { const count = c.count > 0 && c.category !== "other" ? ` n=${c.count}` : ""; - return ` ${c.category.padEnd(18)} ${pct(c.share).padStart(7)} ${ms(c.ns).padStart(10)}${count}`; + return ` ${c.category.padEnd(18)} ${pct(c.share).padStart(6)} ${ms(c.ns)}${count}`; } -/** - * Human-readable multi-line report. Safe for terminals; no color codes. - */ +/** Human-readable multi-line report for CLI / docs. */ export function formatAttributionReport(report: AttributionReport): string { const lines: string[] = []; const s = report.session; lines.push("PerfTrace attribution report"); - lines.push("============================"); + lines.push("───────────────────────────"); lines.push( - `Session wall (completed turns): ${ms(s.wallNs)} turns=${s.turnCount} completed=${s.completedTurnCount}`, + `Session wall: ${ms(s.wallNs)} turns=${s.turnCount} (completed=${s.completedTurnCount})`, ); lines.push(""); - lines.push("Exclusive phase shares (of session wall)"); + lines.push("Exclusive phase shares (of session wall):"); for (const c of s.categories) { lines.push(categoryLine(c)); } lines.push(""); - lines.push("Inference split (ttft vs stream of ttft+stream)"); - lines.push( - ` ttft ${pct(s.inference.ttftShare).padStart(7)} ${ms(s.inference.ttftNs).padStart(10)}`, - ); lines.push( - ` stream ${pct(s.inference.streamShare).padStart(7)} ${ms(s.inference.streamNs).padStart(10)}`, - ); - lines.push(""); - lines.push("Transport signal (adapter.transport / inference)"); - lines.push( - ` transportNs ${ms(s.transportNs).padStart(10)} share_of_inference=${pct(s.transportShareOfInference)}`, - ); - lines.push( - ` tools=${s.toolCount} subagents=${s.subagentCount}`, + `Inference split: ttft=${pct(s.inference.ttftShare)} (${ms(s.inference.ttftNs)}) stream=${pct(s.inference.streamShare)} (${ms(s.inference.streamNs)})`, ); + if (s.transportNs > 0 || s.transportShareOfInference > 0) { + lines.push( + `Transport: ${ms(s.transportNs)} (${pct(s.transportShareOfInference)} of inference)`, + ); + } + lines.push(`Tools: n=${s.toolCount} Subagents: n=${s.subagentCount}`); if (report.turns.length > 0) { lines.push(""); - lines.push("Per-turn summary"); + lines.push("Per-turn:"); for (const t of report.turns) { - const open = t.open ? " OPEN" : ""; - const byCat = Object.fromEntries( - t.categories.map((c) => [c.category, c]), - ) as Record; + const openTag = t.open ? " [open]" : ""; lines.push( - ` turn ${t.turnId}${open} wall=${ms(t.turnNs)} ` + - `inf=${pct(byCat.inference.share)} tools=${pct(byCat.tools.share)} ` + - `perm=${pct(byCat["permission.wait"].share)} sub=${pct(byCat.subagent.share)} ` + - `other=${pct(byCat.other.share)} ` + - `ttft/stream=${pct(t.inference.ttftShare)}/${pct(t.inference.streamShare)} ` + - `tools_n=${t.toolCount} sub_n=${t.subagentCount}`, + ` turn ${t.turnId}${openTag} wall=${ms(t.turnNs)} tools=${t.toolCount} subagents=${t.subagentCount}`, ); + for (const c of t.categories) { + lines.push(` ${c.category.padEnd(16)} ${pct(c.share).padStart(6)} ${ms(c.ns)}`); + } } } - lines.push(""); return lines.join("\n"); } -/** - * Lookup a category share from a report's session or turn categories list. - * Convenience for tests and scripts. - */ +/** Lookup a category share row (throws if missing — categories are always complete). */ export function categoryShare( categories: readonly CategoryShare[], - name: AttributionCategory, + category: AttributionCategory, ): CategoryShare { - const found = categories.find((c) => c.category === name); - if (found === undefined) { - throw new Error(`missing attribution category "${name}"`); + const row = categories.find((c) => c.category === category); + if (row === undefined) { + throw new Error(`attribution report: missing category ${category}`); } - return found; + return row; } - From a892cf3b9921752f1ba4a3bf3e30bd7a24e56a65 Mon Sep 17 00:00:00 2001 From: Sawyer Cutler Date: Tue, 4 Aug 2026 09:19:54 -0700 Subject: [PATCH 3/3] Make exclusive attribution skip nested exclusive children Nested tool/inference under subagent no longer double-count toward turn wall; open phase names surface mid-stall incompleteness; dump version mismatch is rejected with a clear error. --- docs/perftrace-attribution-guide.md | 34 ++-- src/perf/attribution-report.test.ts | 160 ++++++++++++++++- src/perf/attribution-report.ts | 259 +++++++++++++++++++++------- src/perf/rollup.ts | 5 +- 4 files changed, 387 insertions(+), 71 deletions(-) diff --git a/docs/perftrace-attribution-guide.md b/docs/perftrace-attribution-guide.md index 53481d017..f42bade0b 100644 --- a/docs/perftrace-attribution-guide.md +++ b/docs/perftrace-attribution-guide.md @@ -21,8 +21,16 @@ When a session feels slow, the first question is **where the wall time went**: Shares are **exclusive** over turn wall. For **completed** turns, wall is `end − start`. For **open** (still-running) turns — including mid-stall dumps — wall is estimated as `max(completed-descendant endNs) − turn.startNs` so shares -stay meaningful. Nested TTFT/stream and `adapter.transport` are diagnostic -splits (they are not added on top of `inference` in the exclusive table). +stay meaningful, and the report lists **open phase names** (e.g. +`inference.stream`, `turn`) so completed-only shares are not read as a full +stall diagnosis. + +Nested exclusive children under an exclusive parent (e.g. `tool` / +`inference` under `subagent`) count only toward the parent exclusive bucket — +they are not double-counted. Nested TTFT/stream and `adapter.transport` are +diagnostic splits (they are not added on top of `inference` in the exclusive +table). TTFT/stream shares use **(ttft + stream)** as the denominator, not +inference wall. ## Capture a real slow session @@ -92,18 +100,24 @@ Exclusive phase shares (of session wall): `inference` share with high `ttft` points at model queueing / cold start. A large `tools` share with high `n=` points at tool work. A large `permission.wait` share is human/ask-gate idle, not model or tool code. -2. **`other` large** — either real un-instrumented cost (TUI, scheduling) or +2. **Open / incomplete** — if the report says `Open (incomplete)` and lists + still-running phases, exclusive shares only cover completed descendants. + Treat open phase names as the hang candidates; do not conclude from the + exclusive table alone. +3. **`other` large** — either real un-instrumented cost (TUI, scheduling) or gaps between instrumented phases. If `other` dominates a pain session, add spans before optimizing transport. -3. **TTFT vs stream** — of `ttft + stream` only. High TTFT share → time-to-first-token - problem. High stream share → long generation or slow token delivery. -4. **Transport signal** — `adapter.transport / inference`. When transport is a +4. **TTFT vs stream** — of `ttft + stream` only (not inference wall). High TTFT + share → time-to-first-token problem. High stream share → long generation or + slow token delivery. +5. **Transport signal** — `adapter.transport / inference`. When transport is a large fraction of inference wall, prioritize transport work (WebSocket / incremental input). When it is small, transport is not the bottleneck. -5. **Per-turn rows** — find the outlier turn when the session average looks fine - but one turn felt stuck. -6. **Subagent count + share** — fanout cost. High subagent share means child - agents, not the parent inference path. +6. **Per-turn rows** — find the outlier turn when the session average looks fine + but one turn felt stuck. Open turns print `open phases:` explicitly. +7. **Subagent count + share** — fanout cost. High subagent share means child + agents as a whole (nested tools/inference under the subagent are inside that + bucket, not double-counted as parent tools/inference). ### What “large transport share” looks like diff --git a/src/perf/attribution-report.test.ts b/src/perf/attribution-report.test.ts index e82fe232a..fd70d3817 100644 --- a/src/perf/attribution-report.test.ts +++ b/src/perf/attribution-report.test.ts @@ -7,7 +7,7 @@ import { formatAttributionReport, spansFromDumpJson, } from "./attribution-report.js"; -import { buildDump, serializeSpan } from "./dump.js"; +import { DUMP_VERSION, buildDump, serializeSpan } from "./dump.js"; import { MULTI_TOOL_TURN_GOLDEN, multiToolTurnFixture, @@ -148,6 +148,112 @@ describe("attributionFromSpans — subagent + transport", () => { expect(report.session.subagentCount).toBe(1); expect(report.session.transportNs).toBe(800); expect(report.session.transportShareOfInference).toBeCloseTo(800 / 4000, 10); + expect(report.session.open).toBe(false); + expect(report.session.openPhases).toEqual([]); + }); + + test("nested exclusive under subagent does not double-count (share sum ≈ 1)", () => { + // turn 10_000 + // inference 2000 (top-level exclusive) + // subagent 6000 containing nested inference 2500 + tools 1500 + // tool 1000 (sibling exclusive) + // Exclusive: inference=2000, subagent=6000, tools=1000, other=1000 + // Nested under subagent must NOT add 2500+1500 into exclusive buckets. + const spans: PerfSpan[] = [ + span({ id: "t1", name: "turn", startNs: 0n, endNs: 10_000n }), + span({ + id: "i1", + name: "inference", + parentId: "t1", + startNs: 0n, + endNs: 2000n, + }), + span({ + id: "ttft1", + name: "inference.ttft", + parentId: "i1", + startNs: 0n, + endNs: 400n, + }), + span({ + id: "stream1", + name: "inference.stream", + parentId: "i1", + startNs: 400n, + endNs: 2000n, + }), + span({ + id: "sa1", + name: "subagent", + parentId: "t1", + startNs: 2000n, + endNs: 8000n, + }), + span({ + id: "sa_i1", + name: "inference", + parentId: "sa1", + startNs: 2000n, + endNs: 4500n, + }), + span({ + id: "sa_ttft", + name: "inference.ttft", + parentId: "sa_i1", + startNs: 2000n, + endNs: 2500n, + }), + span({ + id: "sa_stream", + name: "inference.stream", + parentId: "sa_i1", + startNs: 2500n, + endNs: 4500n, + }), + span({ + id: "sa_k1", + name: "tool", + parentId: "sa1", + startNs: 4500n, + endNs: 6000n, + }), + span({ + id: "k1", + name: "tool", + parentId: "t1", + startNs: 8000n, + endNs: 9000n, + }), + ]; + + const report = attributionFromSpans(spans); + const inf = categoryShare(report.session.categories, "inference"); + const tools = categoryShare(report.session.categories, "tools"); + const sub = categoryShare(report.session.categories, "subagent"); + const other = categoryShare(report.session.categories, "other"); + + expect(inf.ns).toBe(2000); + expect(sub.ns).toBe(6000); + expect(tools.ns).toBe(1000); // only the top-level tool, not sa_k1 + expect(other.ns).toBe(1000); // 10000 - 2000 - 6000 - 1000 + expect(inf.count).toBe(1); // nested inference under subagent not counted + expect(sub.count).toBe(1); + // toolCount still sees nested tools for visibility + expect(report.session.toolCount).toBe(2); + expect(report.session.subagentCount).toBe(1); + + const shareSum = report.session.categories.reduce((a, c) => a + c.share, 0); + expect(shareSum).toBeCloseTo(1, 10); + + // Nested diagnostics still roll up (parent + subagent ttft/stream) + expect(report.session.inference.ttftNs).toBe(400 + 500); + expect(report.session.inference.streamNs).toBe(1600 + 2000); + + const turnShareSum = report.turns[0]!.categories.reduce( + (a, c) => a + c.share, + 0, + ); + expect(turnShareSum).toBeCloseTo(1, 10); }); }); @@ -192,6 +298,10 @@ describe("attributionFromSpans — open (stall) turns", () => { expect(report.session.wallNs).toBe(3000); expect(report.turns[0]!.open).toBe(true); expect(report.turns[0]!.turnNs).toBe(3000); + expect(report.session.open).toBe(true); + // Still-running: turn + open stream (completed inference/tool are not listed) + expect(report.session.openPhases).toEqual(["inference.stream", "turn"]); + expect(report.turns[0]!.openPhases).toEqual(["inference.stream", "turn"]); expect(categoryShare(report.session.categories, "inference").ns).toBe(2000); expect(categoryShare(report.session.categories, "tools").ns).toBe(1000); @@ -281,6 +391,9 @@ describe("attributionFromSpans — open (stall) turns", () => { expect(report.session.wallNs).toBe(0); expect(report.turns[0]!.open).toBe(true); expect(report.turns[0]!.turnNs).toBe(0); + expect(report.session.open).toBe(true); + expect(report.session.openPhases).toEqual(["inference", "turn"]); + expect(report.turns[0]!.openPhases).toEqual(["inference", "turn"]); for (const c of report.session.categories) { expect(c.share).toBe(0); expect(c.ns).toBe(0); @@ -308,6 +421,17 @@ describe("dump round-trip", () => { expect(spans[0]!.startNs).toBe(0n); expect(deserializeDumpSpan(serialized[0]!).id).toBe("t1"); }); + + test("attributionFromDump rejects unsupported DUMP_VERSION", () => { + const dump = buildDump( + multiToolTurnFixture(), + "fixture-multi", + "2026-04-08T00:00:00.000Z", + ); + expect(() => + attributionFromDump({ ...dump, version: DUMP_VERSION + 1 }), + ).toThrow(/unsupported dump version/); + }); }); describe("formatAttributionReport", () => { @@ -324,5 +448,39 @@ describe("formatAttributionReport", () => { expect(text).toContain("40.0%"); // inference 2000/5000 expect(text).toContain("24.0%"); // tools 1200/5000 expect(text).toContain("turn t1"); + expect(text).toContain("Inference split (of ttft+stream)"); + expect(text).not.toContain("Open (incomplete)"); + }); + + test("surfaces open phases for mid-stall dumps", () => { + const spans: PerfSpan[] = [ + span({ id: "t1", name: "turn", startNs: 0n }), + span({ + id: "i1", + name: "inference", + parentId: "t1", + startNs: 0n, + endNs: 1000n, + }), + span({ + id: "stream1", + name: "inference.stream", + parentId: "i1", + startNs: 200n, + }), + span({ + id: "k1", + name: "tool", + parentId: "t1", + startNs: 1000n, + endNs: 1500n, + }), + ]; + const text = formatAttributionReport(attributionFromSpans(spans)); + expect(text).toContain("Open (incomplete)"); + expect(text).toContain("inference.stream"); + expect(text).toContain("open phases:"); + expect(text).toContain("shares incomplete"); + expect(text).toContain("not a full stall diagnosis"); }); }); diff --git a/src/perf/attribution-report.ts b/src/perf/attribution-report.ts index 6e6591acd..bd94f31f8 100644 --- a/src/perf/attribution-report.ts +++ b/src/perf/attribution-report.ts @@ -4,14 +4,19 @@ * Pure functions: no I/O, no module state, no OTEL. Categories partition turn * wall time into exclusive buckets so shares sum to ~1 (remainder → other). * + * Exclusive buckets do not double-count nested exclusive children (e.g. tools + * under a subagent count only toward `subagent`, not also toward `tools`). + * * Open (still-running) turns use an estimated wall: max completed-descendant - * endNs − turn.startNs. That keeps mid-stall dumps usable for share %. + * endNs − turn.startNs. That keeps mid-stall dumps usable for share %, but + * open phase names are reported so completed-only shares are not mistaken for + * a complete stall diagnosis. */ import type { PerfSpan, SpanName } from "./index.js"; import type { DumpSpan, PerfDump } from "./dump.js"; import { DUMP_VERSION } from "./dump.js"; -import { spanDurationNs } from "./rollup.js"; +import { childrenOf, spanDurationNs, walkDescendants } from "./rollup.js"; /** Exclusive wall-time buckets used for session / turn share %. */ export const ATTRIBUTION_CATEGORIES = [ @@ -24,6 +29,14 @@ export const ATTRIBUTION_CATEGORIES = [ export type AttributionCategory = (typeof ATTRIBUTION_CATEGORIES)[number]; +/** Span names that form the exclusive partition (not nested diagnostics). */ +const EXCLUSIVE_SPAN_NAMES: ReadonlySet = new Set([ + "inference", + "tool", + "permission.wait", + "subagent", +]); + /** One exclusive category and its share of a denominator wall. */ export type CategoryShare = { category: AttributionCategory; @@ -35,7 +48,10 @@ export type CategoryShare = { count: number; }; -/** TTFT vs stream split inside inference wall (not exclusive of each other vs parent). */ +/** + * TTFT vs stream split. Shares use (ttft + stream) as the denominator — + * not inference wall (gaps / un-instrumented inference time are excluded). + */ export type InferenceSplit = { ttftNs: number; streamNs: number; @@ -49,6 +65,12 @@ export type TurnAttribution = { turnId: string; turnNs: number; open: boolean; + /** + * Distinct phase names still open under this turn (and the turn itself when + * open). Empty for completed turns. Surfaces mid-stall hangs so exclusive + * shares of completed children are not read as a full diagnosis. + */ + openPhases: SpanName[]; categories: CategoryShare[]; inference: InferenceSplit; toolCount: number; @@ -70,6 +92,13 @@ export type AttributionReport = { * open turns use estimated wall from max completed-descendant end). */ wallNs: number; + /** True when any turn is still open (stall / mid-dump). */ + open: boolean; + /** + * Distinct open phase names across the session (union of per-turn openPhases). + * Empty when every turn is completed. + */ + openPhases: SpanName[]; categories: CategoryShare[]; inference: InferenceSplit; toolCount: number; @@ -108,36 +137,29 @@ function emptyBucket(): ExclusiveBucket { }; } -function childrenOf(spans: readonly PerfSpan[]): Map { - const byParent = new Map(); - for (const span of spans) { - if (span.parentId === undefined) continue; - const list = byParent.get(span.parentId); - if (list === undefined) { - byParent.set(span.parentId, [span]); - } else { - list.push(span); - } - } - return byParent; +function spanById(spans: readonly PerfSpan[]): Map { + const map = new Map(); + for (const span of spans) map.set(span.id, span); + return map; } -function walkDescendants( - rootId: string, - byParent: Map, - visit: (span: PerfSpan) => void, -): void { - const stack = byParent.get(rootId); - if (stack === undefined) return; - const work: PerfSpan[] = stack.slice(); - while (work.length > 0) { - const span = work.pop()!; - visit(span); - const kids = byParent.get(span.id); - if (kids !== undefined) { - for (const k of kids) work.push(k); - } +/** + * True when any ancestor of `span` is an exclusive-category span. + * Nested exclusive children (e.g. tool under subagent) must not also fill the + * exclusive tools bucket — their wall is already inside the parent exclusive. + */ +function hasExclusiveAncestor( + span: PerfSpan, + byId: Map, +): boolean { + let parentId = span.parentId; + while (parentId !== undefined) { + const parent = byId.get(parentId); + if (parent === undefined) return false; + if (EXCLUSIVE_SPAN_NAMES.has(parent.name)) return true; + parentId = parent.parentId; } + return false; } /** @@ -165,22 +187,53 @@ export function turnWallNs( return { wallNs: d <= 0n ? 0 : Number(d), open: true }; } -/** Accumulate exclusive + nested metrics from a descendant span. */ -function accumulate(bucket: ExclusiveBucket, span: PerfSpan): void { +/** + * Distinct open phase names under `rootId` (descendants only). Stable SPAN_NAMES + * order when known, then any remaining by name. + */ +function openPhasesUnder( + rootId: string, + byParent: Map, + includeRoot?: PerfSpan, +): SpanName[] { + const found = new Set(); + if (includeRoot !== undefined && includeRoot.endNs === undefined) { + found.add(includeRoot.name); + } + walkDescendants(rootId, byParent, (child) => { + if (child.endNs === undefined) found.add(child.name); + }); + if (found.size === 0) return []; + return [...found].sort((a, b) => a.localeCompare(b)); +} + +/** + * Accumulate metrics from a descendant span. + * + * Exclusive categories (inference / tool / permission.wait / subagent) only + * contribute ns when the span is not under another exclusive parent — so a + * nested tool under subagent does not double-count against turn wall. + * Nested diagnostics (ttft / stream / transport) and counts always accumulate. + */ +function accumulate( + bucket: ExclusiveBucket, + span: PerfSpan, + skipExclusiveNs: boolean, +): void { const dur = spanDurationNs(span) ?? 0; switch (span.name as SpanName) { case "inference": - bucket.inferenceNs += dur; + if (!skipExclusiveNs) bucket.inferenceNs += dur; break; case "tool": - bucket.toolNs += dur; + if (!skipExclusiveNs) bucket.toolNs += dur; bucket.toolCount += 1; break; case "permission.wait": - bucket.permissionWaitNs += dur; + if (!skipExclusiveNs) bucket.permissionWaitNs += dur; break; case "subagent": - bucket.subagentNs += dur; + if (!skipExclusiveNs) bucket.subagentNs += dur; bucket.subagentCount += 1; break; case "inference.ttft": @@ -197,6 +250,17 @@ function accumulate(bucket: ExclusiveBucket, span: PerfSpan): void { } } +function accumulateTree( + rootId: string, + byParent: Map, + byId: Map, + bucket: ExclusiveBucket, +): void { + walkDescendants(rootId, byParent, (child) => { + accumulate(bucket, child, hasExclusiveAncestor(child, byId)); + }); +} + function inferenceSplit(ttftNs: number, streamNs: number): InferenceSplit { const split = ttftNs + streamNs; return { @@ -265,14 +329,21 @@ function categorySharesFromBucket( ]; } -function countNameUnder( +/** + * Count exclusive-category spans under root that are not nested under another + * exclusive parent (top-level exclusive only — matches exclusive ns accounting). + */ +function countTopExclusiveUnder( rootId: string, byParent: Map, + byId: Map, name: SpanName, ): number { let n = 0; walkDescendants(rootId, byParent, (s) => { - if (s.name === name) n += 1; + if (s.name !== name) return; + if (hasExclusiveAncestor(s, byId)) return; + n += 1; }); return n; } @@ -283,15 +354,20 @@ function countNameUnder( * Exclusive categories (do not nest-double-count): * inference | tools | permission.wait | subagent | other * + * Nested exclusive children under an exclusive parent (e.g. inference/tool under + * subagent) contribute only to the parent exclusive bucket. + * * Nested diagnostics (not exclusive): - * inference.ttft / inference.stream shares of inference wall + * inference.ttft / inference.stream shares of (ttft + stream) * adapter.transport share of inference (transport prioritization signal) * * Open turns: wall estimated from max completed-descendant end so mid-stall - * dumps still produce usable share percentages. + * dumps still produce usable share percentages; openPhases lists still-running + * phases so the report is not read as a complete hang diagnosis. */ export function attributionFromSpans(spans: readonly PerfSpan[]): AttributionReport { const byParent = childrenOf(spans); + const byId = spanById(spans); const turnSpans = spans .filter((s) => s.name === "turn") .slice() @@ -299,16 +375,30 @@ export function attributionFromSpans(spans: readonly PerfSpan[]): AttributionRep const turns: TurnAttribution[] = turnSpans.map((turn) => { const bucket = emptyBucket(); - walkDescendants(turn.id, byParent, (child) => accumulate(bucket, child)); + accumulateTree(turn.id, byParent, byId, bucket); const { wallNs: turnNs, open } = turnWallNs(turn, byParent); - const inferenceCount = countNameUnder(turn.id, byParent, "inference"); - const permissionWaitCount = countNameUnder(turn.id, byParent, "permission.wait"); + const openPhases = open + ? openPhasesUnder(turn.id, byParent, turn) + : []; + const inferenceCount = countTopExclusiveUnder( + turn.id, + byParent, + byId, + "inference", + ); + const permissionWaitCount = countTopExclusiveUnder( + turn.id, + byParent, + byId, + "permission.wait", + ); return { turnId: turn.id, turnNs, open, + openPhases, categories: categorySharesFromBucket( bucket, turnNs, @@ -325,31 +415,55 @@ export function attributionFromSpans(spans: readonly PerfSpan[]): AttributionRep }); // Session wall includes open-turn estimates so stall dumps keep shares ~1. - // Category ns include all turn descendants (open children contribute 0 duration). + // Category ns use exclusive (non-nested) accounting; open children contribute 0 duration. const sessionBucket = emptyBucket(); let wallNs = 0; let completedTurnCount = 0; let inferenceCount = 0; let permissionWaitCount = 0; + const sessionOpenPhases = new Set(); for (const turn of turnSpans) { const { wallNs: turnNs, open } = turnWallNs(turn, byParent); wallNs += turnNs; - if (!open) completedTurnCount += 1; - walkDescendants(turn.id, byParent, (child) => { - accumulate(sessionBucket, child); - if (child.name === "inference") inferenceCount += 1; - if (child.name === "permission.wait") permissionWaitCount += 1; - }); + if (!open) { + completedTurnCount += 1; + } else { + for (const p of openPhasesUnder(turn.id, byParent, turn)) { + sessionOpenPhases.add(p); + } + } + accumulateTree(turn.id, byParent, byId, sessionBucket); + inferenceCount += countTopExclusiveUnder( + turn.id, + byParent, + byId, + "inference", + ); + permissionWaitCount += countTopExclusiveUnder( + turn.id, + byParent, + byId, + "permission.wait", + ); } // No turn roots (partial / orphan snapshot): fall back to flat exclusive sums - // and use attributed total as the wall denominator. + // (still skip exclusive ns under exclusive ancestors) and use attributed total + // as the wall denominator. if (turnSpans.length === 0) { for (const span of spans) { - accumulate(sessionBucket, span); - if (span.name === "inference") inferenceCount += 1; - if (span.name === "permission.wait") permissionWaitCount += 1; + accumulate(sessionBucket, span, hasExclusiveAncestor(span, byId)); + if (span.name === "inference" && !hasExclusiveAncestor(span, byId)) { + inferenceCount += 1; + } + if ( + span.name === "permission.wait" && + !hasExclusiveAncestor(span, byId) + ) { + permissionWaitCount += 1; + } + if (span.endNs === undefined) sessionOpenPhases.add(span.name); } wallNs = sessionBucket.inferenceNs + @@ -358,9 +472,15 @@ export function attributionFromSpans(spans: readonly PerfSpan[]): AttributionRep sessionBucket.subagentNs; } + const openPhases = [...sessionOpenPhases].sort((a, b) => + a.localeCompare(b), + ); + return { session: { wallNs, + open: openPhases.length > 0 || completedTurnCount < turnSpans.length, + openPhases, categories: categorySharesFromBucket( sessionBucket, wallNs, @@ -416,10 +536,12 @@ export function spansFromDumpJson(raw: unknown): PerfSpan[] { /** Attribute a parsed PerfDump (or dump-like JSON) offline. */ export function attributionFromDump(raw: unknown): AttributionReport { - if (raw !== null && typeof raw === "object") { + if (raw !== null && typeof raw === "object" && !Array.isArray(raw)) { const obj = raw as Partial; if (obj.version !== undefined && obj.version !== DUMP_VERSION) { - // Still attempt — schema may be forward-compatible on spans[]. + throw new Error( + `attribution report: unsupported dump version ${String(obj.version)} (expected ${DUMP_VERSION})`, + ); } } return attributionFromSpans(spansFromDumpJson(raw)); @@ -444,6 +566,10 @@ function categoryLine(c: CategoryShare): string { return ` ${c.category.padEnd(18)} ${pct(c.share).padStart(6)} ${ms(c.ns)}${count}`; } +function formatOpenPhases(phases: readonly SpanName[]): string { + return phases.length === 0 ? "(none)" : phases.join(", "); +} + /** Human-readable multi-line report for CLI / docs. */ export function formatAttributionReport(report: AttributionReport): string { const lines: string[] = []; @@ -454,14 +580,26 @@ export function formatAttributionReport(report: AttributionReport): string { lines.push( `Session wall: ${ms(s.wallNs)} turns=${s.turnCount} (completed=${s.completedTurnCount})`, ); + if (s.open) { + lines.push( + `Open (incomplete): still-running phases: ${formatOpenPhases(s.openPhases)}`, + ); + lines.push( + " Exclusive shares below use completed descendants only — not a full stall diagnosis.", + ); + } lines.push(""); - lines.push("Exclusive phase shares (of session wall):"); + lines.push( + s.open + ? "Exclusive phase shares (of estimated session wall; incomplete while open):" + : "Exclusive phase shares (of session wall):", + ); for (const c of s.categories) { lines.push(categoryLine(c)); } lines.push(""); lines.push( - `Inference split: ttft=${pct(s.inference.ttftShare)} (${ms(s.inference.ttftNs)}) stream=${pct(s.inference.streamShare)} (${ms(s.inference.streamNs)})`, + `Inference split (of ttft+stream): ttft=${pct(s.inference.ttftShare)} (${ms(s.inference.ttftNs)}) stream=${pct(s.inference.streamShare)} (${ms(s.inference.streamNs)})`, ); if (s.transportNs > 0 || s.transportShareOfInference > 0) { lines.push( @@ -478,6 +616,11 @@ export function formatAttributionReport(report: AttributionReport): string { lines.push( ` turn ${t.turnId}${openTag} wall=${ms(t.turnNs)} tools=${t.toolCount} subagents=${t.subagentCount}`, ); + if (t.open) { + lines.push( + ` open phases: ${formatOpenPhases(t.openPhases)} (shares incomplete)`, + ); + } for (const c of t.categories) { lines.push(` ${c.category.padEnd(16)} ${pct(c.share).padStart(6)} ${ms(c.ns)}`); } diff --git a/src/perf/rollup.ts b/src/perf/rollup.ts index 929cab8d2..d51cec92f 100644 --- a/src/perf/rollup.ts +++ b/src/perf/rollup.ts @@ -116,8 +116,9 @@ export function rollupByPhase(spans: readonly PerfSpan[]): PhaseSummary[] { /** * Build parent → children index. Orphans (parent missing after ring eviction) * still appear as roots for by-phase; by-turn only lists actual turn spans. + * Shared with attribution-report (exclusive shares walk the same tree). */ -function childrenOf(spans: readonly PerfSpan[]): Map { +export function childrenOf(spans: readonly PerfSpan[]): Map { const byParent = new Map(); for (const span of spans) { if (span.parentId === undefined) continue; @@ -132,7 +133,7 @@ function childrenOf(spans: readonly PerfSpan[]): Map { } /** Depth-first walk of the subtree rooted at `rootId` (excluding the root). */ -function walkDescendants( +export function walkDescendants( rootId: string, byParent: Map, visit: (span: PerfSpan) => void,