feat(cli): add an opt-in tool/approval wall-time bottleneck report for unattended runs (#220)

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<string, unknown>) => Promise<boolean>,
   preToolUseHooks: readonly PreToolUseHook[],
+  bottleneck: BottleneckCollector | undefined,
   turnImages?: TurnImageCollector,
 ): Promise<ToolResult> {
   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 };

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 & {

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 <usd>",
     "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

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<string, Accumulator>();
+  const approval = new Map<string, Accumulator>();
+  const bump = (map: Map<string, Accumulator>, 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<string, Accumulator>,
+  approval: Map<string, Accumulator>,
+): 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");
+}