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

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.
Every span and metric carries agent_profiler.observability. The mod never claims to measure "inference time"; it reports what the client can observe.
| Grade | Meaning | Example |
|---|---|---|
measured | Value measured and handed over by the engine | classic.PostToolUse.duration_ms (tool execution time) |
observed | Interval the mod timed in-process from event boundaries | turn.step send, first chunk, end; tool.call entry to return |
reported | Value reported by the API | usage.output_tokens, cache read/creation tokens |
inferred | Remainder computed from the values above | tool 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.
/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.
| Command | What it does |
|---|---|
/profile | Markdown report of the whole session (time categories, tool/model stats, repeated reads, subagents, findings) |
/profile turn | The same report for the last turn only |
/profile-pane | Opens the live pane (in-flight requests and tools, category bars, recent findings) |
/profile-export | Writes 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.
Set in the /plugin settings menu or in settings pluginConfigs.
| Key | Default | Meaning |
|---|---|---|
otlpEndpoint | "" | OTLP/HTTP base URL, e.g. http://localhost:4318. The mod POSTs to {endpoint}/v1/traces. Empty means file only. |
outputDir | ~/.claude/agent-profiler | Where trace files are written, one folder per session (see below). |
exportCommandText | false | Include turn prompts, Bash command lines and search patterns in exported traces (files and POSTs), with obvious secrets redacted. |
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.
| File | Written | Contents |
|---|---|---|
<loadId>-<seq>.otlp.json (seq = 0001, 0002, ...) | after every turn.complete, and at session.end | Per-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.json | by /profile-export | A 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.
Per span: name, start/end time, parent, status, and these attributes.
service.name=claude-code, session.id, agent_profiler.version.agent_profiler.turn.reason; agent_profiler.turn.prompt (first 120 characters) only with exportCommandText.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.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.invoke_agent <type>): agent id and type, whether it ran async.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.
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.
| Environment | Hooks, recording, export | Pane / status line | /profile text |
|---|---|---|---|
Terminal claude | yes | yes | yes |
| Desktop Code tab | yes | yes | yes |
| VS Code chat panel | yes | no (drawing is not shown) | yes |
claude -p / SDK | yes | no | yes |
Reports, panels and display labels mask supported credential formats before truncation; this does not change the underlying analysis. Existing saved files are not rewritten.
/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.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.invoke_agent span is still a child of execute_tool Agent but outlives it, and the completion notification starts an extra main turn.CLAUDE_CODE_ENABLE_FUNCTION_HOOKS=1. Other versions may differ.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.
hooks/register.tsx 364 lines1import 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}
364hooks/core/analyze.ts 344 lines1import { 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}
344hooks/core/cache.ts 17 lines1import { 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}
17hooks/core/export.ts 54 lines1import 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}
54hooks/core/otlp.ts 210 lines1import { 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}
210hooks/core/profiler.ts 404 lines1import 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}
404hooks/core/report.ts 107 lines1import 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}
107hooks/core/classify.ts 182 lines1export 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}
182hooks/core/format.ts 28 lines1export 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}
28hooks/core/types.ts 70 lines1export 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 }
70hooks/core/ids.ts 25 lines1const 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}
25hooks/core/redact.ts 31 lines1// 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