From 293fa8096c10cbea8d31fbb4a3d0743e8509ea89 Mon Sep 17 00:00:00 2001 From: qwen-code-dev-bot <269191875+qwen-code-dev-bot@users.noreply.github.com> Date: Thu, 23 Jul 2026 02:30:35 +0800 Subject: [PATCH] feat(cli): add an opt-in tool/approval wall-time bottleneck report for unattended runs (#220) A long autonomous run could look healthy in the aggregate run summary while one slow tool or one long approval gate dominated its wall-time, with no way to tell where the time went short of parsing raw logs. Add a privacy-safe, bounded bottleneck report (opt-in --bottleneck) that ranks tools and approval gates by wall-time and call count, in both the NDJSON headless stream and the plain-text path. The report is metadata only (tool names, wall-time, counts) and has no channel for prompts, file contents, secrets, or raw tool payloads. --- src/agent.ts | 20 ++- src/headless-protocol.ts | 5 + src/index.ts | 18 +++ src/run-bottleneck.ts | 140 +++++++++++++++++ tests/integration/run-bottleneck.test.ts | 189 +++++++++++++++++++++++ tests/unit/run-bottleneck.test.ts | 139 +++++++++++++++++ 6 files changed, 510 insertions(+), 1 deletion(-) create mode 100644 src/run-bottleneck.ts create mode 100644 tests/integration/run-bottleneck.test.ts create mode 100644 tests/unit/run-bottleneck.test.ts diff --git a/src/agent.ts b/src/agent.ts index 7f64a99..8c68e27 100644 --- a/src/agent.ts +++ b/src/agent.ts @@ -14,6 +14,7 @@ import { buildEffectiveSystemPrompt } from "./instruction-context.js"; import { compactMessages, buildCompactedTranscript } from "./compaction.js"; import type { LoadedImage } from "./image-input.js"; import type { TurnImageCollector } from "./turn-checkpoint.js"; +import type { BottleneckCollector } from "./run-bottleneck.js"; const MAX_ROUNDS = 30; @@ -49,6 +50,10 @@ export interface AgentOptions { // caller). Each matching hook runs as a deny-only gate before a tool executes; // a hook can only block a call, never approve it. Empty/undefined ⇒ no hooks. preToolUseHooks?: readonly PreToolUseHook[]; + // Optional wall-time bottleneck collector. When present, the loop records each + // tool's execution wall-time and each approval gate's wait wall-time so the + // caller can build a privacy-safe bottleneck report. Undefined ⇒ no collection. + bottleneck?: BottleneckCollector; } // Cumulative usage and cost reported after each round. `estimatedCostUsd` is an @@ -410,6 +415,7 @@ export async function runAgent( opts.mutatingAllowed ?? true, requestApproval, preToolUseHooks, + opts.bottleneck, opts.turnImages, ); sink.toolResult({ id: tc.id, name: tc.name, result, round }); @@ -450,6 +456,7 @@ async function executeToolCall( mutatingAllowed: boolean, requestApproval: (name: string, args: Record) => Promise, preToolUseHooks: readonly PreToolUseHook[], + bottleneck: BottleneckCollector | undefined, turnImages?: TurnImageCollector, ): Promise { const tool = toolMap.get(tc.name); @@ -514,7 +521,11 @@ async function executeToolCall( try { parsed = JSON.parse(tc.arguments); } catch { /* ignore */ } + // Time the approval gate separately from the tool's own execution so a long + // human-approval wait surfaces as an `approval` bottleneck, not a tool one. + const approvalStartedAt = Date.now(); const approved = await requestApproval(tc.name, parsed); + bottleneck?.recordApproval(tc.name, Date.now() - approvalStartedAt); if (!approved) { return { content: "Tool execution denied by user", isError: true }; } @@ -533,7 +544,14 @@ async function executeToolCall( /* path escape is the tool's own error to surface */ } } - return await tool.execute(parsed, workspace); + // Time only the tool's own execution (approval/policy/hook gates are measured + // or rejected above); recorded even when the tool throws via the finally. + const executeStartedAt = Date.now(); + try { + return await tool.execute(parsed, workspace); + } finally { + bottleneck?.recordTool(tc.name, Date.now() - executeStartedAt); + } } catch (err: unknown) { const msg = err instanceof Error ? err.message : String(err); return { content: `Tool error: ${msg}`, isError: true }; diff --git a/src/headless-protocol.ts b/src/headless-protocol.ts index 735d1e3..75abefe 100644 --- a/src/headless-protocol.ts +++ b/src/headless-protocol.ts @@ -1,6 +1,7 @@ import type { AgentSink } from "./agent.js"; import type { ToolResult } from "./tools.js"; import type { RunSummary } from "./run-summary.js"; +import type { BottleneckReport } from "./run-bottleneck.js"; import { redactSecrets } from "./permission-impact.js"; // A stable, versioned newline-delimited JSON protocol for core run lifecycle @@ -75,6 +76,10 @@ export type HeadlessEvent = // Opt-in (`--summary`) privacy-safe run summary, emitted just before the // terminal `complete`. Carries only metadata, never prompt/tool/file content. | { type: "summary"; summary: RunSummary } + // Opt-in (`--bottleneck`) privacy-safe tool/approval wall-time bottleneck + // report, emitted just before the terminal `complete`. Metadata only: tool + // names, wall-time, and counts — never prompt/tool/file content. + | { type: "bottleneck"; bottleneck: BottleneckReport } | { type: "complete"; ok: boolean; exitCode: number; rounds: number; reason: string }; export type HeadlessRecord = HeadlessEvent & { diff --git a/src/index.ts b/src/index.ts index 4504f31..54244e9 100644 --- a/src/index.ts +++ b/src/index.ts @@ -153,6 +153,7 @@ import { import { HeadlessWriter, createHeadlessSink, startEvent } from "./headless-protocol.js"; import { redactSecrets, redactHomePath } from "./permission-impact.js"; import { buildRunSummary, formatRunSummary } from "./run-summary.js"; +import { createBottleneckCollector, formatBottleneckReport } from "./run-bottleneck.js"; import { loadImageAttachments, imageRef } from "./image-input.js"; import type { LoadedImage } from "./image-input.js"; import { createTools } from "./tools.js"; @@ -373,6 +374,10 @@ program ) .option("--no-color", "Disable ANSI color output (also honors the NO_COLOR env var)") .option("--summary", "Print a privacy-safe execution summary for the run (unattended use)") + .option( + "--bottleneck", + "Print a privacy-safe tool/approval wall-time bottleneck report for the run (unattended use)", + ) .option( "--budget ", "Spend budget in USD; stop before further provider calls once the estimated cost reaches it (also honors OMC_SPEND_BUDGET_USD)", @@ -1936,6 +1941,7 @@ program const sink = createHeadlessSink(writer); const startedAt = Date.now(); const turnImages = new TurnImageCollector(); + const bottleneck = opts.bottleneck ? createBottleneckCollector() : null; let result: AgentResult; try { result = await runAgent(opts.prompt, existingMessages, { @@ -1951,10 +1957,14 @@ program images, turnImages, preToolUseHooks, + bottleneck: bottleneck?.collector, }); } catch (err: unknown) { const msg = err instanceof Error ? err.message : String(err); writer.emit({ type: "error", stage: "internal", message: redactSecrets(msg).text }); + if (bottleneck) { + writer.emit({ type: "bottleneck", bottleneck: bottleneck.build(Date.now() - startedAt) }); + } if (opts.summary) { writer.emit({ type: "summary", @@ -1999,6 +2009,9 @@ program }), }); } + if (bottleneck) { + writer.emit({ type: "bottleneck", bottleneck: bottleneck.build(Date.now() - startedAt) }); + } writer.emit({ type: "complete", ok: result.ok, @@ -2011,6 +2024,7 @@ program const startedAt = Date.now(); const turnImages = new TurnImageCollector(); + const bottleneck = opts.bottleneck ? createBottleneckCollector() : null; const result = await runAgent(opts.prompt, existingMessages, { config, workspace, @@ -2023,6 +2037,7 @@ program images, turnImages, preToolUseHooks, + bottleneck: bottleneck?.collector, }); sealSession(); recordTurnCheckpoint(turnImages); @@ -2047,6 +2062,9 @@ program }); process.stdout.write("\n" + formatRunSummary(summary) + "\n"); } + if (bottleneck) { + process.stdout.write("\n" + formatBottleneckReport(bottleneck.build(Date.now() - startedAt)) + "\n"); + } process.exit(exitCode); } else { // Interactive REPL diff --git a/src/run-bottleneck.ts b/src/run-bottleneck.ts new file mode 100644 index 0000000..fa001c9 --- /dev/null +++ b/src/run-bottleneck.ts @@ -0,0 +1,140 @@ +// A privacy-safe wall-time bottleneck report for unattended (`-p`) runs. It ranks +// tools and approval gates by wall-time and call count so an operator can answer +// "where did this long run spend its time?" without parsing raw logs: a slow tool +// surfaces as a `tool` bottleneck, a long human-approval wait as an `approval` +// bottleneck. It is opt-in (`--bottleneck`), bounded (a fixed head of ranked +// entries), and metadata-only — it carries tool names, wall-time, and counts, and +// has no channel for prompts, file contents, secrets, or raw tool payloads. The +// schema is stable and deterministic so CI can retain and diff it. + +export const BOTTLENECK_REPORT_SCHEMA = "oh-my-cli.bottleneck"; +export const BOTTLENECK_REPORT_VERSION = 1; + +// Bound the number of ranked entries so a pathological run cannot inflate the +// report into high-cardinality output. Entries beyond the head are not listed; +// their count is reported in `truncated`. +const MAX_BOTTLENECK_ENTRIES = 16; + +// Tool names flow from model output; although only registered tool names are ever +// recorded (unknown tools are rejected before timing), bound and sanitize anyway +// so the report can never carry a runaway or control-laced name. +const MAX_NAME = 256; + +export type BottleneckKind = "tool" | "approval"; + +export interface BottleneckEntry { + kind: BottleneckKind; + name: string; + // Total wall-time spent in this tool's execution (kind "tool") or waiting at + // its approval gate (kind "approval"), summed across all calls, in milliseconds. + wallMs: number; + calls: number; +} + +export interface BottleneckReport { + schema: typeof BOTTLENECK_REPORT_SCHEMA; + v: typeof BOTTLENECK_REPORT_VERSION; + // Total run wall-time, for context (the entries sum to the tool/approval + // portion of it; provider/model time is intentionally out of scope). + elapsedMs: number; + // Ranked by wall-time (desc), head-bound to MAX_BOTTLENECK_ENTRIES. + entries: BottleneckEntry[]; + // Count of distinct entries that fell off the head bound (0 when none). + truncated: number; +} + +// Accumulates per-tool execution and per-approval-gate wall-time across a run. +export interface BottleneckCollector { + recordTool(name: string, wallMs: number): void; + recordApproval(name: string, wallMs: number): void; +} + +interface Accumulator { + wallMs: number; + calls: number; +} + +function safeName(name: string): string { + const cleaned = name.replace(/[\u0000-\u001f\u007f]+/g, "_").trim(); + return cleaned.length <= MAX_NAME ? cleaned : cleaned.slice(0, MAX_NAME); +} + +export function createBottleneckCollector(): { + collector: BottleneckCollector; + build: (elapsedMs: number) => BottleneckReport; +} { + const tool = new Map(); + const approval = new Map(); + const bump = (map: Map, name: string, wallMs: number): void => { + const ms = Number.isFinite(wallMs) && wallMs > 0 ? wallMs : 0; + const key = safeName(name); + const acc = map.get(key) ?? { wallMs: 0, calls: 0 }; + acc.wallMs += ms; + acc.calls += 1; + map.set(key, acc); + }; + const collector: BottleneckCollector = { + recordTool: (name, wallMs) => bump(tool, name, wallMs), + recordApproval: (name, wallMs) => bump(approval, name, wallMs), + }; + return { collector, build: (elapsedMs) => buildBottleneckReport(elapsedMs, tool, approval) }; +} + +function buildBottleneckReport( + elapsedMs: number, + tool: Map, + approval: Map, +): BottleneckReport { + const all: BottleneckEntry[] = []; + for (const [name, acc] of tool) { + all.push({ kind: "tool", name, wallMs: Math.round(acc.wallMs), calls: acc.calls }); + } + for (const [name, acc] of approval) { + all.push({ kind: "approval", name, wallMs: Math.round(acc.wallMs), calls: acc.calls }); + } + // Rank by wall-time desc, then call count desc, then a stable name/kind order so + // identical runs produce byte-identical reports. + all.sort( + (a, b) => + b.wallMs - a.wallMs || + b.calls - a.calls || + a.name.localeCompare(b.name) || + a.kind.localeCompare(b.kind), + ); + const entries = all.slice(0, MAX_BOTTLENECK_ENTRIES); + return { + schema: BOTTLENECK_REPORT_SCHEMA, + v: BOTTLENECK_REPORT_VERSION, + elapsedMs: Math.max(0, Math.round(elapsedMs)), + entries, + truncated: Math.max(0, all.length - entries.length), + }; +} + +function formatElapsed(ms: number): string { + return `${(ms / 1000).toFixed(1)}s`; +} + +// A deterministic, human-readable rendering of the report. It contains only tool +// names, wall-time, and counts — there is no channel for prompt/tool/file content. +export function formatBottleneckReport(report: BottleneckReport): string { + const lines: string[] = []; + lines.push(`Bottleneck report (${report.schema} v${report.v})`); + lines.push(` elapsed: ${formatElapsed(report.elapsedMs)}`); + if (report.entries.length === 0) { + lines.push(" bottlenecks: (no tool or approval activity recorded)"); + } else { + lines.push(` bottlenecks (top ${report.entries.length} by wall-time):`); + report.entries.forEach((e, i) => { + const label = `${e.kind} ${e.name}`; + const callWord = e.calls === 1 ? "call" : "calls"; + lines.push( + ` ${String(i + 1).padStart(2)}. ${label.padEnd(24)} ${formatElapsed(e.wallMs).padStart(9)} (${e.calls} ${callWord})`, + ); + }); + } + if (report.truncated > 0) { + lines.push(` truncated: ${report.truncated} more entr${report.truncated === 1 ? "y" : "ies"} beyond the head bound`); + } + return lines.join("\n"); +} diff --git a/tests/integration/run-bottleneck.test.ts b/tests/integration/run-bottleneck.test.ts new file mode 100644 index 0000000..9e5cab6 --- /dev/null +++ b/tests/integration/run-bottleneck.test.ts @@ -0,0 +1,189 @@ +import { describe, it, expect, beforeAll, afterAll, beforeEach } from "vitest"; +import { createFakeServer } from "../fake-provider.js"; +import type { FakeServer } from "../fake-provider.js"; +import { parseHeadlessStream } from "../../src/headless-protocol.js"; +import { spawn } from "node:child_process"; +import path from "node:path"; +import fs from "node:fs"; +import os from "node:os"; + +function runCli( + args: string[], + env: Record, + timeoutMs = 20_000, +): Promise<{ stdout: string; stderr: string; code: number | null }> { + return new Promise((resolve, reject) => { + const cliPath = path.resolve(import.meta.dirname, "../../dist/index.js"); + const proc = spawn("node", [cliPath, ...args], { + env: { ...process.env, ...env }, + timeout: timeoutMs, + }); + let stdout = ""; + let stderr = ""; + proc.stdout.on("data", (d) => { stdout += d; }); + proc.stderr.on("data", (d) => { stderr += d; }); + proc.on("close", (code) => resolve({ stdout, stderr, code })); + proc.on("error", reject); + }); +} + +function writeCall(id: string, fileName: string) { + return { + id, + name: "write", + arguments: JSON.stringify({ path: fileName, content: "hi" }), + }; +} + +function shellCall(id: string, command: string) { + return { + id, + name: "shell", + arguments: JSON.stringify({ command }), + }; +} + +describe("Integration: bottleneck report (--bottleneck)", () => { + let server: FakeServer; + let tmpDir: string; + let sessionDir: string; + let baseEnv: Record; + + beforeAll(async () => { + server = await createFakeServer(); + tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), "oh-my-cli-bottleneck-")); + sessionDir = fs.mkdtempSync(path.join(os.tmpdir(), "oh-my-cli-bottleneck-sess-")); + baseEnv = { + OPENAI_API_KEY: "fake-key", + OPENAI_BASE_URL: server.url, + OPENAI_MODEL: "fake-model", + HOME: sessionDir, + }; + }); + + afterAll(async () => { + await server.close(); + fs.rmSync(tmpDir, { recursive: true, force: true }); + fs.rmSync(sessionDir, { recursive: true, force: true }); + }); + + beforeEach(() => { + server.requests.length = 0; + }); + + it("prints a bottleneck report after a text run only when requested", async () => { + server.setResponses([ + { type: "tool_calls", toolCalls: [shellCall("call_1", "echo hi")] }, + { type: "text", content: "Done" }, + ]); + const withReport = await runCli( + ["-p", "do work", "--bottleneck", "--approval-mode", "yolo", "--workspace", tmpDir], + baseEnv, + ); + expect(withReport.code).toBe(0); + expect(withReport.stdout).toContain("Bottleneck report (oh-my-cli.bottleneck v1)"); + expect(withReport.stdout).toContain("tool shell"); + + server.setResponses([ + { type: "tool_calls", toolCalls: [shellCall("call_1", "echo hi")] }, + { type: "text", content: "Done" }, + ]); + const plain = await runCli( + ["-p", "do work", "--approval-mode", "yolo", "--workspace", tmpDir], + baseEnv, + ); + expect(plain.code).toBe(0); + expect(plain.stdout).not.toContain("Bottleneck report (oh-my-cli.bottleneck v1)"); + }); + + it("emits a bottleneck event with a tool entry in the JSON stream", async () => { + server.setResponses([ + { type: "tool_calls", toolCalls: [shellCall("call_1", "echo hi")] }, + { type: "text", content: "Completed" }, + ]); + const r = await runCli( + ["-p", "do work", "--output", "json", "--bottleneck", "--approval-mode", "yolo", "--workspace", tmpDir], + baseEnv, + ); + expect(r.code).toBe(0); + + const recs = parseHeadlessStream(r.stdout); + const bn = recs.find((x) => x.type === "bottleneck"); + expect(bn).toBeDefined(); + if (bn?.type === "bottleneck") { + const report = bn.bottleneck; + expect(report.schema).toBe("oh-my-cli.bottleneck"); + expect(report.v).toBe(1); + expect(typeof report.elapsedMs).toBe("number"); + const shell = report.entries.find((e) => e.kind === "tool" && e.name === "shell"); + expect(shell).toBeDefined(); + expect(shell!.calls).toBe(1); + expect(shell!.wallMs).toBeGreaterThanOrEqual(0); + } + + // The terminal complete record is still present and matches the exit code. + const complete = recs.find((x) => x.type === "complete"); + if (complete?.type === "complete") expect(complete.exitCode).toBe(r.code); + }); + + it("ranks a deliberately slow tool above a fast one by wall-time", async () => { + server.setResponses([ + { type: "tool_calls", toolCalls: [writeCall("call_1", "fast.txt")] }, + { type: "tool_calls", toolCalls: [shellCall("call_2", "sleep 0.3")] }, + { type: "text", content: "done" }, + ]); + const r = await runCli( + ["-p", "do work", "--output", "json", "--bottleneck", "--approval-mode", "yolo", "--workspace", tmpDir], + baseEnv, + ); + expect(r.code).toBe(0); + + const recs = parseHeadlessStream(r.stdout); + const bn = recs.find((x) => x.type === "bottleneck"); + expect(bn).toBeDefined(); + if (bn?.type === "bottleneck") { + const report = bn.bottleneck; + const shell = report.entries.find((e) => e.kind === "tool" && e.name === "shell"); + const write = report.entries.find((e) => e.kind === "tool" && e.name === "write"); + expect(shell).toBeDefined(); + expect(write).toBeDefined(); + // The slow shell command dominates wall-time and ranks first. + expect(report.entries[0].name).toBe("shell"); + expect(shell!.wallMs).toBeGreaterThan(write!.wallMs); + } + expect(fs.existsSync(path.join(tmpDir, "fast.txt"))).toBe(true); + }); + + it("keeps secret-shaped tool arguments out of the bottleneck report", async () => { + const secret = "sk-abcdefghijklmnopqrstuvwxyz1234567890"; + server.setResponses([ + { + type: "tool_calls", + toolCalls: [{ id: "call_1", name: "write", arguments: JSON.stringify({ path: "leak.txt", content: secret }) }], + }, + { type: "text", content: "done" }, + ]); + const r = await runCli( + ["-p", "do work", "--output", "json", "--bottleneck", "--approval-mode", "yolo", "--workspace", tmpDir], + baseEnv, + ); + expect(r.code).toBe(0); + + const recs = parseHeadlessStream(r.stdout); + const bn = recs.find((x) => x.type === "bottleneck"); + expect(bn).toBeDefined(); + // The report is metadata only: the secret-bearing argument never appears in it. + expect(JSON.stringify(bn)).not.toContain(secret); + }); + + it("reports an empty inventory for a run with no tool activity", async () => { + server.setResponses([{ type: "text", content: "just text" }]); + const r = await runCli( + ["-p", "hello", "--bottleneck", "--workspace", tmpDir], + baseEnv, + ); + expect(r.code).toBe(0); + expect(r.stdout).toContain("Bottleneck report (oh-my-cli.bottleneck v1)"); + expect(r.stdout).toContain("(no tool or approval activity recorded)"); + }); +}); diff --git a/tests/unit/run-bottleneck.test.ts b/tests/unit/run-bottleneck.test.ts new file mode 100644 index 0000000..b6c1428 --- /dev/null +++ b/tests/unit/run-bottleneck.test.ts @@ -0,0 +1,139 @@ +import { describe, it, expect } from "vitest"; +import { + createBottleneckCollector, + formatBottleneckReport, + BOTTLENECK_REPORT_SCHEMA, + BOTTLENECK_REPORT_VERSION, +} from "../../src/run-bottleneck.js"; + +describe("createBottleneckCollector / build", () => { + it("builds a deterministic report ranked by wall-time (desc)", () => { + const { collector, build } = createBottleneckCollector(); + collector.recordTool("write", 100); + collector.recordTool("shell", 5000); + collector.recordTool("read", 50); + const report = build(6000); + + expect(report.schema).toBe(BOTTLENECK_REPORT_SCHEMA); + expect(report.v).toBe(BOTTLENECK_REPORT_VERSION); + expect(report.elapsedMs).toBe(6000); + expect(report.truncated).toBe(0); + expect(report.entries.map((e) => e.name)).toEqual(["shell", "write", "read"]); + expect(report.entries[0]).toEqual({ kind: "tool", name: "shell", wallMs: 5000, calls: 1 }); + }); + + it("records tool execution and approval gate wall-time as distinct kinds", () => { + const { collector, build } = createBottleneckCollector(); + collector.recordTool("shell", 200); + collector.recordApproval("shell", 3000); + const report = build(3200); + + const approval = report.entries.find((e) => e.kind === "approval"); + const tool = report.entries.find((e) => e.kind === "tool"); + expect(approval).toEqual({ kind: "approval", name: "shell", wallMs: 3000, calls: 1 }); + expect(tool).toEqual({ kind: "tool", name: "shell", wallMs: 200, calls: 1 }); + // The approval gate dominated, so it ranks first. + expect(report.entries[0].kind).toBe("approval"); + }); + + it("sums wall-time and call counts across repeated calls to the same tool", () => { + const { collector, build } = createBottleneckCollector(); + collector.recordTool("read", 10); + collector.recordTool("read", 20); + collector.recordTool("read", 30); + const report = build(100); + expect(report.entries).toEqual([{ kind: "tool", name: "read", wallMs: 60, calls: 3 }]); + }); + + it("breaks ties by call count, then name, then kind for stable output", () => { + const { collector, build } = createBottleneckCollector(); + collector.recordTool("beta", 100); // beta: 100ms, 1 call + collector.recordTool("alpha", 50); // alpha: 50ms, 1 call + collector.recordTool("alpha", 50); // alpha: 100ms total, 2 calls + const report = build(200); + // Equal wall-time (100ms each); alpha has more calls, so it ranks first. + expect(report.entries[0].wallMs).toBe(100); + expect(report.entries[1].wallMs).toBe(100); + expect(report.entries.map((e) => e.name)).toEqual(["alpha", "beta"]); + }); + + it("bounds the ranked head and reports how many entries were truncated", () => { + const { collector, build } = createBottleneckCollector(); + for (let i = 0; i < 20; i++) { + collector.recordTool(`tool${String(i).padStart(2, "0")}`, (i + 1) * 10); + } + const report = build(10000); + expect(report.entries).toHaveLength(16); + expect(report.truncated).toBe(4); + // The highest wall-time tool ranks first. + expect(report.entries[0].name).toBe("tool19"); + }); + + it("treats non-finite or negative wall-time as zero but still counts the call", () => { + const { collector, build } = createBottleneckCollector(); + collector.recordTool("write", Number.NaN); + collector.recordTool("write", -5); + const report = build(100); + expect(report.entries).toEqual([{ kind: "tool", name: "write", wallMs: 0, calls: 2 }]); + }); + + it("sanitizes control characters out of a tool name", () => { + const { collector, build } = createBottleneckCollector(); + collector.recordTool("bad\u0000name\u001f", 100); + const report = build(100); + expect(report.entries[0].name).toBe("bad_name_"); + expect(report.entries[0].name).not.toMatch(/[\u0000-\u001f\u007f]/); + }); + + it("clamps a negative elapsed time to zero", () => { + const { build } = createBottleneckCollector(); + expect(build(-50).elapsedMs).toBe(0); + }); + + it("reports an empty inventory when nothing was recorded", () => { + const { build } = createBottleneckCollector(); + const report = build(1000); + expect(report.entries).toEqual([]); + expect(report.truncated).toBe(0); + expect(report.elapsedMs).toBe(1000); + }); +}); + +describe("formatBottleneckReport", () => { + it("renders a ranked, human-readable report", () => { + const { collector, build } = createBottleneckCollector(); + collector.recordTool("shell", 8200); + collector.recordTool("shell", 100); + collector.recordApproval("write", 500); + const text = formatBottleneckReport(build(9000)); + expect(text).toContain(`Bottleneck report (${BOTTLENECK_REPORT_SCHEMA} v${BOTTLENECK_REPORT_VERSION})`); + expect(text).toContain("elapsed: 9.0s"); + expect(text).toContain("tool shell"); + expect(text).toContain("8.3s"); + expect(text).toContain("(2 calls)"); + expect(text).toContain("approval write"); + }); + + it("renders an explicit empty-inventory line when nothing was recorded", () => { + const { build } = createBottleneckCollector(); + const text = formatBottleneckReport(build(1000)); + expect(text).toContain("(no tool or approval activity recorded)"); + }); + + it("reports the truncated count beyond the head bound", () => { + const { collector, build } = createBottleneckCollector(); + for (let i = 0; i < 18; i++) collector.recordTool(`t${i}`, (i + 1) * 10); + const text = formatBottleneckReport(build(5000)); + expect(text).toContain("truncated: 2 more entries beyond the head bound"); + }); + + it("carries no channel for prompt/tool/file content (metadata only)", () => { + const { collector, build } = createBottleneckCollector(); + // Even if a tool name somehow carried sensitive-looking text, the report only + // surfaces the (sanitized) name and numbers — never arguments or content. + collector.recordTool("write", 100); + const text = formatBottleneckReport(build(100)); + expect(text).not.toContain("content"); + expect(text).not.toContain("secret"); + }); +});