SLOPSHOPPER

agent-profiler

Execution profiler for Claude Code: model wait vs tools vs subagents, live, with OTLP export

newpaneguardcommandtoaststatus
A shopper browsing a rack in a slop shop
Preview · a replayed session in a sandbox
claude · ~/work/app · agent-profiler
│ ┃ Agent Profiler ✕ › fix the failing auth test and add an audit log call │ ┃ 10ms agent time · 1 turn(s) │ ┃ model ░░░░░░░░░░░░░░░░░░░░ 0% ⏺ Read(src/auth.ts) │ ┃ tools ██░░░░░░░░░░░░░░░░░░ 10% ⎿ Read 6 lines │ ┃ subagents ░░░░░░░░░░░░░░░░░░░░ 0% ⏺ Update(src/auth.ts) │ ┃ engine/other ██████████████████░░ 90% ⎿ Added 2 lines, removed 1 line │ ┃ ⏺ Bash(bun test) │ ┃ Running ⎿ 3 pass, 1 fail │ ┃ idle │ ┃ ● Done. refresh now rejects expired claims and logs an audit event. │ ┃ Slowest tools │ ┃ 1ms Read /work/app/src/auth.ts ✻ Worked for 42s · done 4:20 PM │ ┃ 0ms Grep /work/app/src │ ┃ 0ms Edit /work/app/src/auth.ts › /profile │ ┃ 0ms Write /work/app/src/audit.ts ⎿ agent-profiler: Agent Profiler · session · 1 turn(s) · 10ms agen │ ┃ 0ms Write /work/app/src/cache.ts ⎿ agent-profiler: │ ⎿ agent-profiler: Where the time went (exclusive; adds up to agent │ ⎿ agent-profiler: Model response wait 0ms 0% ░░░░░░░ │ ⎿ agent-profiler: Tools 1ms 10% █░░░░░░ │ ⎿ agent-profiler: Subagents (blocking) 0ms 0% ░░░░░░░ │ │ ────────────────────────────────────────────────────────────────────────────────────────────────────────────────────── › ? for shortcuts

Draws

Pane · Agent Profiler
10ms agent time · 1 turn(s) model ░░░░░░░░░░░░░░░░░░░░ 0% tools ██░░░░░░░░░░░░░░░░░░ 10% subagents ░░░░░░░░░░░░░░░░░░░░ 0% engine/other ██████████████████░░ 90% Running idle Slowest tools 1ms Read /work/app/src/auth.ts 0ms Grep /work/app/src 0ms Edit /work/app/src/auth.ts 0ms Write /work/app/src/audit.ts 0ms Write /work/app/src/cache.ts
README

agent-profiler

A Claude Code mod that shows where an agent session's time goes: model wait, tool execution, subagents, test runs, repeated file reads, and engine overhead. It exports the session as an OTLP trace so you can open it in Jaeger or Grafana Tempo.

Requires Claude Code 2.1.287 or later (desktop 2.1.286). Event shapes follow the 2.1.292 type declarations; the end-to-end probe (claude -p), the Jaeger import and the tests ran on Claude Code 2.1.280 with CLAUDE_CODE_ENABLE_FUNCTION_HOOKS=1.

What it shows

Every span and metric carries agent_profiler.observability. The mod never claims to measure "inference time"; it reports what the client can observe.

GradeMeaningExample
measuredValue measured and handed over by the engineclassic.PostToolUse.duration_ms (tool execution time)
observedInterval the mod timed in-process from event boundariesturn.step send, first chunk, end; tool.call entry to return
reportedValue reported by the APIusage.output_tokens, cache read/creation tokens
inferredRemainder computed from the values abovetool wait = wall - exec; engine overhead = turn - (request + tool)

Time categories (one context is the main loop or one subagent loop):

turn (turn.start -> turn.complete)                                   observed
+- model.request (turn.step: next call -> stream end)                observed
|   +- ttft            : send -> first chunk (network + queueing + prefill, not separable)
|   +- thinking.stream : first thinking chunk -> last thinking chunk
|   +- output.stream   : first text/tool chunk -> end
|   + usage (tokens)                                                 reported
+- tool (tool.call: entry -> next return)                            observed
|   +- exec = duration_ms                                            measured
|   +- wait = wall - exec                                            inferred
|        approval wait if tool.check said 'ask', otherwise tool.overhead
+- subagent (classic.SubagentStart -> classic.SubagentStop)          observed
|   +- (recursive) model.request / tool
+- engine.overhead = turn - (model.request U tool U blocking subagent)   inferred
idle: turn.complete -> next turn.start (excluded from agent time)

TTFT and stream times are response-wait times observed at the client, not time the model spent computing. Engine retries are absorbed into one turn.step, so they appear as a longer TTFT.

Terminal API failures (including usage/rate limits) close the affected turn and its open requests and tools at classic.StopFailure. Waiting for the limit to reset is excluded. Independent background agents keep their own timers; a failed subagent closes only its own context. turn.complete also settles any requests or tools still open in that turn.

Install

/plugin marketplace add YeonwooSung/my-claude-code-mods
/plugin install agent-profiler@my-claude-code-mods

During development, load the folder directly:

claude --plugin-dir ./agent-profiler

Mods are on by default from Claude Code 2.1.287 (desktop 2.1.286). Earlier builds need CLAUDE_CODE_ENABLE_FUNCTION_HOOKS=1 in the environment of the claude process; 2.1.287+ ignores it.

Commands

CommandWhat it does
/profileMarkdown report of the whole session (time categories, tool/model stats, repeated reads, subagents, findings)
/profile turnThe same report for the last turn only
/profile-paneOpens the live pane (in-flight requests and tools, category bars, recent findings)
/profile-exportWrites a full snapshot of the session as OTLP JSON chunk files and POSTs each if an endpoint is configured; returns one line per file written and the POST result

A status line (model 61% - tools 28% - running: Bash npm test 14s) is updated at most twice a second.

Settings

Set in the /plugin settings menu or in settings pluginConfigs.

KeyDefaultMeaning
otlpEndpoint""OTLP/HTTP base URL, e.g. http://localhost:4318. The mod POSTs to {endpoint}/v1/traces. Empty means file only.
outputDir~/.claude/agent-profilerWhere trace files are written, one folder per session (see below).
exportCommandTextfalseInclude turn prompts, Bash command lines and search patterns in exported traces (files and POSTs), with obvious secrets redacted.

Trace files

Files go to <outputDir>/<sessionId>/. <loadId> is a base-36 timestamp taken when the mod loads, so a hot reload or --resume starts new file names and never overwrites earlier ones.

FileWrittenContents
<loadId>-<seq>.otlp.json (seq = 0001, 0002, ...)after every turn.complete, and at session.endPer-turn batches hold only the turns, requests, tools and subagents that finished since the previous batch. The session.end batch holds everything not written yet (open spans marked agent_profiler.incomplete) plus the session root span.
<loadId>-full-<n>.otlp.jsonby /profile-exportA full snapshot of what is in memory, root and open spans included. A later /profile-export in the same load rewrites these.

Each file is at most 3.5 MiB; a larger batch or snapshot is split into several files (and several POSTs). If otlpEndpoint is set, each batch is POSTed after it is written. The session.end POST gets what is left of Claude Code's short exit budget (1.5 s at most) and is dropped past it; the file is written first. Nothing is written until the session id is known. A failed automatic write or POST is shown once as a toast.

The numbered batches together are the whole session; the full files are a separate snapshot, so send one set or the other, not both.

What is exported

Per span: name, start/end time, parent, status, and these attributes.

  • Resource: service.name=claude-code, session.id, agent_profiler.version.
  • Turn: agent_profiler.turn.reason; agent_profiler.turn.prompt (first 120 characters) only with exportCommandText.
  • Model request (chat <model>): gen_ai.request.model, gen_ai.response.model, input/output token counts, cache read/creation tokens, finish reason, effort, agent_profiler.ttft_ms; child spans model.ttft, model.thinking_stream, model.output_stream.
  • Tool (execute_tool <tool>): tool name and call id, agent_profiler.exec_ms, wait_ms, permission decision, fs.path and fs.range (file tools), search.pattern (Glob/Grep, redacted and only with exportCommandText), bash.category, launched agent id; agent_profiler.bash.command only with exportCommandText; child spans tool.exec and tool.approval_wait / tool.overhead.
  • Subagent (invoke_agent <type>): agent id and type, whether it ran async.
  • Every span: agent_profiler.category, agent_profiler.observability, agent_profiler.incomplete when still open.

With exportCommandText on, prompts and commands are redacted first: Authorization: ... header values, Bearer <token>, --password <x> / --password=<x>, mysql ... -p<password>, and NAME=value where NAME contains KEY, TOKEN, SECRET or PASSWORD. This catches common shapes only, so leave the setting off when traces leave your machine and commands may carry secrets. File paths and search patterns are always exported.

Jaeger / Tempo

traceId is the session UUID without dashes and spanId is a deterministic hash, so re-sending the same session yields the same spans.

Jaeger:

docker compose -f agent-profiler/examples/jaeger/docker-compose.yml up -d
# send a session's numbered batches (leave out the -full- snapshot files)
for f in $HOME/.claude/agent-profiler/<sessionId>/*.otlp.json; do
  case "$f" in *-full-*) continue ;; esac
  curl -sS -X POST -H 'content-type: application/json' --data @"$f" http://localhost:4318/v1/traces
done

To send the latest /profile-export snapshot instead, loop over *-full-*.otlp.json of one load id.

Open http://localhost:16686 in a browser and pick the service claude-code. Stop it with:

docker compose -f agent-profiler/examples/jaeger/docker-compose.yml down

Or set otlpEndpoint to http://localhost:4318 and the mod sends the trace itself.

Grafana Tempo accepts the same OTLP/HTTP endpoint (port 4318 by default), so use the same curl or otlpEndpoint value pointing at your Tempo (or OpenTelemetry Collector) host.

Span names follow the GenAI semantic conventions: chat <model>, execute_tool <tool>, invoke_agent <type>, with agent_profiler.* attributes for the rest.

Behavior by environment

EnvironmentHooks, recording, exportPane / status line/profile text
Terminal claudeyesyesyes
Desktop Code tabyesyesyes
VS Code chat panelyesno (drawing is not shown)yes
claude -p / SDKyesnoyes

Reports, panels and display labels mask supported credential formats before truncation; this does not change the underlying analysis. Existing saved files are not rewritten.

Limitations

  • Time inside the model server (queueing, prefill, decoding, GPU) cannot be broken down. TTFT lumps network, queueing and prefill together.
  • Files modified through Bash are not visible to the repeated-read detection.
  • Hot reload resets in-memory state: /profile and the pane start over from the reload. Batches already written stay on disk, and the new load writes under a new load id.
  • Memory is capped at 20,000 requests and tool calls. Past it, whole finished turns are dropped, oldest first, with their requests, tools and subagents; they were already written as batches. The report then says "covers the last N turns; M older turns dropped".
  • turn.start fires only for main-loop turns. Subagents have no turn spans of their own: their chat and execute_tool spans hang directly under invoke_agent.
  • Background (async) subagents keep running after the Agent tool returns. Their invoke_agent span is still a child of execute_tool Agent but outlives it, and the completion notification starts an extra main turn.
  • Event shapes follow the 2.1.292 type declarations; the end-to-end probe, Jaeger import and tests ran on 2.1.280 with CLAUDE_CODE_ENABLE_FUNCTION_HOOKS=1. Other versions may differ.

Tests

cd agent-profiler
CLAUDE_CODE_ENABLE_FUNCTION_HOOKS=1 claude plugin test
claude plugin validate .

(The variable is only needed before 2.1.287.)

Type check (from the repository root):

npx -y -p typescript@5 tsc -p agent-profiler --noEmit

tsconfig.json includes .claude-plugin/types, where Claude Code writes claude-code/index.d.ts each time it loads the mod (the folder is git-ignored). Before the first load, copy the declarations there yourself, e.g. from the plugin-authoring skill's types/claude-code.d.ts to agent-profiler/.claude-plugin/types/claude-code/index.d.ts.

Secret masking is best-effort and covers credential flags, sensitive headers, URL passwords, curl/mysql credentials and common credential fields in JSON strings. It does not sanitize snapshot file contents or retroactively rewrite saved files. Review files before sharing.

Source 12 files
hooks/register.tsx 364 lines
1import type { EngineInterface, PluginOptions, Register, Timer } from 'claude-code'
2
3import { summarize, type Scope, type Summary } from './core/analyze.ts'
4import { SummaryCache } from './core/cache.ts'
5import { MAX_EXPORT_BYTES, pendingKeys, splitRequest } from './core/export.ts'
6import { toOtlp, type OtlpRequest } from './core/otlp.ts'
7import { Profiler, summarizeInput, toolOutcome } from './core/profiler.ts'
8import { paneLines, renderReport, statusLine } from './core/report.ts'
9
10const VERSION = '0.1.5'
11const PANE = 'agent-profiler'
12const COMMANDS = [
13  { name: 'profile', description: "Show where this session's time went (model wait, tools, subagents, tests, re-reads); 'turn' for the last turn" },
14  { name: 'profile-pane', description: 'Open the live Agent Profiler pane' },
15  { name: 'profile-export', description: "Write this session's trace as OTLP JSON and send it to the configured endpoint" },
16]
17// Names this module load's files, so a hot reload or --resume never overwrites earlier batches.
18const LOAD_ID = Date.now().toString(36)
19
20let profiler = new Profiler()
21let lastPaint = 0
22let paintQueuedAt = 0
23let anonymous = 0
24let batchSeq = 0
25let ticker: Timer | undefined
26// Records already written as a per-turn batch, for the current profiler.
27let exported = new Set<string>()
28const toasted = new Set<string>()
29const summaries = new SummaryCache()
30
31// Recording must never break the session: every bookkeeping step goes through here.
32function safe<T>(fn: () => T): void {
33  try {
34    fn()
35  } catch {
36    // dropped on purpose
37  }
38}
39
40// Share a paint bucket while live; completed sessions keep their version-only cache.
41function cachedSummary(scope: Scope = 'session'): Summary {
42  return summaries.get(profiler, scope, Date.now())
43}
44
45function paintNow($: EngineInterface): void {
46  const now = Date.now()
47  lastPaint = now
48  safe(() => {
49    $.ui.status(statusLine(cachedSummary(), profiler.running(now)))
50    $.ui.invalidate('ui.render')
51  })
52}
53
54// Hooks never paint on their own path: a paint is queued behind the event (at most one pending).
55function paint($: EngineInterface, force = false): void {
56  const now = Date.now()
57  if (paintQueuedAt && now - paintQueuedAt < 2_000) return // a refused timer must not block paints forever
58  if (!force && now - lastPaint < 500) return
59  paintQueuedAt = now
60  try {
61    $.clock.after(0, () => {
62      paintQueuedAt = 0
63      paintNow($)
64    })
65  } catch {
66    paintQueuedAt = 0
67  }
68}
69
70function useProfiler(next: Profiler): void {
71  profiler = next
72  exported = new Set()
73}
74
75// Failures of automatic saves surface once each, as a toast; the status line is the profiler's own.
76function warn($: EngineInterface, message: string): void {
77  if (toasted.has(message)) return
78  toasted.add(message)
79  safe(() => $.ui.toast(`agent-profiler: ${message}`))
80}
81
82async function sessionIdOf($: EngineInterface, p: Profiler): Promise<string | undefined> {
83  if (p.sessionId !== 'unknown') return p.sessionId
84  try {
85    p.adoptSessionId(await $.session.id())
86  } catch {
87    // still unknown
88  }
89  return p.sessionId === 'unknown' ? undefined : p.sessionId
90}
91
92async function outputDir($: EngineInterface, options: PluginOptions): Promise<string> {
93  const dir = (String(options.outputDir ?? '').trim() || '~/.claude/agent-profiler').replace(/\/+$/, '')
94  if (!/^~(?=\/|$)/.test(dir)) return dir
95  return dir.replace(/^~/, (await $.env.get('HOME')) ?? '.')
96}
97
98function endpointOf(options: PluginOptions): string {
99  return String(options.otlpEndpoint ?? '').trim().replace(/\/+$/, '')
100}
101
102// One POST; with a deadline it gives up when the deadline passes or the signal aborts.
103async function post($: EngineInterface, endpoint: string, body: string, deadline?: { at: number; signal?: AbortSignal }): Promise<string | undefined> {
104  const request = $.http.fetch(`${endpoint}/v1/traces`, { method: 'POST', headers: { 'content-type': 'application/json' }, body })
105  request.catch(() => undefined) // a late failure after a timeout is nobody's business
106  try {
107    let answer
108    if (deadline) {
109      const left = deadline.at - Date.now()
110      if (left <= 0) return 'no time left before exit'
111      const timeout = $.clock.sleep(left, deadline.signal ? { signal: deadline.signal } : undefined).then(() => undefined)
112      answer = await Promise.race([request, timeout])
113      if (!answer) return `no answer within ${left}ms`
114    } else {
115      answer = await request
116    }
117    return answer.ok ? undefined : `${endpoint} answered ${answer.status}`
118  } catch (error) {
119    return String(error)
120  }
121}
122
123type ExportMode = 'batch' | 'final' | 'full'
124type ExportResult = { notes: string[]; failures: string[] }
125
126// batch: records finished since the last batch. final: everything not exported yet, open records
127// marked incomplete, and the session root. full: a whole snapshot (/profile-export), in chunk files.
128async function exportTrace($: EngineInterface, options: PluginOptions, mode: ExportMode, deadline?: { at: number; signal?: AbortSignal }): Promise<ExportResult> {
129  const result: ExportResult = { notes: [], failures: [] }
130  const p = profiler
131  const done = exported
132  const sessionId = await sessionIdOf($, p)
133  if (sessionId === undefined) {
134    result.failures.push('session id not known yet; nothing written')
135    return result
136  }
137  const dir = `${await outputDir($, options)}/${sessionId}`
138
139  // From snapshot to claim nothing awaits, so overlapping exports never pick the same records.
140  const snap = p.snapshot(Date.now())
141  const commandText = options.exportCommandText === true
142  let claimed: string[] = []
143  let request: OtlpRequest
144  if (mode === 'full') {
145    request = toOtlp(snap, VERSION, { commandText })
146  } else {
147    claimed = pendingKeys(snap, done, mode === 'final')
148    const keys = new Set(claimed)
149    for (const key of claimed) done.add(key)
150    request = toOtlp(snap, VERSION, { include: key => keys.has(key), root: mode === 'final', commandText })
151  }
152  const parts = splitRequest(request, MAX_EXPORT_BYTES)
153  if (parts.length === 0) {
154    if (mode === 'full') result.notes.push('nothing recorded yet')
155    return result
156  }
157
158  const bodies: string[] = []
159  try {
160    for (const [n, part] of parts.entries()) {
161      const name = mode === 'full' ? `${LOAD_ID}-full-${n + 1}` : `${LOAD_ID}-${String((batchSeq += 1)).padStart(4, '0')}`
162      const path = `${dir}/${name}.otlp.json`
163      const body = JSON.stringify(part)
164      await $.fs.write(path, body)
165      bodies.push(body)
166      result.notes.push(`wrote ${path}`)
167    }
168  } catch (error) {
169    for (const key of claimed) done.delete(key) // retried with the next batch
170    result.failures.push(`could not write to ${dir}: ${String(error)}`)
171    return result
172  }
173
174  const endpoint = endpointOf(options)
175  if (endpoint) {
176    let failed = 0
177    for (const body of bodies) {
178      const reason = await post($, endpoint, body, deadline)
179      if (reason !== undefined) {
180        failed += 1
181        result.failures.push(`POST failed: ${reason}`)
182        break
183      }
184    }
185    if (failed === 0) result.notes.push(`sent to ${endpoint}${bodies.length > 1 ? ` in ${bodies.length} requests` : ''}`)
186  }
187  return result
188}
189
190function autoExport($: EngineInterface, options: PluginOptions): void {
191  exportTrace($, options, 'batch').then(
192    r => r.failures.forEach(f => warn($, f)),
193    error => warn($, `could not save the trace: ${String(error)}`),
194  )
195}
196
197export const register: Register = (on, options) => {
198  on('session.start', async ($, e, next) => {
199    try {
200      useProfiler(new Profiler(await $.session.id()))
201    } catch {
202      useProfiler(new Profiler())
203    }
204    // Each step on its own: a refusal here must not keep the session from starting.
205    for (const command of COMMANDS) {
206      try {
207        await $.command.register(command)
208      } catch {
209        // the command stays unavailable
210      }
211    }
212    safe(() => ticker?.cancel())
213    ticker = undefined
214    try {
215      ticker = $.clock.every(1_000, () => {
216        if (profiler.running(Date.now()).length > 0) paintNow($)
217      })
218    } catch {
219      // no live refresh
220    }
221    return next(e)
222  })
223
224  on('turn.start', async ($, e, next) => {
225    const t = Date.now()
226    try {
227      const id = await $.session.id()
228      if (profiler.sessionId === 'unknown') profiler.adoptSessionId(id) // loaded mid-session
229      else if (id !== profiler.sessionId) useProfiler(new Profiler(id)) // a /clear starts a new session id
230    } catch {
231      // keep the current profiler
232    }
233    safe(() => profiler.turnStart(t, e.turnId, e.text))
234    paint($, true)
235    return next(e)
236  })
237
238  on('turn.complete', async ($, e, next) => {
239    safe(() => profiler.turnComplete(Date.now(), e.turnId, e.reason))
240    paint($, true)
241    safe(() => $.clock.after(0, () => autoExport($, options)))
242    return next(e)
243  })
244
245  on('classic.StopFailure', async ($, e, next) => {
246    safe(() => profiler.stopFailure(Date.now(), e.agent_id))
247    paint($, true)
248    safe(() => $.clock.after(0, () => autoExport($, options)))
249    return next(e)
250  })
251
252  on('turn.step', async function* ($, e, next) {
253    let id = ''
254    safe(() => {
255      id = profiler.stepStart(Date.now(), { turnId: e.turnId, index: e.index, model: e.model, effort: e.effort, agentId: e.agentId })
256    })
257    paint($)
258    try {
259      for await (const chunk of next(e)) {
260        safe(() => {
261          profiler.stepChunk(Date.now(), id, chunk.kind)
262          if (chunk.kind === 'stop') profiler.stepUsage(id, chunk.usage, chunk.stopReason)
263        })
264        yield chunk
265      }
266    } finally {
267      safe(() => profiler.stepEnd(Date.now(), id))
268      paint($)
269    }
270  })
271
272  on('tool.call', async ($, e, next) => {
273    anonymous += 1
274    const id = e.tool_use_id ?? `anonymous-${anonymous}`
275    const tool = String(e.tool)
276    safe(() => profiler.toolStart(Date.now(), { id, tool, agentId: e.agentId, input: summarizeInput(tool, e as unknown as Record<string, unknown>) }))
277    paint($)
278    try {
279      const answer = await next(e)
280      safe(() => profiler.toolEnd(Date.now(), id, toolOutcome(answer)))
281      return answer
282    } catch (error) {
283      safe(() => profiler.toolEnd(Date.now(), id, { denied: false, isError: true }))
284      throw error
285    } finally {
286      paint($)
287    }
288  }).catch(($, e, next) => next(e))
289
290  on('tool.check', async ($, e, next) => {
291    const verdict = await next(e)
292    const id = e.tool_use_id
293    if (id !== undefined) safe(() => profiler.toolCheck(id, verdict.decision))
294    return verdict
295  }).catch(($, e, next) => next(e))
296
297  on('classic.PostToolUse', async ($, e, next) => {
298    safe(() => profiler.toolDuration(e.tool_use_id, e.duration_ms))
299    return next(e)
300  })
301
302  on('classic.PostToolUseFailure', async ($, e, next) => {
303    safe(() => profiler.toolDuration(e.tool_use_id, e.duration_ms))
304    return next(e)
305  })
306
307  on('classic.SubagentStart', async ($, e, next) => {
308    safe(() => profiler.subagentStart(Date.now(), e.agent_id, e.agent_type))
309    paint($, true)
310    return next(e)
311  })
312
313  on('classic.SubagentStop', async ($, e, next) => {
314    safe(() => profiler.subagentStop(Date.now(), e.agent_id))
315    paint($, true)
316    return next(e)
317  })
318
319  on('session.end', async ($, e, next) => {
320    try {
321      // Files first; the POST gets what is left of the shared exit budget, 1.5s at most.
322      const budget = next.budget.remainingMs
323      const at = Date.now() + Math.max(0, Math.min(1_500, budget - 250))
324      await exportTrace($, options, 'final', { at, signal: next.signal })
325    } catch {
326      // nothing left to tell
327    }
328    return next(e)
329  })
330
331  on('command.run', { command: 'profile' }, async ($, e) => {
332    const scope = e.args.trim() === 'turn' ? 'turn' : 'session'
333    return { text: renderReport(summarize(profiler.snapshot(Date.now()), scope)) }
334  })
335
336  on('command.run', { command: 'profile-pane' }, async $ => {
337    await $.ui.open({ id: PANE, title: 'Agent Profiler' })
338    return { text: 'Agent Profiler pane opened (shown in the terminal and the desktop app).' }
339  })
340
341  on('command.run', { command: 'profile-export' }, async $ => {
342    try {
343      const r = await exportTrace($, options, 'full')
344      return { text: [...r.notes, ...r.failures].join('\n') }
345    } catch (error) {
346      return { text: `export failed: ${String(error)}` }
347    }
348  })
349
350  on('ui.render', { component: 'Pane', requestId: PANE }, async ($, e) => {
351    const { Box, Text } = $.ui.resolve(e)
352    const lines = paneLines(cachedSummary(), profiler.running(Date.now()), e.props.bodyColumns ?? 60)
353    return (
354      <Box flexDirection="column">
355        {lines.map(line => (
356          <Text bold={line.bold} dimColor={line.dim}>
357            {line.text || ' '}
358          </Text>
359        ))}
360      </Box>
361    )
362  })
363}
364
hooks/core/analyze.ts 344 lines
1import { classifyCommand, type BashCategory } from './classify.ts'
2import { clip, fmtMs, pct } from './format.ts'
3import { MAIN, isAgentTool, toolLabel } from './profiler.ts'
4import type { Snapshot, ToolRec } from './types.ts'
5
6export type Interval = [number, number]
7export type Category = 'model' | 'subagent' | 'tool' | 'engine'
8export type Scope = 'session' | 'turn'
9
10export type Summary = {
11  scope: Scope
12  turns: number
13  wallMs: number
14  exclusive: Record<Category, number>
15  model: {
16    requests: number
17    ttftAvg: number
18    ttftP95: number
19    thinkingMs: number
20    outputMs: number
21    inputTokens: number
22    cacheReadTokens: number
23    outputTokens: number
24    tokensPerSec: number | null
25  }
26  tools: {
27    calls: number
28    sumMs: number
29    unionMs: number
30    execMs: number
31    permissionMs: number
32    // Approval wait as a share of agent time: the union of the waits inside main turns, so at most 1.
33    permissionShare: number
34    overheadMs: number
35    errors: number
36    denied: number
37    byTool: { tool: string; calls: number; ms: number }[]
38    slowest: { tool: string; label: string; ms: number; waitMs: number; ctx: string }[]
39  }
40  // testMs sums every test run; testShare is the union of test execution inside main turns over agent time (≤ 1).
41  bash: { byCategory: { category: BashCategory; calls: number; ms: number }[]; testMs: number; testShare: number }
42  reads: { path: string; reads: number; redundant: number }[]
43  agents: { id: string; agentType: string; wallMs: number; modelMs: number; toolMs: number; requests: number; tools: number; blocking: boolean; done: boolean }[]
44  findings: string[]
45  incomplete: number
46  droppedTurns: number
47  droppedSpans: number
48}
49
50const WRITE_TOOLS = new Set(['Write', 'Edit', 'MultiEdit', 'NotebookEdit'])
51const PRIORITY: Category[] = ['model', 'subagent', 'tool']
52
53// Sorted, disjoint cover of the intervals.
54export function mergeIntervals(intervals: Interval[]): Interval[] {
55  const sorted = intervals.filter(([a, b]) => b > a).sort((x, y) => x[0] - y[0])
56  const out: Interval[] = []
57  for (const [a, b] of sorted) {
58    const last = out[out.length - 1]
59    if (last && a <= last[1]) last[1] = Math.max(last[1], b)
60    else out.push([a, b])
61  }
62  return out
63}
64
65export function unionLength(intervals: Interval[]): number {
66  return mergeIntervals(intervals).reduce((sum, [a, b]) => sum + b - a, 0)
67}
68
69// Length of (∪ intervals) ∩ (∪ windows).
70export function overlapLength(intervals: Interval[], windows: Interval[]): number {
71  const xs = mergeIntervals(intervals)
72  const ws = mergeIntervals(windows)
73  let total = 0
74  for (let i = 0, j = 0; i < xs.length && j < ws.length; ) {
75    const x = xs[i] as Interval
76    const w = ws[j] as Interval
77    total += Math.max(0, Math.min(x[1], w[1]) - Math.max(x[0], w[0]))
78    if (x[1] < w[1]) i += 1
79    else j += 1
80  }
81  return total
82}
83
84// Sweep line over the window: at every moment the highest-priority active category gets the time,
85// and moments with nothing active are engine time. O(n log n) in the number of intervals.
86export function attribute(window: Interval, tagged: { cat: Category; iv: Interval }[]): Record<Category, number> {
87  const out: Record<Category, number> = { model: 0, subagent: 0, tool: 0, engine: 0 }
88  const [w0, w1] = window
89  if (w1 <= w0) return out
90  const events: { t: number; d: number; cat: Category }[] = []
91  for (const x of tagged) {
92    const a = Math.max(w0, x.iv[0])
93    const b = Math.min(w1, x.iv[1])
94    if (b > a) events.push({ t: a, d: 1, cat: x.cat }, { t: b, d: -1, cat: x.cat })
95  }
96  events.sort((p, q) => p.t - q.t)
97  const active: Record<Category, number> = { model: 0, subagent: 0, tool: 0, engine: 0 }
98  const top = (): Category => PRIORITY.find(cat => active[cat] > 0) ?? 'engine'
99  let at = w0
100  for (const ev of events) {
101    if (ev.t > at) {
102      out[top()] += ev.t - at
103      at = ev.t
104    }
105    active[ev.cat] += ev.d
106  }
107  if (w1 > at) out[top()] += w1 - at
108  return out
109}
110
111function groupBy<T>(items: T[], key: (item: T) => string | undefined): Map<string, T[]> {
112  const out = new Map<string, T[]>()
113  for (const item of items) {
114    const k = key(item)
115    if (k === undefined) continue
116    const list = out.get(k)
117    if (list) list.push(item)
118    else out.set(k, [item])
119  }
120  return out
121}
122
123function scopeAgents(s: Snapshot, mainTools: ToolRec[], scope: Scope, toolById: Map<string, ToolRec>): Set<string> {
124  if (scope === 'session') return new Set(s.agents.map(a => a.id))
125  const toolIds = new Set(mainTools.map(t => t.id))
126  const ids = new Set<string>()
127  for (let grew = true; grew; ) {
128    grew = false
129    for (const agent of s.agents) {
130      if (ids.has(agent.id) || !agent.parentToolId) continue
131      const parent = toolById.get(agent.parentToolId)
132      if (toolIds.has(agent.parentToolId) || (parent && ids.has(parent.ctx))) {
133        ids.add(agent.id)
134        grew = true
135      }
136    }
137  }
138  return ids
139}
140
141export function summarize(s: Snapshot, scope: Scope = 'session'): Summary {
142  const end = (x: { end?: number }) => x.end ?? s.now
143  let mainTurns = s.turns.filter(t => t.ctx === MAIN).sort((a, b) => a.start - b.start)
144  if (scope === 'turn') mainTurns = mainTurns.slice(-1)
145  const turnIds = new Set(mainTurns.map(t => t.id))
146  const inScope = (turnId: string | undefined) => scope === 'session' || (turnId !== undefined && turnIds.has(turnId))
147  const mainTools = s.tools.filter(t => t.ctx === MAIN && inScope(t.turnId))
148  const toolById = new Map(s.tools.map(t => [t.id, t]))
149  const agentIds = scopeAgents(s, mainTools, scope, toolById)
150  const steps = s.steps.filter(x => (x.ctx === MAIN ? inScope(x.turnId) : agentIds.has(x.ctx)))
151  const tools = [...mainTools, ...s.tools.filter(x => x.ctx !== MAIN && agentIds.has(x.ctx))]
152  const agents = s.agents.filter(a => agentIds.has(a.id))
153
154  const stepsByTurn = groupBy(steps, x => (x.ctx === MAIN ? x.turnId : undefined))
155  const toolsByTurn = groupBy(mainTools, x => x.turnId)
156  const exclusive: Record<Category, number> = { model: 0, subagent: 0, tool: 0, engine: 0 }
157  let wallMs = 0
158  for (const turn of mainTurns) {
159    const window: Interval = [turn.start, end(turn)]
160    wallMs += window[1] - window[0]
161    const tagged = [
162      ...(stepsByTurn.get(turn.id) ?? []).map(x => ({ cat: 'model' as Category, iv: [x.start, end(x)] as Interval })),
163      ...(toolsByTurn.get(turn.id) ?? []).map(x => ({
164        cat: (isAgentTool(x.tool) && x.launchedAsync !== true ? 'subagent' : 'tool') as Category,
165        iv: [x.start, end(x)] as Interval,
166      })),
167    ]
168    const part = attribute(window, tagged)
169    for (const cat of Object.keys(part) as Category[]) exclusive[cat] += part[cat]
170  }
171
172  const ttfts = steps.filter(x => x.firstContent !== undefined).map(x => (x.firstContent as number) - x.start).sort((a, b) => a - b)
173  let thinkingMs = 0
174  let outputMs = 0
175  let inputTokens = 0
176  let cacheReadTokens = 0
177  let outputTokens = 0
178  let streamTokens = 0
179  let streamMs = 0
180  for (const x of steps) {
181    if (x.thinkFirst !== undefined && x.thinkLast !== undefined) thinkingMs += x.thinkLast - x.thinkFirst
182    if (x.outFirst !== undefined) outputMs += end(x) - x.outFirst
183    if (x.usage) {
184      inputTokens += x.usage.input_tokens + x.usage.cache_read_input_tokens + x.usage.cache_creation_input_tokens
185      cacheReadTokens += x.usage.cache_read_input_tokens
186      outputTokens += x.usage.output_tokens
187      if (x.firstContent !== undefined) {
188        streamTokens += x.usage.output_tokens
189        streamMs += end(x) - x.firstContent
190      }
191    }
192  }
193
194  const plain = tools.filter(x => !isAgentTool(x.tool))
195  const timed = plain.map(x => {
196    const wall = end(x) - x.start
197    const exec = x.execMs !== undefined ? Math.min(x.execMs, wall) : wall
198    return { x, wall, exec, wait: Math.max(0, wall - exec) }
199  })
200  const testIntervals: Interval[] = []
201  const waitIntervals: Interval[] = []
202  let execMs = 0
203  let permissionMs = 0
204  let overheadMs = 0
205  let sumMs = 0
206  const byTool = new Map<string, { tool: string; calls: number; ms: number }>()
207  const byCategory = new Map<BashCategory, { category: BashCategory; calls: number; ms: number }>()
208  for (const { x, wall, exec, wait } of timed) {
209    sumMs += wall
210    execMs += exec
211    if (x.decision === 'ask') {
212      permissionMs += wait
213      waitIntervals.push([x.start, x.start + wait])
214    } else {
215      overheadMs += wait
216    }
217    const row = byTool.get(x.tool) ?? { tool: x.tool, calls: 0, ms: 0 }
218    row.calls += 1
219    row.ms += wall
220    byTool.set(x.tool, row)
221    if (x.tool === 'Bash') {
222      const category = classifyCommand(x.input.command ?? '')
223      const cat = byCategory.get(category) ?? { category, calls: 0, ms: 0 }
224      cat.calls += 1
225      cat.ms += exec
226      byCategory.set(category, cat)
227      if (category === 'test') testIntervals.push([x.start + wait, x.start + wall])
228    }
229  }
230  const testMs = byCategory.get('test')?.ms ?? 0
231  const windows = mainTurns.map(t => [t.start, end(t)] as Interval)
232  const share = (intervals: Interval[]) => (wallMs > 0 ? overlapLength(intervals, windows) / wallMs : 0)
233
234  const seen = new Map<string, { path: string; reads: number; redundant: number; ranges: Set<string> }>()
235  for (const x of [...tools].sort((a, b) => a.start - b.start)) {
236    const path = x.input.path
237    if (!path) continue
238    if (x.tool === 'Read') {
239      const row = seen.get(path) ?? { path, reads: 0, redundant: 0, ranges: new Set<string>() }
240      const range = x.input.range ?? ''
241      if (row.ranges.has(range)) row.redundant += 1
242      row.ranges.add(range)
243      row.reads += 1
244      seen.set(path, row)
245    } else if (WRITE_TOOLS.has(x.tool)) {
246      seen.get(path)?.ranges.clear()
247    }
248  }
249
250  const stepsByCtx = groupBy(s.steps, x => x.ctx)
251  const toolsByCtx = groupBy(s.tools, x => x.ctx)
252  const summary: Summary = {
253    scope,
254    turns: mainTurns.length,
255    wallMs,
256    exclusive,
257    model: {
258      requests: steps.length,
259      ttftAvg: ttfts.length ? Math.round(ttfts.reduce((a, b) => a + b, 0) / ttfts.length) : 0,
260      ttftP95: ttfts[Math.max(0, Math.ceil(ttfts.length * 0.95) - 1)] ?? 0,
261      thinkingMs,
262      outputMs,
263      inputTokens,
264      cacheReadTokens,
265      outputTokens,
266      tokensPerSec: streamMs > 0 && streamTokens > 0 ? streamTokens / (streamMs / 1_000) : null,
267    },
268    tools: {
269      calls: plain.length,
270      sumMs,
271      unionMs: unionLength(plain.map(x => [x.start, end(x)] as Interval)),
272      execMs,
273      permissionMs,
274      permissionShare: share(waitIntervals),
275      overheadMs,
276      errors: plain.filter(x => x.isError).length,
277      denied: plain.filter(x => x.denied).length,
278      byTool: [...byTool.values()].sort((a, b) => b.ms - a.ms),
279      slowest: [...timed]
280        .sort((a, b) => b.wall - a.wall)
281        .slice(0, 5)
282        .map(({ x, wall, wait }) => ({ tool: x.tool, label: toolLabel(x), ms: wall, waitMs: wait, ctx: x.ctx })),
283    },
284    bash: { byCategory: [...byCategory.values()].sort((a, b) => b.ms - a.ms), testMs, testShare: share(testIntervals) },
285    reads: [...seen.values()]
286      .filter(r => r.reads >= 2)
287      .sort((a, b) => b.redundant - a.redundant || b.reads - a.reads)
288      .slice(0, 10)
289      .map(({ path, reads, redundant }) => ({ path, reads, redundant })),
290    agents: agents
291      .map(agent => {
292        const parent = agent.parentToolId ? toolById.get(agent.parentToolId) : undefined
293        const ownSteps = stepsByCtx.get(agent.id) ?? []
294        const ownTools = toolsByCtx.get(agent.id) ?? []
295        return {
296          id: agent.id,
297          agentType: agent.agentType,
298          wallMs: end(agent) - agent.start,
299          modelMs: unionLength(ownSteps.map(x => [x.start, end(x)] as Interval)),
300          toolMs: unionLength(ownTools.map(x => [x.start, end(x)] as Interval)),
301          requests: ownSteps.length,
302          tools: ownTools.length,
303          blocking: parent !== undefined && parent.launchedAsync !== true,
304          done: agent.end !== undefined,
305        }
306      })
307      .sort((a, b) => b.wallMs - a.wallMs),
308    findings: [],
309    incomplete: [...mainTurns, ...steps, ...tools, ...agents].filter(x => x.end === undefined).length,
310    droppedTurns: s.droppedTurns,
311    droppedSpans: s.droppedSpans,
312  }
313  summary.findings = buildFindings(summary)
314  return summary
315}
316
317function buildFindings(sum: Summary): string[] {
318  const wall = sum.wallMs
319  const out: string[] = []
320  if (wall < 1_000) return out
321  if (sum.exclusive.model / wall >= 0.7) {
322    out.push(`Waiting for the model is ${pct(sum.exclusive.model, wall)} of agent time (TTFT p95 ${fmtMs(sum.model.ttftP95)}); tools are not the bottleneck.`)
323  }
324  if (sum.bash.testShare >= 0.25) {
325    const runs = sum.bash.byCategory.find(c => c.category === 'test')?.calls ?? 0
326    out.push(`Tests took ${pct(sum.bash.testShare, 1)} of agent time (${fmtMs(sum.bash.testMs)} over ${runs} run(s)).`)
327  }
328  if (sum.tools.permissionShare >= 0.2) {
329    out.push(`Waiting for approval took ${pct(sum.tools.permissionShare, 1)} of agent time (${fmtMs(sum.tools.permissionMs)}); allow rules for repeated commands would remove it.`)
330  }
331  for (const r of sum.reads) {
332    if (r.redundant >= 2) out.push(`${clip(r.path, 80)} was read ${r.reads}× (${r.redundant}× with no edit in between).`)
333  }
334  for (const a of sum.agents) {
335    if (a.blocking && a.wallMs / wall >= 0.5) out.push(`Subagent ${a.agentType} blocked the main loop for ${pct(a.wallMs, wall)} (${fmtMs(a.wallMs)}).`)
336  }
337  const top = sum.tools.slowest[0]
338  if (top && top.ms / wall >= 0.3) out.push(`One call took ${pct(top.ms, wall)}: ${clip(top.label, 60)} (${fmtMs(top.ms)}).`)
339  if (sum.exclusive.engine / wall >= 0.25) {
340    out.push(`${pct(sum.exclusive.engine, wall)} of the time is outside model requests and tools (hooks, context building, compaction).`)
341  }
342  return out
343}
344
hooks/core/cache.ts 17 lines
1import { summarize, type Scope, type Summary } from './analyze.ts'
2import type { Profiler } from './profiler.ts'
3
4// Share summary work between status, pane and ticker.
5export class SummaryCache {
6  private readonly summaries = new Map<Scope, { profiler: Profiler; version: number; bucket: number; sum: Summary }>()
7
8  get(profiler: Profiler, scope: Scope = 'session', now = Date.now()): Summary {
9    const hit = this.summaries.get(scope)
10    const bucket = profiler.isLive ? Math.floor(now / 500) : -1
11    if (hit && hit.profiler === profiler && hit.version === profiler.version && hit.bucket === bucket) return hit.sum
12    const sum = summarize(profiler.snapshot(now), scope)
13    this.summaries.set(scope, { profiler, version: profiler.version, bucket, sum })
14    return sum
15  }
16}
17
hooks/core/export.ts 54 lines
1import type { OtlpRequest, OtlpSpan } from './otlp.ts'
2import { recordKey } from './otlp.ts'
3import { MAIN } from './profiler.ts'
4import type { Snapshot } from './types.ts'
5
6// $.fs.write refuses more than 4 MiB; stay well under it.
7export const MAX_EXPORT_BYTES = Math.floor(3.5 * 1024 * 1024)
8
9// Keys of the records not exported yet: finished ones only for a per-turn batch, open ones too
10// (exported as incomplete) for the final batch at session end.
11export function pendingKeys(s: Snapshot, exported: ReadonlySet<string>, withOpen: boolean): string[] {
12  const out: string[] = []
13  const take = (key: string, finished: boolean) => {
14    if (!exported.has(key) && (withOpen || finished)) out.push(key)
15  }
16  for (const t of s.turns) if (t.ctx === MAIN) take(recordKey('turn', t.id), t.end !== undefined)
17  for (const a of s.agents) take(recordKey('agent', a.id), a.end !== undefined)
18  for (const x of s.steps) take(recordKey('step', x.id), x.end !== undefined)
19  for (const x of s.tools) take(recordKey('tool', x.id), x.end !== undefined)
20  return out
21}
22
23function byteLength(text: string): number {
24  return new TextEncoder().encode(text).length
25}
26
27// Splits a request into requests whose JSON stays within maxBytes (a single span larger than that
28// goes alone). Every part keeps the resource and scope; no spans means no parts.
29export function splitRequest(req: OtlpRequest, maxBytes: number): OtlpRequest[] {
30  const resource = req.resourceSpans[0]
31  const scope = resource?.scopeSpans[0]
32  if (!resource || !scope || scope.spans.length === 0) return []
33  const wrap = (spans: OtlpSpan[]): OtlpRequest => ({
34    resourceSpans: [{ resource: resource.resource, scopeSpans: [{ scope: scope.scope, spans }] }],
35  })
36  if (byteLength(JSON.stringify(req)) <= maxBytes) return [req]
37  const envelope = byteLength(JSON.stringify(wrap([])))
38  const parts: OtlpRequest[] = []
39  let current: OtlpSpan[] = []
40  let size = envelope
41  for (const span of scope.spans) {
42    const bytes = byteLength(JSON.stringify(span)) + 1 // the comma between spans
43    if (current.length > 0 && size + bytes > maxBytes) {
44      parts.push(wrap(current))
45      current = []
46      size = envelope
47    }
48    current.push(span)
49    size += bytes
50  }
51  if (current.length > 0) parts.push(wrap(current))
52  return parts
53}
54
hooks/core/otlp.ts 210 lines
1import { classifyCommand } from './classify.ts'
2import { spanId, traceIdFromSession } from './ids.ts'
3import { MAIN, isAgentTool } from './profiler.ts'
4import { redactSecrets } from './redact.ts'
5import type { Snapshot } from './types.ts'
6
7type AttrValue = { stringValue: string } | { intValue: string } | { doubleValue: number } | { boolValue: boolean }
8export type OtlpAttr = { key: string; value: AttrValue }
9export type OtlpSpan = {
10  traceId: string
11  spanId: string
12  parentSpanId?: string
13  name: string
14  kind: number
15  startTimeUnixNano: string
16  endTimeUnixNano: string
17  attributes: OtlpAttr[]
18  status: { code: number; message?: string }
19}
20export type OtlpRequest = {
21  resourceSpans: { resource: { attributes: OtlpAttr[] }; scopeSpans: { scope: { name: string; version: string }; spans: OtlpSpan[] }[] }[]
22}
23type Attrs = Record<string, string | number | boolean | undefined>
24
25export type OtlpOptions = {
26  // Which records to emit, by recordKey(); a record's phase spans (ttft, exec, wait, ...) go with it. Default: all.
27  include?: (key: string) => boolean
28  // Emit the session root span. Default true; batches leave it to the final export.
29  root?: boolean
30  // Export prompts, Bash commands and search patterns (redacted). Default false: all are left out.
31  commandText?: boolean
32}
33
34export type RecordKind = 'turn' | 'step' | 'tool' | 'agent'
35
36export function recordKey(kind: RecordKind, id: string): string {
37  return `${kind}:${id}`
38}
39
40const INTERNAL = 1
41const CLIENT = 3
42const STATUS_OK = 1
43const STATUS_ERROR = 2
44
45export function nanos(ms: number): string {
46  return (BigInt(Math.round(ms)) * 1_000_000n).toString()
47}
48
49function attrs(values: Attrs): OtlpAttr[] {
50  const out: OtlpAttr[] = []
51  for (const [key, v] of Object.entries(values)) {
52    if (v === undefined || v === '') continue
53    if (typeof v === 'string') out.push({ key, value: { stringValue: v } })
54    else if (typeof v === 'boolean') out.push({ key, value: { boolValue: v } })
55    else if (Number.isInteger(v)) out.push({ key, value: { intValue: String(v) } })
56    else out.push({ key, value: { doubleValue: v } })
57  }
58  return out
59}
60
61export function toOtlp(s: Snapshot, version: string, options: OtlpOptions = {}): OtlpRequest {
62  const traceId = traceIdFromSession(s.sessionId)
63  const include = options.include ?? (() => true)
64  const want = (kind: RecordKind, id: string) => include(recordKey(kind, id))
65  const text = (value: string | undefined) => (options.commandText === true && value ? redactSecrets(value) : undefined)
66  const spans: OtlpSpan[] = []
67  const end = (x: { end?: number }) => x.end ?? s.now
68  const open = (x: { end?: number }) => (x.end === undefined ? true : undefined)
69  const add = (kind: string, key: string, name: string, parent: string | undefined, start: number, stop: number, values: Attrs, extra: { spanKind?: number; error?: string } = {}): string => {
70    const id = spanId(kind, key)
71    spans.push({
72      traceId,
73      spanId: id,
74      ...(parent ? { parentSpanId: parent } : {}),
75      name,
76      kind: extra.spanKind ?? INTERNAL,
77      startTimeUnixNano: nanos(start),
78      endTimeUnixNano: nanos(Math.max(start, stop)),
79      attributes: attrs(values),
80      status: extra.error ? { code: STATUS_ERROR, message: extra.error } : { code: STATUS_OK },
81    })
82    return id
83  }
84
85  // Span ids are deterministic, so a span can name a parent emitted in another batch.
86  const root = spanId('session', s.sessionId)
87  if (options.root !== false) {
88    const sessionStart = [...s.turns, ...s.steps, ...s.tools, ...s.agents].reduce((min, x) => Math.min(min, x.start), s.started ?? s.now)
89    add('session', s.sessionId, 'claude-code session', undefined, sessionStart, s.now, {
90      'session.id': s.sessionId,
91      'agent_profiler.observability': 'observed',
92    })
93  }
94
95  const mainTurns = new Set<string>()
96  for (const t of s.turns) {
97    if (t.ctx !== MAIN) continue
98    mainTurns.add(t.id)
99    if (!want('turn', t.id)) continue
100    add('turn', t.id, 'turn', root, t.start, end(t), {
101      'agent_profiler.category': 'turn',
102      'agent_profiler.observability': 'observed',
103      'agent_profiler.turn.reason': t.reason,
104      'agent_profiler.turn.prompt': text(t.prompt),
105      'agent_profiler.incomplete': open(t),
106    })
107  }
108
109  const agents = new Set(s.agents.map(a => a.id))
110  const tools = new Map(s.tools.map(t => [t.id, t]))
111  const parentOf = (ctx: string, turnId?: string): string =>
112    ctx === MAIN
113      ? turnId !== undefined && mainTurns.has(turnId)
114        ? spanId('turn', turnId)
115        : root
116      : agents.has(ctx)
117        ? spanId('agent', ctx)
118        : root
119
120  for (const a of s.agents) {
121    if (!want('agent', a.id)) continue
122    const parentTool = a.parentToolId ? tools.get(a.parentToolId) : undefined
123    add('agent', a.id, `invoke_agent ${a.agentType}`, parentTool ? spanId('tool', parentTool.id) : root, a.start, end(a), {
124      'gen_ai.operation.name': 'invoke_agent',
125      'gen_ai.agent.id': a.id,
126      'gen_ai.agent.name': a.agentType,
127      'agent_profiler.category': 'subagent',
128      'agent_profiler.observability': 'observed',
129      'agent_profiler.async': parentTool ? parentTool.launchedAsync === true : undefined,
130      'agent_profiler.incomplete': open(a),
131    })
132  }
133
134  for (const x of s.steps) {
135    if (!want('step', x.id)) continue
136    const ttft = x.firstContent !== undefined ? x.firstContent - x.start : undefined
137    const id = add('step', x.id, `chat ${x.model}`, parentOf(x.ctx, x.turnId), x.start, end(x), {
138      'gen_ai.operation.name': 'chat',
139      'gen_ai.request.model': x.model,
140      'gen_ai.response.model': x.usage?.model,
141      'gen_ai.usage.input_tokens': x.usage?.input_tokens,
142      'gen_ai.usage.output_tokens': x.usage?.output_tokens,
143      'gen_ai.response.finish_reasons': x.stopReason,
144      'gen_ai.agent.id': x.ctx === MAIN ? undefined : x.ctx,
145      'agent_profiler.usage.cache_read_input_tokens': x.usage?.cache_read_input_tokens,
146      'agent_profiler.usage.cache_creation_input_tokens': x.usage?.cache_creation_input_tokens,
147      'agent_profiler.effort': x.effort,
148      'agent_profiler.ttft_ms': ttft,
149      'agent_profiler.category': 'model',
150      'agent_profiler.observability': 'observed',
151      'agent_profiler.incomplete': open(x),
152    }, { spanKind: CLIENT })
153    if (x.firstContent !== undefined) {
154      add('step.ttft', x.id, 'model.ttft', id, x.start, x.firstContent, {
155        'agent_profiler.observability': 'observed',
156        'agent_profiler.note': 'network + queueing + prefill, not separable from the client',
157      })
158    }
159    if (x.thinkFirst !== undefined && x.thinkLast !== undefined) {
160      add('step.thinking', x.id, 'model.thinking_stream', id, x.thinkFirst, x.thinkLast, { 'agent_profiler.observability': 'observed' })
161    }
162    if (x.outFirst !== undefined) {
163      add('step.output', x.id, 'model.output_stream', id, x.outFirst, end(x), { 'agent_profiler.observability': 'observed' })
164    }
165  }
166
167  for (const x of s.tools) {
168    if (!want('tool', x.id)) continue
169    const wall = end(x) - x.start
170    const exec = x.execMs !== undefined ? Math.min(x.execMs, wall) : undefined
171    const wait = exec !== undefined ? wall - exec : undefined
172    const id = add('tool', x.id, `execute_tool ${x.tool}`, parentOf(x.ctx, x.turnId), x.start, end(x), {
173      'gen_ai.operation.name': 'execute_tool',
174      'gen_ai.tool.name': x.tool,
175      'gen_ai.tool.call.id': x.id,
176      'gen_ai.agent.id': x.ctx === MAIN ? undefined : x.ctx,
177      // An async Agent call returns at once and does not block the turn, as in summarize().
178      'agent_profiler.category': isAgentTool(x.tool) && x.launchedAsync !== true ? 'subagent' : 'tool',
179      'agent_profiler.observability': 'observed',
180      'agent_profiler.exec_ms': exec,
181      'agent_profiler.wait_ms': wait,
182      'agent_profiler.permission': x.decision,
183      'agent_profiler.fs.path': x.input.path,
184      'agent_profiler.fs.range': x.input.range,
185      'agent_profiler.search.pattern': text(x.input.pattern),
186      'agent_profiler.bash.command': text(x.input.command),
187      'agent_profiler.bash.category': x.tool === 'Bash' ? classifyCommand(x.input.command ?? '') : undefined,
188      'agent_profiler.launched_agent': x.launchedAgentId,
189      'agent_profiler.incomplete': open(x),
190    }, { error: x.denied ? 'denied' : x.isError ? 'tool error' : undefined })
191    if (exec !== undefined && wait !== undefined && x.end !== undefined) {
192      if (wait > 0) {
193        add('tool.wait', x.id, x.decision === 'ask' ? 'tool.approval_wait' : 'tool.overhead', id, x.start, x.start + wait, {
194          'agent_profiler.observability': 'inferred',
195        })
196      }
197      add('tool.exec', x.id, 'tool.exec', id, x.start + wait, x.end, { 'agent_profiler.observability': 'measured' })
198    }
199  }
200
201  return {
202    resourceSpans: [
203      {
204        resource: { attributes: attrs({ 'service.name': 'claude-code', 'session.id': s.sessionId, 'agent_profiler.version': version }) },
205        scopeSpans: [{ scope: { name: 'agent-profiler', version }, spans }],
206      },
207    ],
208  }
209}
210
hooks/core/profiler.ts 404 lines
1import type { AgentRec, Outcome, Snapshot, StepRec, ToolInputSummary, ToolRec, TurnRec, Usage } from './types.ts'
2import { redactSecrets } from './redact.ts'
3
4export const MAIN = 'main'
5
6export type RunningItem = { kind: 'model' | 'tool' | 'agent'; label: string; ctx: string; ms: number }
7
8export function isAgentTool(tool: string): boolean {
9  return tool === 'Agent' || tool === 'Task'
10}
11
12export function toolLabel(tool: ToolRec): string {
13  const detail = tool.input.command ?? tool.input.path ?? tool.input.pattern ?? tool.input.subagentType ?? ''
14  return redactSecrets(detail ? `${tool.tool} ${detail}` : tool.tool)
15}
16
17function text(value: unknown, n: number): string | undefined {
18  return typeof value === 'string' ? value.slice(0, n) : undefined
19}
20
21function safeText(value: unknown, n: number): string | undefined {
22  return typeof value === 'string' ? redactSecrets(value).slice(0, n) : undefined
23}
24
25function defined<T extends object>(value: T): T {
26  return Object.fromEntries(Object.entries(value).filter(([, v]) => v !== undefined)) as T
27}
28
29export function summarizeInput(tool: string, input: Record<string, unknown>): ToolInputSummary {
30  switch (tool) {
31    case 'Bash':
32      return defined({ command: safeText(input.command, 512), description: safeText(input.description, 120) })
33    case 'Read': {
34      const paged = input.offset !== undefined || input.limit !== undefined
35      return defined({ path: text(input.file_path, 512), range: paged ? `${input.offset ?? ''}:${input.limit ?? ''}` : undefined })
36    }
37    case 'Write':
38    case 'Edit':
39    case 'MultiEdit':
40      return defined({ path: text(input.file_path, 512) })
41    case 'NotebookEdit':
42      return defined({ path: text(input.notebook_path, 512) })
43    case 'Glob':
44    case 'Grep':
45      return defined({ pattern: safeText(input.pattern, 200), path: text(input.path, 512) })
46    case 'Agent':
47    case 'Task':
48      return defined({ subagentType: safeText(input.subagent_type, 80), description: safeText(input.description, 120) })
49    default:
50      return {}
51  }
52}
53
54export function toolOutcome(answer: unknown): Outcome {
55  const value = (answer ?? {}) as { deny?: unknown; isError?: unknown; result?: unknown }
56  const result = (value.result ?? {}) as { agentId?: unknown; status?: unknown }
57  return {
58    denied: typeof value.deny === 'string',
59    isError: value.isError === true,
60    launchedAgentId: typeof result.agentId === 'string' ? result.agentId : undefined,
61    launchedAsync: result.status === 'async_launched',
62  }
63}
64
65export class Profiler {
66  sessionId: string
67  private readonly maxSpans: number
68  private readonly turns = new Map<string, TurnRec>()
69  private readonly steps = new Map<string, StepRec>()
70  private readonly tools = new Map<string, ToolRec>()
71  private readonly agents = new Map<string, AgentRec>()
72  private readonly openTurns = new Map<string, string[]>()
73  private readonly pendingExec = new Map<string, number>()
74  private readonly openSteps = new Set<string>()
75  private readonly openTools = new Set<string>()
76  private readonly openAgents = new Set<string>()
77  private droppedTurns = 0
78  private droppedSpans = 0
79  private started: number | undefined
80  // Bumped on every change, so callers can cache what they derive from a snapshot.
81  version = 0
82
83  get isLive(): boolean {
84    return this.openSteps.size > 0 || this.openTools.size > 0 || this.openAgents.size > 0 || [...this.openTurns.values()].some(turns => turns.length > 0)
85  }
86
87  constructor(sessionId = 'unknown', maxSpans = 20_000) {
88    this.sessionId = sessionId
89    this.maxSpans = maxSpans
90  }
91
92  // A profiler created before the session id was known (a reload mid-session) takes it on later.
93  adoptSessionId(id: string): void {
94    if (this.sessionId !== 'unknown' || !id) return
95    this.sessionId = id
96    this.version += 1
97  }
98
99  turnStart(t: number, turnId: string, prompt = '', ctx = MAIN): void {
100    if (this.turns.has(turnId)) return
101    this.turns.set(turnId, { id: turnId, ctx, start: t, prompt: redactSecrets(prompt).slice(0, 120) })
102    this.seen(t)
103    this.stack(ctx).push(turnId)
104    this.version += 1
105  }
106
107  turnComplete(t: number, turnId: string, reason?: string): void {
108    const turn = this.turns.get(turnId)
109    if (!turn) return
110    if (turn.end === undefined) turn.end = t
111    if (reason !== undefined) turn.reason = reason
112    // Completion is authoritative even when a stream/tool's cleanup arrives late.
113    for (const id of [...this.openSteps]) {
114      if (this.steps.get(id)?.turnId === turnId) this.stepEnd(turn.end, id)
115    }
116    for (const id of [...this.openTools]) {
117      const tool = this.tools.get(id)
118      if (tool?.turnId !== turnId) continue
119      tool.end = turn.end
120      this.openTools.delete(id)
121    }
122    this.unstack(turn.ctx, turnId)
123    this.version += 1
124  }
125
126  // StopFailure can arrive before turn.complete after a terminal API error.
127  // Only settle that loop: independent background agents may still be working.
128  stopFailure(t: number, ctx = MAIN): void {
129    for (const turnId of [...(this.openTurns.get(ctx) ?? [])]) this.turnComplete(t, turnId, 'error')
130    if (ctx !== MAIN) this.subagentStop(t, ctx)
131    for (const id of [...this.openSteps]) {
132      if (this.steps.get(id)?.ctx === ctx) this.stepEnd(t, id)
133    }
134    for (const id of [...this.openTools]) {
135      const tool = this.tools.get(id)
136      if (tool?.ctx !== ctx) continue
137      tool.end = t
138      this.openTools.delete(id)
139      this.version += 1
140    }
141  }
142
143  stepStart(t: number, args: { turnId: string; index: number; model: string; effort?: string | number; agentId?: string }): string {
144    const ctx = args.agentId ?? MAIN
145    const turn = this.turns.get(args.turnId)
146    if (!turn) {
147      this.turnStart(t, args.turnId, '', ctx)
148    } else if (turn.ctx !== ctx) {
149      // The engine may raise turn.start for a subagent's loop too; the step tells us whose turn it is.
150      this.unstack(turn.ctx, turn.id)
151      turn.ctx = ctx
152      if (turn.end === undefined) this.stack(ctx).push(turn.id)
153    }
154    let id = `${args.turnId}#${args.index}`
155    for (let n = 1; this.steps.has(id); n += 1) id = `${args.turnId}#${args.index}.${n}`
156    const step: StepRec = { id, ctx, turnId: args.turnId, index: args.index, model: args.model, start: t }
157    if (args.effort !== undefined) step.effort = String(args.effort)
158    this.steps.set(id, step)
159    this.openSteps.add(id)
160    this.seen(t)
161    this.version += 1
162    this.trim()
163    return id
164  }
165
166  stepChunk(t: number, stepId: string, kind: string): void {
167    const step = this.steps.get(stepId)
168    if (!step || step.end !== undefined || kind === 'engine' || kind === 'stop') return
169    if (kind !== 'thinking' && step.outFirst !== undefined) return
170    if (step.firstContent === undefined) step.firstContent = t
171    if (kind === 'thinking') {
172      if (step.thinkFirst === undefined) step.thinkFirst = t
173      step.thinkLast = t
174    } else {
175      step.outFirst = t
176    }
177    this.version += 1
178  }
179
180  stepUsage(stepId: string, usage: Usage | null | undefined, stopReason?: string | null): void {
181    const step = this.steps.get(stepId)
182    if (!step) return
183    if (usage) step.usage = { ...usage }
184    if (stopReason) step.stopReason = stopReason
185    this.version += 1
186  }
187
188  stepEnd(t: number, stepId: string): void {
189    const step = this.steps.get(stepId)
190    if (!step || step.end !== undefined) return
191    step.end = t
192    this.openSteps.delete(stepId)
193    this.version += 1
194  }
195
196  toolStart(t: number, args: { id: string; tool: string; agentId?: string; input: ToolInputSummary }): void {
197    if (this.tools.has(args.id)) return
198    const ctx = args.agentId ?? MAIN
199    const tool: ToolRec = { id: args.id, ctx, tool: args.tool, input: args.input, start: t }
200    const turnId = this.currentTurn(ctx)
201    if (turnId !== undefined) tool.turnId = turnId
202    const exec = this.pendingExec.get(args.id)
203    if (exec !== undefined) {
204      tool.execMs = exec
205      this.pendingExec.delete(args.id)
206    }
207    this.tools.set(args.id, tool)
208    this.openTools.add(args.id)
209    this.seen(t)
210    this.version += 1
211    this.trim()
212  }
213
214  toolCheck(id: string, decision: string): void {
215    const tool = this.tools.get(id)
216    if (!tool) return
217    tool.decision = decision
218    this.version += 1
219  }
220
221  toolDuration(id: string, ms: unknown): void {
222    if (typeof ms !== 'number' || !Number.isFinite(ms) || ms < 0) return
223    const tool = this.tools.get(id)
224    if (tool) {
225      tool.execMs = ms
226      this.version += 1
227    } else if (this.pendingExec.size < 1_000) this.pendingExec.set(id, ms)
228  }
229
230  toolEnd(t: number, id: string, outcome: Outcome): void {
231    const tool = this.tools.get(id)
232    if (!tool || tool.end !== undefined) return
233    tool.end = t
234    this.openTools.delete(id)
235    this.version += 1
236    tool.denied = outcome.denied
237    tool.isError = outcome.isError
238    if (outcome.launchedAgentId) {
239      tool.launchedAgentId = outcome.launchedAgentId
240      tool.launchedAsync = outcome.launchedAsync
241      const agent = this.agents.get(outcome.launchedAgentId)
242      if (agent) agent.parentToolId = id
243    }
244  }
245
246  subagentStart(t: number, agentId: string, agentType: string): void {
247    if (this.agents.has(agentId)) return
248    const claimed = new Set([...this.agents.values()].map(agent => agent.parentToolId))
249    let parent: ToolRec | undefined
250    for (const tool of this.tools.values()) {
251      if (!isAgentTool(tool.tool) || claimed.has(tool.id)) continue
252      if (tool.launchedAgentId !== undefined && tool.launchedAgentId !== agentId) continue
253      if (tool.end !== undefined && t - tool.end > 2_000) continue
254      if (!parent || tool.start > parent.start) parent = tool
255    }
256    const agent: AgentRec = { id: agentId, agentType, start: t }
257    if (parent) agent.parentToolId = parent.id
258    this.agents.set(agentId, agent)
259    this.openAgents.add(agentId)
260    this.seen(t)
261    this.version += 1
262  }
263
264  subagentStop(t: number, agentId: string): void {
265    const agent = this.agents.get(agentId)
266    if (!agent) return
267    if (agent.end === undefined) agent.end = t
268    this.openAgents.delete(agentId)
269    // Whatever the agent left open ended with it, so running() and the ticker settle.
270    for (const id of [...this.openSteps]) {
271      const step = this.steps.get(id)
272      if (step?.ctx === agentId) this.stepEnd(t, id)
273    }
274    for (const id of [...this.openTools]) {
275      const tool = this.tools.get(id)
276      if (tool?.ctx !== agentId) continue
277      tool.end = t
278      this.openTools.delete(id)
279    }
280    this.version += 1
281    for (const turnId of [...(this.openTurns.get(agentId) ?? [])]) this.turnComplete(t, turnId, 'agent-stop')
282  }
283
284  running(now: number): RunningItem[] {
285    // Walks only the open spans, so the once-a-second ticker stays cheap however long the session.
286    const items: RunningItem[] = []
287    for (const id of this.openSteps) {
288      const step = this.steps.get(id)
289      if (step) items.push({ kind: 'model', label: `model ${step.model}`, ctx: step.ctx, ms: now - step.start })
290    }
291    for (const id of this.openTools) {
292      const tool = this.tools.get(id)
293      if (tool) items.push({ kind: 'tool', label: toolLabel(tool), ctx: tool.ctx, ms: now - tool.start })
294    }
295    for (const id of this.openAgents) {
296      const agent = this.agents.get(id)
297      if (agent) items.push({ kind: 'agent', label: `agent ${agent.agentType}`, ctx: agent.id, ms: now - agent.start })
298    }
299    return items.sort((a, b) => b.ms - a.ms)
300  }
301
302  snapshot(now: number): Snapshot {
303    return {
304      sessionId: this.sessionId,
305      now,
306      turns: [...this.turns.values()].map(turn => ({ ...turn })),
307      steps: [...this.steps.values()].map(step => ({ ...step, ...(step.usage ? { usage: { ...step.usage } } : {}) })),
308      tools: [...this.tools.values()].map(tool => ({ ...tool, input: { ...tool.input } })),
309      agents: [...this.agents.values()].map(agent => ({ ...agent })),
310      ...(this.started !== undefined ? { started: this.started } : {}),
311      droppedTurns: this.droppedTurns,
312      droppedSpans: this.droppedSpans,
313    }
314  }
315
316  private currentTurn(ctx: string): string | undefined {
317    const open = this.openTurns.get(ctx)
318    return open && open.length > 0 ? open[open.length - 1] : undefined
319  }
320
321  private stack(ctx: string): string[] {
322    let open = this.openTurns.get(ctx)
323    if (!open) {
324      open = []
325      this.openTurns.set(ctx, open)
326    }
327    return open
328  }
329
330  private unstack(ctx: string, turnId: string): void {
331    const open = this.openTurns.get(ctx)
332    const at = open ? open.indexOf(turnId) : -1
333    if (open && at >= 0) open.splice(at, 1)
334  }
335
336  private seen(t: number): void {
337    if (this.started === undefined || t < this.started) this.started = t
338  }
339
340  // Past the cap, drop whole finished main turns, oldest first, with their requests and tools and the
341  // subagents launched from them (and those subagents' own work). Dropping a turn's spans without the
342  // turn would show their time as engine overhead.
343  private trim(): void {
344    if (this.steps.size + this.tools.size <= this.maxSpans) return
345    const target = Math.floor(this.maxSpans * 0.9)
346    const byTurn = new Map<string, { steps: string[]; tools: string[] }>()
347    const byCtx = new Map<string, { steps: string[]; tools: string[]; turns: string[] }>()
348    const slot = <K, V>(map: Map<K, V>, key: K, make: () => V): V => {
349      let value = map.get(key)
350      if (!value) {
351        value = make()
352        map.set(key, value)
353      }
354      return value
355    }
356    for (const step of this.steps.values()) {
357      if (step.ctx === MAIN) slot(byTurn, step.turnId, () => ({ steps: [], tools: [] })).steps.push(step.id)
358      else slot(byCtx, step.ctx, () => ({ steps: [], tools: [], turns: [] })).steps.push(step.id)
359    }
360    for (const tool of this.tools.values()) {
361      if (tool.ctx !== MAIN) slot(byCtx, tool.ctx, () => ({ steps: [], tools: [], turns: [] })).tools.push(tool.id)
362      else if (tool.turnId !== undefined) slot(byTurn, tool.turnId, () => ({ steps: [], tools: [] })).tools.push(tool.id)
363    }
364    for (const turn of this.turns.values()) {
365      if (turn.ctx !== MAIN) slot(byCtx, turn.ctx, () => ({ steps: [], tools: [], turns: [] })).turns.push(turn.id)
366    }
367    const launched = new Map<string, string[]>()
368    for (const agent of this.agents.values()) {
369      if (agent.parentToolId !== undefined) slot(launched, agent.parentToolId, () => [] as string[]).push(agent.id)
370    }
371
372    for (const turn of [...this.turns.values()]) {
373      if (this.steps.size + this.tools.size <= target) return
374      if (turn.ctx !== MAIN || turn.end === undefined) continue
375      const own = byTurn.get(turn.id) ?? { steps: [], tools: [] }
376      const steps = [...own.steps]
377      const tools = [...own.tools]
378      const turns = [turn.id]
379      const agents: string[] = []
380      for (let i = 0; i < tools.length; i += 1) {
381        for (const agentId of launched.get(tools[i] as string) ?? []) {
382          if (agents.includes(agentId)) continue
383          agents.push(agentId)
384          const work = byCtx.get(agentId)
385          if (!work) continue
386          steps.push(...work.steps)
387          tools.push(...work.tools)
388          turns.push(...work.turns)
389        }
390      }
391      const busy =
392        steps.some(id => this.openSteps.has(id)) || tools.some(id => this.openTools.has(id)) || agents.some(id => this.openAgents.has(id))
393      if (busy) continue
394      for (const id of steps) this.steps.delete(id)
395      for (const id of tools) this.tools.delete(id)
396      for (const id of agents) this.agents.delete(id)
397      for (const id of turns) this.turns.delete(id)
398      this.droppedTurns += 1
399      this.droppedSpans += steps.length + tools.length + agents.length
400      this.version += 1
401    }
402  }
403}
404
hooks/core/report.ts 107 lines
1import type { Category, Summary } from './analyze.ts'
2import { bar, clip as clipText, fmtCount, fmtMs, pct } from './format.ts'
3import { redactSecrets } from './redact.ts'
4import type { RunningItem } from './profiler.ts'
5
6const ORDER: Category[] = ['model', 'tool', 'subagent', 'engine']
7const LABEL: Record<Category, string> = {
8  model: 'Model response wait',
9  tool: 'Tools',
10  subagent: 'Subagents (blocking)',
11  engine: 'Engine/other (inferred)',
12}
13const SHORT: Record<Category, string> = { model: 'model', tool: 'tools', subagent: 'subagents', engine: 'engine/other' }
14const clip = (text: string, n: number): string => clipText(redactSecrets(text), n)
15
16export type PaneLine = { text: string; bold?: boolean; dim?: boolean }
17
18export function renderReport(sum: Summary): string {
19  const wall = sum.wallMs
20  const lines = [`Agent Profiler · ${sum.scope === 'turn' ? 'last turn' : 'session'} · ${sum.turns} turn(s) · ${fmtMs(wall)} agent time`]
21  if (sum.turns === 0) {
22    lines.push('No turns recorded yet.')
23    return lines.map(redactSecrets).join('\n')
24  }
25  if (sum.scope === 'session' && sum.droppedTurns > 0) {
26    lines.push(`Covers the last ${sum.turns} turn(s); ${sum.droppedTurns} older turn(s) dropped (already exported).`)
27  }
28  lines.push('', 'Where the time went (exclusive; adds up to agent time)')
29  for (const cat of ORDER) {
30    const ms = sum.exclusive[cat]
31    lines.push(`  ${LABEL[cat].padEnd(24)} ${fmtMs(ms).padStart(7)} ${pct(ms, wall).padStart(4)}  ${bar(wall ? ms / wall : 0)}`)
32  }
33
34  const m = sum.model
35  lines.push(
36    '',
37    `Model requests [observed] ${m.requests} · TTFT avg ${fmtMs(m.ttftAvg)} / p95 ${fmtMs(m.ttftP95)} · thinking stream ${fmtMs(m.thinkingMs)} · output stream ${fmtMs(m.outputMs)}`,
38    `  tokens [reported] in ${fmtCount(m.inputTokens)} (cache read ${fmtCount(m.cacheReadTokens)}) · out ${fmtCount(m.outputTokens)}${m.tokensPerSec === null ? '' : ` · ${Math.round(m.tokensPerSec)} tok/s`}`,
39  )
40
41  const t = sum.tools
42  const parallel = t.unionMs > 0 ? (t.sumMs / t.unionMs).toFixed(1) : '1.0'
43  lines.push(
44    '',
45    `Tools ${t.calls} call(s) · exec ${fmtMs(t.execMs)} [measured] · approval wait ${fmtMs(t.permissionMs)} · overhead ${fmtMs(t.overheadMs)} [inferred] · parallelism ${parallel}×${t.errors ? ` · ${t.errors} error(s)` : ''}${t.denied ? ` · ${t.denied} denied` : ''}`,
46  )
47  for (const row of t.slowest) {
48    const wait = row.waitMs >= 1_000 ? ` (wait ${fmtMs(row.waitMs)})` : ''
49    const where = row.ctx === 'main' ? '' : ` [agent ${row.ctx.slice(0, 8)}]`
50    lines.push(`  ${fmtMs(row.ms).padStart(7)}  ${clip(row.label, 70)}${wait}${where}`)
51  }
52
53  if (sum.bash.byCategory.length) {
54    lines.push('', 'Bash by category [measured]')
55    for (const row of sum.bash.byCategory) lines.push(`  ${row.category.padEnd(8)} ${fmtMs(row.ms).padStart(7)}  ${row.calls}×`)
56  }
57  if (sum.reads.length) {
58    lines.push('', 'Files read more than once')
59    for (const row of sum.reads) lines.push(`  ${String(row.reads).padStart(3)}×  ${clip(row.path, 70)}${row.redundant ? ` (${row.redundant}× unchanged)` : ''}`)
60  }
61  if (sum.agents.length) {
62    lines.push('', 'Subagents')
63    for (const a of sum.agents) {
64      lines.push(`  ${fmtMs(a.wallMs).padStart(7)}  ${a.agentType} ${a.blocking ? 'blocking' : 'background'} · model ${fmtMs(a.modelMs)} · tools ${fmtMs(a.toolMs)} · ${a.requests} req / ${a.tools} tool(s)${a.done ? '' : ' · running'}`)
65    }
66  }
67  if (sum.findings.length) {
68    lines.push('', 'Findings')
69    for (const finding of sum.findings) lines.push(`  • ${finding}`)
70  }
71  lines.push(
72    '',
73    'observed = timed by this mod at event boundaries · measured = timed by Claude Code · reported = API usage · inferred = remainder.',
74    "Model time is how long the agent waited for the response, not the model's internal compute time.",
75  )
76  if (sum.incomplete) lines.push(`${sum.incomplete} span(s) still open.`)
77  return lines.map(redactSecrets).join('\n')
78}
79
80export function statusLine(sum: Summary, running: RunningItem[]): string {
81  const wall = sum.wallMs
82  const parts = [`⏱ model ${pct(sum.exclusive.model, wall)}`, `tools ${pct(sum.exclusive.tool, wall)}`]
83  if (sum.exclusive.subagent > 0) parts.push(`agents ${pct(sum.exclusive.subagent, wall)}`)
84  const top = running.find(item => item.kind !== 'agent') ?? running[0]
85  if (top && top.ms >= 1_000) parts.push(`▶ ${clip(top.label, 40)} ${fmtMs(top.ms)}`)
86  return parts.join(' · ')
87}
88
89export function paneLines(sum: Summary, running: RunningItem[], width: number): PaneLine[] {
90  const w = Math.max(30, width)
91  const out: PaneLine[] = [{ text: `${fmtMs(sum.wallMs)} agent time · ${sum.turns} turn(s)`, bold: true }]
92  for (const cat of ORDER) {
93    const share = sum.wallMs ? sum.exclusive[cat] / sum.wallMs : 0
94    out.push({ text: `${SHORT[cat].padEnd(12)} ${bar(share, Math.min(20, w - 20))} ${pct(sum.exclusive[cat], sum.wallMs).padStart(4)}` })
95  }
96  out.push({ text: '' }, { text: 'Running', bold: true })
97  if (running.length === 0) out.push({ text: '  idle', dim: true })
98  for (const item of running.slice(0, 5)) out.push({ text: clip(`  ${fmtMs(item.ms).padStart(6)} ${item.label}`, w) })
99  out.push({ text: '' }, { text: 'Slowest tools', bold: true })
100  for (const row of sum.tools.slowest) out.push({ text: clip(`  ${fmtMs(row.ms).padStart(6)} ${row.label}`, w) })
101  if (sum.findings.length) {
102    out.push({ text: '' }, { text: 'Findings', bold: true })
103    for (const finding of sum.findings.slice(0, 4)) out.push({ text: clip(`• ${finding}`, w * 2) })
104  }
105  return out
106}
107
hooks/core/classify.ts 182 lines
1export type BashCategory = 'test' | 'build' | 'install' | 'git' | 'search' | 'other'
2
3// Blank out single/double quoted strings and $(...) bodies before splitting
4function blankOutStringLiterals(command: string): string {
5  let result = ''
6  let i = 0
7
8  while (i < command.length) {
9    // Single-quoted string: no escaping inside
10    if (command[i] === "'") {
11      result += "'"
12      i++
13      while (i < command.length && command[i] !== "'") {
14        result += ' '
15        i++
16      }
17      if (i < command.length) {
18        result += "'"
19        i++
20      }
21    }
22    // Double-quoted string: escaping possible
23    else if (command[i] === '"') {
24      result += '"'
25      i++
26      while (i < command.length && command[i] !== '"') {
27        if (command[i] === '\\' && i + 1 < command.length) {
28          result += '  '
29          i += 2
30        } else {
31          result += ' '
32          i++
33        }
34      }
35      if (i < command.length) {
36        result += '"'
37        i++
38      }
39    }
40    // $(...) substitution
41    else if (command[i] === '$' && i + 1 < command.length && command[i + 1] === '(') {
42      result += '  '
43      i += 2
44      let depth = 1
45      while (i < command.length && depth > 0) {
46        if (command[i] === '(') {
47          depth++
48        } else if (command[i] === ')') {
49          depth--
50        }
51        result += depth === 0 ? ')' : ' '
52        i++
53      }
54    } else {
55      result += command[i]
56      i++
57    }
58  }
59
60  return result
61}
62
63// Normalise: strip leading env vars and wrappers
64function normalise(segment: string): string {
65  if (typeof segment !== 'string') return ''
66
67  let s = segment.trim()
68  const wrappers = ['pnpm exec', 'poetry run', 'yarn dlx', 'uv run', 'npx', 'bunx', 'env', 'time', 'sudo']
69
70  let changed = true
71  while (changed) {
72    changed = false
73
74    // Strip leading env var assignments (VAR=value ...)
75    const envMatch = s.match(/^([A-Za-z_][A-Za-z0-9_]*=\S+\s+)+/)
76    if (envMatch) {
77      s = s.slice(envMatch[0].length).trim()
78      changed = true
79      continue
80    }
81
82    // Strip leading wrappers
83    for (const wrapper of wrappers) {
84      if (s.startsWith(wrapper + ' ')) {
85        s = s.slice(wrapper.length + 1).trim()
86        changed = true
87        break
88      }
89    }
90  }
91
92  return s
93}
94
95// Classify gradle/gradlew/mvn commands by analyzing task tokens
96function classifyGradleMvn(segment: string): BashCategory {
97  const tokens = segment.split(/\s+/)
98
99  for (let i = 0; i < tokens.length; i++) {
100    const token = tokens[i] ?? ''
101
102    // Skip if it starts with - (flag or option)
103    if (token.startsWith('-')) {
104      // Special case: if this is -x and next token is test, skip both
105      if (token === '-x' && i + 1 < tokens.length && tokens[i + 1] === 'test') {
106        i++ // skip the test token too
107      }
108      continue
109    }
110
111    // Check if this is a test task
112    if (token === 'test' || token === 'verify' || token === 'check' || token.endsWith(':test')) {
113      return 'test'
114    }
115  }
116
117  return 'build'
118}
119
120const RULES: [BashCategory, RegExp][] = [
121  ['test', /^(jest|vitest|mocha|pytest|tox|nox|rspec|phpunit|ctest|nosetests|bats|karma|ava|jasmine)\b/],
122  ['test', /^cypress\s+run\b/],
123  ['test', /^playwright\s+test\b/],
124  ['test', /^(npm|bun)\s+(run\s+)?test\b/],
125  ['test', /^npm\s+t\b/],
126  ['test', /^(pnpm|yarn)\s+((-r|--filter\s+\S+)\s+)?(run\s+)?test\b/],
127  ['test', /^(go|cargo|deno|dotnet|mix|swift)\s+test\b/],
128  ['test', /^cargo\s+nextest\s+run\b/],
129  ['test', /^node\s+--test\b/],
130  ['test', /^(python|python3)\s+-m\s+(unittest|pytest)\b/],
131  ['test', /^make\s+(test|check)\b/],
132  ['test', /^claude\s+plugin\s+test\b/],
133  ['install', /^(npm|pnpm|yarn|bun)\s+(install|i|add|ci)\b/],
134  ['install', /^yarn\s*$/],
135  ['install', /^(pip|pip3)\s+install\b/],
136  ['install', /^uv\s+(pip|sync|add)\b/],
137  ['install', /^poetry\s+install\b/],
138  ['install', /^brew\s+install\b/],
139  ['install', /^(apt|apt-get)\s+install\b/],
140  ['install', /^cargo\s+(add|install|fetch)\b/],
141  ['install', /^go\s+(get|mod\s+download)\b/],
142  ['install', /^bundle\s+install\b/],
143  ['build', /^(tsc|webpack|esbuild|rollup|make|cmake|ninja|bazel)\b/],
144  ['build', /^(npm|pnpm|yarn|bun)\s+(run\s+)?build\b/],
145  ['build', /^vite\s+build\b/],
146  ['build', /^(cargo|go|swift|dotnet)\s+build\b/],
147  ['build', /^docker\s+build\b/],
148  ['git', /^(git|gh)\b/],
149  ['search', /^(rg|grep|ag|ack|find|fd|ls|tree|cat|head|tail|wc)\b/],
150]
151
152const RANK: BashCategory[] = ['test', 'build', 'install', 'git', 'search', 'other']
153
154function classifySegment(segment: string): BashCategory {
155  const normalized = normalise(segment)
156
157  // Special handling for gradle/mvn commands
158  const cmd = normalized.replace(/^\.\//, '').split(/\s+/)[0]
159  if (cmd === 'gradle' || cmd === 'gradlew' || cmd === 'mvn') {
160    return classifyGradleMvn(normalized)
161  }
162
163  return RULES.find(([, pattern]) => pattern.test(normalized))?.[0] ?? 'other'
164}
165
166export function classifyCommand(command: string): BashCategory {
167  if (typeof command !== 'string') return 'other'
168
169  const blanked = blankOutStringLiterals(command)
170  const segments = blanked
171    .split(/&&|\|\||;|\||\n|[&](?![&])/)
172    .map(s => s.trim())
173    .filter(Boolean)
174
175  let best: BashCategory = 'other'
176  for (const segment of segments) {
177    const category = classifySegment(segment)
178    if (RANK.indexOf(category) < RANK.indexOf(best)) best = category
179  }
180  return best
181}
182
hooks/core/format.ts 28 lines
1export function fmtMs(ms: number): string {
2  if (!Number.isFinite(ms) || ms < 0) return '-'
3  if (ms < 1_000) return `${Math.round(ms)}ms`
4  if (ms < 60_000) return `${(ms / 1_000).toFixed(1)}s`
5  const minutes = Math.floor(ms / 60_000)
6  const seconds = Math.floor((ms % 60_000) / 1_000)
7  return `${minutes}m${String(seconds).padStart(2, '0')}s`
8}
9
10export function pct(part: number, whole: number): string {
11  // part * 100 first: (6050 / 10000) * 100 is 60.49999… in floating point.
12  return whole > 0 ? `${Math.round((part * 100) / whole)}%` : '0%'
13}
14
15export function clip(text: string, n: number): string {
16  const line = text.replace(/[\r\n\t]+/g, ' ')
17  return line.length <= n ? line : `${line.slice(0, Math.max(0, n - 1))}…`
18}
19
20export function bar(share: number, width = 10): string {
21  const filled = Math.max(0, Math.min(width, Math.round(share * width)))
22  return '█'.repeat(filled) + '░'.repeat(width - filled)
23}
24
25export function fmtCount(n: number): string {
26  return n >= 1_000 ? `${(n / 1_000).toFixed(1)}k` : String(n)
27}
28
hooks/core/types.ts 70 lines
1export type Usage = {
2  input_tokens: number
3  output_tokens: number
4  cache_read_input_tokens: number
5  cache_creation_input_tokens: number
6  model?: string
7}
8
9export type ToolInputSummary = {
10  command?: string
11  description?: string
12  path?: string
13  range?: string
14  pattern?: string
15  subagentType?: string
16}
17
18export type TurnRec = { id: string; ctx: string; start: number; end?: number; reason?: string; prompt: string }
19
20export type StepRec = {
21  id: string
22  ctx: string
23  turnId: string
24  index: number
25  model: string
26  effort?: string
27  start: number
28  firstContent?: number
29  thinkFirst?: number
30  thinkLast?: number
31  outFirst?: number
32  end?: number
33  usage?: Usage
34  stopReason?: string
35}
36
37export type ToolRec = {
38  id: string
39  ctx: string
40  turnId?: string
41  tool: string
42  input: ToolInputSummary
43  start: number
44  end?: number
45  execMs?: number
46  decision?: string
47  isError?: boolean
48  denied?: boolean
49  launchedAgentId?: string
50  launchedAsync?: boolean
51}
52
53export type AgentRec = { id: string; agentType: string; start: number; end?: number; parentToolId?: string }
54
55export type Snapshot = {
56  sessionId: string
57  now: number
58  turns: TurnRec[]
59  steps: StepRec[]
60  tools: ToolRec[]
61  agents: AgentRec[]
62  // Earliest start ever recorded, including spans dropped since.
63  started?: number
64  // Whole main turns dropped past the span cap, and the requests, tools and agents that went with them.
65  droppedTurns: number
66  droppedSpans: number
67}
68
69export type Outcome = { denied: boolean; isError: boolean; launchedAgentId?: string; launchedAsync?: boolean }
70
hooks/core/ids.ts 25 lines
1const FNV_OFFSET = 0xcbf29ce484222325n
2const FNV_PRIME = 0x100000001b3n
3const MASK = 0xffffffffffffffffn
4
5export function fnv1a64(text: string): string {
6  let hash = FNV_OFFSET
7  for (const byte of new TextEncoder().encode(text)) {
8    hash ^= BigInt(byte)
9    hash = (hash * FNV_PRIME) & MASK
10  }
11  return hash.toString(16).padStart(16, '0')
12}
13
14// OTLP rejects an all-zero span id.
15export function spanId(kind: string, key: string): string {
16  const id = fnv1a64(`${kind}:${key}`)
17  return id === '0000000000000000' ? '0000000000000001' : id
18}
19
20export function traceIdFromSession(sessionId: string): string {
21  const hex = sessionId.replace(/-/g, '').toLowerCase()
22  if (/^[0-9a-f]{32}$/.test(hex) && !/^0+$/.test(hex)) return hex
23  return fnv1a64(`trace:${sessionId}`) + fnv1a64(`trace2:${sessionId}`)
24}
25
hooks/core/redact.ts 31 lines
1// Canonical source; run node scripts/sync-redactors.mjs after editing.
2// Best-effort removal of obvious secrets from command lines before they are exported.
3const VALUE = String.raw`("(?:\\[\s\S]|[^"\\])*"|'[^']*'|(?:\\[\s\S]|[^\s'"\\])+)`
4const HEADER = String.raw`(?:authorization|[a-z0-9][a-z0-9-]*-(?:key|token|secret))`
5// Only match user:password arguments, leaving username-only options (e.g. mysql -u) alone.
6const CREDENTIAL = String.raw`("(?:\\[\s\S]|[^":\\])*:(?:\\[\s\S]|[^"\\])*"|'[^':]*:[^']*'|[^\s'":]*:[^\s'"]*)`
7const RULES: [RegExp, string][] = [
8  // Shell-quoted headers must be handled before key/value rules: an escaped quote is
9  // part of the secret, while the opposite quote is ordinary data inside this shell word.
10  [new RegExp(String.raw`("` + HEADER + String.raw`\s*:\s*)(?:\\[\s\S]|[^"\\])*"`, 'gi'), '$1[REDACTED]"'],
11  [new RegExp(String.raw`('` + HEADER + String.raw`\s*:\s*)[^']*'`, 'gi'), "$1[REDACTED]'"],
12  [new RegExp(String.raw`(\b` + HEADER + String.raw`\s*:\s*)(?:\\[\s\S]|[^'"\r\n\\])+`, 'gi'), '$1[REDACTED]'],
13  [new RegExp(String.raw`((?:["']?)(?:password|passwd|pwd|token|(?:access|refresh|id|session|auth)[_-]?token|(?:api|access|secret|private)[_-]?key|client[_-]?secret|secret|authorization|credentials?|cookies?)(?:["']?)\s*:\s*)` + VALUE, 'gi'), '$1[REDACTED]'],
14  [/(\bbearer\s+)[A-Za-z0-9._~+/=-]+/gi, '$1[REDACTED]'],
15  [new RegExp(String.raw`(--(?:password|token|api-key|secret)(?:=|\s+))` + VALUE, 'gi'), '$1[REDACTED]'],
16  [/([a-z][a-z0-9+.-]*:\/\/[^\s/:@'"]*:)[^\s/@'"]*@/gi, '$1[REDACTED]@'],
17  [new RegExp(String.raw`(\s(?:--user(?:=|\s+)|-u\s*))` + CREDENTIAL, 'g'), '$1[REDACTED]'],
18  [/(\bmysql\w*\b[^\n;&|]*?\s-p)(?=\S)("[^"]*"|'[^']*'|\S+)/g, '$1[REDACTED]'],
19  [new RegExp(String.raw`\b([A-Za-z0-9_]*(?:KEY|TOKEN|SECRET|PASSWORD)[A-Za-z0-9_]*)=` + VALUE, 'gi'), '$1=[REDACTED]'],
20]
21
22export function redactSecrets(text: string): string {
23  return RULES.reduce((out, [pattern, replacement]) => out.replace(pattern, replacement), text)
24}
25
26// Match complete key names, including common camelCase/underscore/hyphen spellings.
27// Do not match ordinary names such as token_count or keyboard.
28export function isSecretKey(key: string): boolean {
29  return /^(?:password|passwd|pwd|authorization|proxyauthorization|apikey|accesskey|secretkey|privatekey|clientsecret|secret|token|accesstoken|refreshtoken|idtoken|sessiontoken|authtoken|credential|credentials|cookie|setcookie)$/i.test(key.replace(/[_\s-]/g, '')) || /^[a-z0-9][a-z0-9-]*-(?:key|token|secret)$/i.test(key)
30}
31