diff --git a/README.md b/README.md index 05672a1..8dd2cdc 100644 --- a/README.md +++ b/README.md @@ -519,19 +519,21 @@ traces facts --otlp spans.otlp.jsonl --out facts.json | Fact | What it is | |---|---| -| `toolCalls` | TOOL spans the agent actually invoked. Synthesized subagent lifecycle spans are excluded and counted separately in `synthesizedToolSpans`, so the total is not high by the number of subagents | +| `toolCalls` | TOOL spans **this session's agent** actually invoked. Synthesized lifecycle spans are excluded and counted in `synthesizedToolSpans`, so the total is not high by the number of subagents; calls a spawned subagent made are excluded and counted in `subagentToolSpans` | | `toolCallsByName` | the same calls by tool name, so a category decision is the reader's, not a guess | -| `subagents` | every `spawn_agent` call with the task name the adapter recorded | +| `subagentToolSpans` | TOOL spans excluded because a subagent, not this agent, made the call. Zero on a trace that carries no subagent records | +| `subagents` | every subagent-spawning call with the task name the adapter recorded | | `pullRequests` | the pull requests the commands created and merged, each named by number or head branch, with the command span and how the identity was joined. Scanned the way a shell reads the script, so a `gh pr create` inside a heredoc body is not a command that ran | | `humanTurns` | `user.prompt` turns a person typed into this session, in order, with the timestamp. Inherited fork or compaction history, harness-injected blocks, and a second record of the same turn are excluded — each listed in `excludedTurns` with its reason and span ids, never silently dropped. `turnsByActor` shows every turn by actor so the filter is checkable | | `finalMessages` | the last message of the session's own agent, and of each subagent task, kept apart | -| `changedFiles` | paths named by patch headers and file-editing tool arguments, with the operation | -| `firstRecordAt` / `lastRecordAt` | the trace's earliest span start and latest span end | +| `changedFiles` | paths the harness recorded for the changes it applied, plus paths named by patch headers and file-editing tool arguments, with the operation | +| `firstRecordAt` / `lastRecordAt` | the earliest span start and latest span end among this session's own records — a subagent that outlives the session does not stretch its window | | `unreadRecords` | records the session reader could not parse, from the session's integrity receipt | | `tokenTotal` | the harness's own cumulative token total, when a span carries `traces.session.total_tokens` | -Two rules hold for every field: +Three rules hold for every field: +- **Every fact is about this session's own agent.** Some harnesses fold a spawned agent's transcript into the parent's trace, so a trace can carry both what this agent did and what a child it spawned did. The child's work is named in `subagents` and counted in `subagentToolSpans`; it is never added to the parent's totals. - **Every fact names its span ids.** `spanIds` lists the spans the value was computed from, so any number here can be opened and checked. The sheet itself is not a span and cannot be cited. - **A fact the spans cannot support is `null` with its reason.** It is never guessed, and never a silent zero. `partial` marks a measured value that is known to be incomplete — a truncated patch, or a list above the entry cap. diff --git a/docs/trace-analysts.md b/docs/trace-analysts.md index 332ba8b..977be2b 100644 --- a/docs/trace-analysts.md +++ b/docs/trace-analysts.md @@ -192,21 +192,23 @@ The sheet is that extraction, made part of the tool. | Field | Value | | --- | --- | -| `toolCalls` | TOOL spans the agent invoked. Synthesized subagent lifecycle spans are excluded and counted in `synthesizedToolSpans` | +| `toolCalls` | TOOL spans **this session's agent** invoked. Synthesized lifecycle spans are excluded and counted in `synthesizedToolSpans`; calls made by a spawned subagent are excluded and counted in `subagentToolSpans` | | `toolCallsByName` | the same calls by tool name | -| `subagents` | every `spawn_agent` call with the task name from `traces.codex.spawn_agent_path` | +| `subagentToolSpans` | TOOL spans excluded because a subagent, not this agent, made the call | +| `subagents` | every subagent-spawning call, with the task name the call recorded | | `pullRequests` | pull requests the commands created and merged, each named by number or head branch, with the command span and the join evidence | | `humanTurns` | `user.prompt` turns a person typed into this session, in order, with timestamps | | `excludedTurns` | every `user.prompt` turn `humanTurns` left out, grouped by the reason, with the span ids | | `turnsByActor` | every `user.prompt` turn by actor, so the human filter is checkable | | `finalMessages` | the last message of the session's own agent, and of each subagent task, separately | -| `changedFiles` | paths from `*** Add/Update/Delete/Move to File:` patch headers and from file-editing tool arguments | -| `firstRecordAt`, `lastRecordAt` | the trace's earliest span start and latest span end | +| `changedFiles` | paths the harness recorded for its own file changes, plus paths from `*** Add/Update/Delete/Move to File:` patch headers and from file-editing tool arguments | +| `firstRecordAt`, `lastRecordAt` | the earliest span start and latest span end among this session's own records | | `unreadRecords` | records the session reader could not parse | | `tokenTotal` | the harness's cumulative total, when a span carries `traces.session.total_tokens` | -Two rules hold for every field. +Three rules hold for every field. +- **Every fact is about this session's own agent.** Some harnesses fold a spawned agent's transcript into the parent's trace — Claude Code writes one file per subagent under the session directory and the adapter reads them all — so a trace can carry both what this agent did and what a child it spawned did. The child's work is named in `subagents` and counted in `subagentToolSpans`, never added to the parent's totals. On a trace with no subagent records every one of those counts is zero. - **Every fact names the span ids it came from.** A reader can open those spans and check the number. The sheet is not a span and cannot be cited. - **A fact the spans cannot support is `null` with a stated reason.** It is never guessed and never a silent zero. `partial` marks a measured value known to be incomplete. diff --git a/src/adapters/claude.ts b/src/adapters/claude.ts index bc09710..a318672 100644 --- a/src/adapters/claude.ts +++ b/src/adapters/claude.ts @@ -50,13 +50,74 @@ import { type WorkflowRunBinding, type WorkflowRunReference, } from './claude-workflow.js' -import { capText, userPromptSpan } from './conversation.js' +import { ACTOR_ATTR, capText, userPromptSpan, type Actor } from './conversation.js' +import { + SUBAGENT_SPAN_ATTR, + SUBAGENT_SPAN_COUNT_ATTR, + SUBAGENT_SPAWN_ATTR, + SUBAGENT_SPAWN_TASK_ATTR, + SUBAGENT_TASK_ATTR, + SYNTHESIZED_SOURCE_ATTR, + SYNTHESIZED_SPAN_ATTR, + isSubagentSpan, +} from './provenance.js' import { toolIoAttributes } from './tool-io.js' import { appendSourceAttributes, sourceOf, textSources, SOURCE_ATTRIBUTE_PREFIX, type SourceReferences } from '../source-location.js' const SERVICE = 'claude-code' const EPOCH = new Date(0).toISOString() +/** + * Claude Code's own label for who produced a record: `human` for a person at + * the keyboard, and a namespaced kind for everything the harness or another + * agent put in the conversation (`task-notification`, `peer`, …). + * + * This is the structural signal, so it decides on its own — it is what the + * harness recorded, not what the text looks like. A transcript that stamps it + * at all stamps it on every record a person produced, so inside such a + * transcript a user record WITHOUT it is not a human turn however human its + * text reads: `[Request interrupted by user]` is written by the CLI, and + * `/login` is the CLI's record of a session + * command rather than a message to the agent. {@link ORIGIN_EVIDENCE_ATTR} + * marks each turn the second rule reclassified, so the reading is checkable. + * Older transcripts carry no `origin` at all and the text heuristics in + * `actor.ts` answer instead. + */ +const HUMAN_ORIGIN = 'human' + +/** Why a turn that reads human was not counted as one. */ +const ORIGIN_EVIDENCE_ATTR = 'traces.claude.actor_evidence' + +/** `true` on a `user.prompt` span whose record carried a recorded origin. */ +const ORIGIN_RECORDED_ATTR = 'traces.claude.origin_recorded' + +/** Claude Code's own name for the kind of record an origin describes. */ +const ORIGIN_KIND_ATTR = 'traces.claude.origin_kind' + +/** + * A slash command as the transcript stores it: the CLI wraps the line a person + * typed in `` and `` (plus a `` + * display label it did not type). Rejoining the two recovers the typed line, + * which is what a reader counting human turns is looking for. + */ +const COMMAND_NAME = /([\s\S]*?)<\/command-name>/ +const COMMAND_ARGS = /([\s\S]*?)<\/command-args>/ + +/** + * The tool input field with which Claude Code's Task tool selects the agent to + * run. A tool call carrying it spawned a subagent, whatever the tool is named: + * the field is the harness's own signal, so no allowlist of tool names decides + * what counts as a spawn. + */ +const SPAWN_TYPE_KEY = 'subagent_type' + +/** The Task tool's short name for the work it hands the child. */ +const SPAWN_DESCRIPTION_KEY = 'description' + +const SPAWN_TYPE_ATTR = 'traces.claude.subagent_type' +const SUBAGENT_TRANSCRIPT_ATTR = 'traces.claude.subagent_transcript' +const SUBAGENT_AGENT_ID_ATTR = 'traces.claude.subagent_agent_id' + const CLAUDE_SOURCE_TRACE_ID = 'traces.claude.source_trace_id' const CLAUDE_SOURCE_SPAN_ID = 'traces.claude.source_span_id' const CLAUDE_SOURCE_PARENT_SPAN_ID = 'traces.claude.source_parent_span_id' @@ -90,6 +151,9 @@ interface ClaudeEvent { isSidechain?: boolean isMeta?: boolean userType?: string + origin?: { kind?: unknown } + /** `file-history-delta`: the path the harness backed up before changing it. */ + trackingPath?: string message?: { id?: string role?: string @@ -109,6 +173,10 @@ interface ClaudeEvent { toolName?: string exitCode?: number stderr?: string + /** `queued_command`: the message a person sent while the turn was running. */ + prompt?: unknown + origin?: { kind?: unknown } + timestamp?: string } toolUseResult?: { runId?: unknown @@ -174,8 +242,16 @@ interface ClaudeStreamState { llmSpanByMessageId: Map llmContentByMessageId: Map> toolCountByMessageId: Map + messageSpanByMessageId: Map step: number sawUserTurn: boolean + /** `user.prompt` spans, so the origin rule can be applied once at the end. */ + promptSpans: OtlpSpan[] + /** Whether any record in this stream carried Claude Code's `origin`. */ + sawRecordedOrigin: boolean + /** Earliest and latest record timestamp consumed, span-producing or not. */ + firstRecordAt: string | null + lastRecordAt: string | null } function createClaudeStream(startStep: number): ClaudeStreamState { @@ -185,8 +261,13 @@ function createClaudeStream(startStep: number): ClaudeStreamState { llmSpanByMessageId: new Map(), llmContentByMessageId: new Map(), toolCountByMessageId: new Map(), + messageSpanByMessageId: new Map(), step: startStep, sawUserTurn: false, + promptSpans: [], + sawRecordedOrigin: false, + firstRecordAt: null, + lastRecordAt: null, } } @@ -224,7 +305,13 @@ type ClaudeEventProjection = cacheWriteInputTokens: number | null content: string | null contentSource?: SourceReferences - tools: Array<{ id: string | null; name: string; attributes: Record }> + tools: Array<{ + id: string | null + name: string + attributes: Record + /** The task a spawn call named. Absent when the call spawned nothing. */ + spawnTask?: string | null + }> } | { kind: 'user' @@ -234,9 +321,24 @@ type ClaudeEventProjection = isSidechain?: boolean isMeta?: boolean userType?: string | null + originKind?: string | null results: ToolResultProjection[] } | { kind: 'attachment'; timestamp: string; result: ToolResultProjection } + | { + /** + * A message a person sent while a turn was running. Claude Code does not + * open a conversation turn for it — it surfaces the text inside the + * running turn as an attachment — so it is a human turn the transcript + * records nowhere else, and a reader counting turns misses it entirely. + */ + kind: 'queued-prompt' + timestamp: string + prompt: string + originKind: string | null + contentSource?: SourceReferences + } + | { kind: 'file-change'; timestamp: string; path: string; contentSource?: SourceReferences } | { kind: 'ignored' } function projectToolResult( @@ -264,10 +366,20 @@ function projectToolResult( function projectClaudeEvent(event: ClaudeEvent): ClaudeEventProjection { const timestamp = event.timestamp ?? EPOCH if (event.type === 'assistant' && event.message) { - const tools: Array<{ id: string | null; name: string; attributes: Record }> = [] + const tools: Array<{ + id: string | null + name: string + attributes: Record + spawnTask?: string | null + }> = [] for (const block of asBlocks(event.message.content)) { if (block.type !== 'tool_use' || !block.name) continue - tools.push({ id: block.id || null, name: block.name, attributes: toolIoAttributes({ input: block.input, inputSource: sourceOf(block, 'input') }) }) + tools.push({ + id: block.id || null, + name: block.name, + attributes: toolIoAttributes({ input: block.input, inputSource: sourceOf(block, 'input') }), + ...(spawnsSubagent(block.input) ? { spawnTask: spawnTaskName(block.input) } : {}), + }) } return { kind: 'assistant', @@ -315,6 +427,7 @@ function projectClaudeEvent(event: ClaudeEvent): ClaudeEventProjection { isSidechain: event.isSidechain === true, isMeta: event.isMeta === true, userType: event.userType ?? null, + originKind: recordedOrigin(event.origin), } : {}), results, @@ -333,9 +446,95 @@ function projectClaudeEvent(event: ClaudeEvent): ClaudeEventProjection { ), } } + if (event.type === 'attachment' && event.attachment?.type === 'queued_command') { + // The queued text is a message body, so it arrives in either shape a + // message body takes: a string, or the content blocks of a message that + // carried an image alongside the words. + const prompt = textOf(event.attachment.prompt) + if (prompt) { + return { + kind: 'queued-prompt', + // The queue records when the person sent it, which is earlier than the + // turn that absorbed it; the sent time is the time of the turn. + timestamp: event.attachment.timestamp ?? timestamp, + prompt, + originKind: recordedOrigin(event.attachment.origin), + contentSource: sourceOf(event.attachment, 'prompt'), + } + } + } + // The harness's own record of a file it changed: it backs the file up before + // the edit lands, so the path here is the one the edit reached rather than + // the one a tool argument asked for. Claude Code states no change kind, so + // the span states none either. + if (event.type === 'file-history-delta' && typeof event.trackingPath === 'string' && event.trackingPath.length > 0) { + return { + kind: 'file-change', + timestamp, + path: event.trackingPath, + contentSource: sourceOf(event, 'trackingPath'), + } + } return { kind: 'ignored' } } +/** + * Who produced a user-role record, preferring the harness's own label. + * + * `recorded` is Claude Code's `origin.kind`. When it is present it decides: + * `human` is a person, and any other kind is the harness or another agent + * putting text in the conversation. Without it the text heuristics answer, as + * they did before Claude Code recorded an origin at all. + */ +function claudeActorFromOrigin( + recorded: string | null | undefined, + fallback: () => Actor, +): Actor { + if (typeof recorded === 'string' && recorded.length > 0) { + return recorded === HUMAN_ORIGIN ? 'human' : 'injected' + } + return fallback() +} + +/** + * The line a person typed, for a turn stored as a slash-command wrapper. + * + * Applied only to a turn the harness attributed to a person: the wrapper is + * how the CLI stores what they typed, so `` plus `` + * IS the text, and reporting the tags instead reports the harness's storage + * format as the human's words. Text carrying no wrapper is returned unchanged, + * and so is a wrapper with no command name. + */ +function typedPromptText(text: string): string { + const name = COMMAND_NAME.exec(text)?.[1]?.trim() + if (!name) return text + const args = COMMAND_ARGS.exec(text)?.[1]?.trim() + return args ? `${name} ${args}` : name +} + +/** Claude Code's `origin.kind`, when the record carries a usable one. */ +function recordedOrigin(origin: { kind?: unknown } | undefined): string | null { + const kind = origin?.kind + return typeof kind === 'string' && kind.length > 0 ? kind : null +} + +/** The task name a spawn call gave its child, when the call named one. */ +function spawnTaskName(input: unknown): string | null { + if (input === null || typeof input !== 'object') return null + const record = input as Record + const described = record[SPAWN_DESCRIPTION_KEY] + if (typeof described === 'string' && described.trim().length > 0) return described.trim() + const type = record[SPAWN_TYPE_KEY] + return typeof type === 'string' && type.trim().length > 0 ? type.trim() : null +} + +/** Whether a tool call selected an agent to run, i.e. spawned a subagent. */ +function spawnsSubagent(input: unknown): boolean { + if (input === null || typeof input !== 'object') return false + const type = (input as Record)[SPAWN_TYPE_KEY] + return typeof type === 'string' && type.trim().length > 0 +} + function indexWorkflowProjection( projection: ClaudeEventProjection, index: WorkflowProjectionIndex, @@ -459,6 +658,7 @@ function consumeClaudeEvent( }) mergeMessageContent(llmSpan, messageId, event.content, state) if (event.content) appendSourceAttributes(llmSpan.attributes, 'content', event.contentSource) + if (event.content) mergeAssistantMessage(event, messageId, llmSpan, ctx, state) for (const tool of event.tools) { const existingTool = tool.id ? state.toolSpanByUseId.get(tool.id) : undefined @@ -479,7 +679,15 @@ function consumeClaudeEvent( agent: ctx.agent, tool: tool.name, step: state.step, - extra: tool.attributes, + extra: { + ...tool.attributes, + ...(tool.spawnTask === undefined + ? {} + : { + [SUBAGENT_SPAWN_ATTR]: true, + ...(tool.spawnTask ? { [SUBAGENT_SPAWN_TASK_ATTR]: tool.spawnTask } : {}), + }), + }, }) state.spans.push(toolSpan) if (tool.id) state.toolSpanByUseId.set(tool.id, toolSpan) @@ -488,28 +696,33 @@ function consumeClaudeEvent( } } else if (event.kind === 'user') { if (event.prompt) { - const actor = claudeActor({ - text: event.prompt, + const actor = claudeActorFromOrigin(event.originKind, () => claudeActor({ + text: event.prompt ?? '', isSidechain: event.isSidechain, isMeta: event.isMeta, userType: event.userType ?? null, isFirstUserTurn: !state.sawUserTurn, - }) + })) state.sawUserTurn = true - state.spans.push( - userPromptSpan({ - traceId: ctx.traceId, - spanId: `${ctx.idPrefix}${uid}:user`, - parentSpanId: ctx.rootParent, - startTime: event.timestamp, - service: SERVICE, - agent: ctx.agent, - step: state.step, - content: event.prompt, - contentSource: event.contentSource, - actor, - }), - ) + if (event.originKind) state.sawRecordedOrigin = true + const prompt = userPromptSpan({ + traceId: ctx.traceId, + spanId: `${ctx.idPrefix}${uid}:user`, + parentSpanId: ctx.rootParent, + startTime: event.timestamp, + service: SERVICE, + agent: ctx.agent, + step: state.step, + content: actor === 'human' ? typedPromptText(event.prompt) : event.prompt, + contentSource: event.contentSource, + actor, + }) + if (event.originKind) { + prompt.attributes[ORIGIN_RECORDED_ATTR] = true + prompt.attributes[ORIGIN_KIND_ATTR] = event.originKind + } + state.spans.push(prompt) + state.promptSpans.push(prompt) state.step += 1 } for (const result of event.results) { @@ -517,6 +730,103 @@ function consumeClaudeEvent( } } else if (event.kind === 'attachment') { backfillResult(state.toolSpanByUseId.get(event.result.toolUseId), event.timestamp, event.result) + } else if (event.kind === 'queued-prompt') { + const actor = claudeActorFromOrigin(event.originKind, () => 'injected') + if (event.originKind) state.sawRecordedOrigin = true + const prompt = userPromptSpan({ + traceId: ctx.traceId, + spanId: `${ctx.idPrefix}${uid}:queued`, + parentSpanId: ctx.rootParent, + startTime: event.timestamp, + service: SERVICE, + agent: ctx.agent, + step: state.step, + content: actor === 'human' ? typedPromptText(event.prompt) : event.prompt, + contentSource: event.contentSource, + actor, + }) + prompt.attributes['traces.claude.queued'] = true + if (event.originKind) { + prompt.attributes[ORIGIN_RECORDED_ATTR] = true + prompt.attributes[ORIGIN_KIND_ATTR] = event.originKind + } + state.spans.push(prompt) + state.promptSpans.push(prompt) + state.step += 1 + } else if (event.kind === 'file-change') { + state.spans.push(span({ + traceId: ctx.traceId, + spanId: `${ctx.idPrefix}${uid}:file-change`, + parentSpanId: ctx.rootParent, + name: 'file.change', + kind: 'CHAIN', + startTime: event.timestamp, + endTime: event.timestamp, + service: SERVICE, + agent: ctx.agent, + step: state.step, + extra: toolIoAttributes({ input: { path: event.path }, inputSource: event.contentSource }), + })) + state.step += 1 + } +} + +/** + * The assistant's prose as its own span, alongside the `llm.turn` that carries + * the call's tokens. + * + * One assistant message arrives as several records while it streams, so the + * span is created once per message id and its content merged, exactly as the + * `llm.turn` above is. A reader asking what the agent said last wants the last + * message, not the last call that happened to carry text. + */ +function mergeAssistantMessage( + event: Extract, + messageId: string, + llmSpan: OtlpSpan, + ctx: ClaudeStreamContext, + state: ClaudeStreamState, +): void { + const existing = state.messageSpanByMessageId.get(messageId) + if (existing) { + includeSpanTimestamp(existing, event.timestamp) + existing.attributes.content = llmSpan.attributes.content + return + } + const messageSpan = span({ + traceId: ctx.traceId, + spanId: `${llmSpan.span_id}:message`, + parentSpanId: llmSpan.span_id, + name: 'message.assistant', + kind: 'CHAIN', + startTime: event.timestamp, + endTime: event.timestamp, + service: SERVICE, + agent: ctx.agent, + step: state.step, + content: typeof llmSpan.attributes.content === 'string' ? llmSpan.attributes.content : '', + contentSource: event.contentSource, + }) + state.spans.push(messageSpan) + state.messageSpanByMessageId.set(messageId, messageSpan) + state.step += 1 +} + +/** + * Apply Claude Code's own origin labelling across a finished stream. + * + * A transcript that records `origin` records it on every message a person + * sent, so inside such a transcript a user record without one is not a human + * turn — however human its text reads. The reclassification is stamped so a + * reader can see which turns it moved and disagree with it span by span. + */ +function applyRecordedOrigins(state: ClaudeStreamState): void { + if (!state.sawRecordedOrigin) return + for (const prompt of state.promptSpans) { + if (prompt.attributes[ACTOR_ATTR] !== 'human') continue + if (prompt.attributes[ORIGIN_RECORDED_ATTR] === true) continue + prompt.attributes[ACTOR_ATTR] = 'injected' + prompt.attributes[ORIGIN_EVIDENCE_ATTR] = 'no_human_origin' } } @@ -551,15 +861,55 @@ function mergeMessageContent( } function finishClaudeStream(state: ClaudeStreamState): ParsedStream { + applyRecordedOrigins(state) return { spans: state.spans, toolSpanByUseId: state.toolSpanByUseId, nextStep: state.step } } -function setRootTimeBounds(root: OtlpSpan, spans: readonly OtlpSpan[]): void { +/** + * Widen the stream's record window to include one record's timestamp. + * + * The window is over RECORDS, not spans: a session's first and last record are + * often ones that produce no span — the file-history snapshot the CLI writes + * when the session opens, the `continued-in` marker it writes when the session + * ends. Reporting the first span instead reports when the agent started, which + * is a different question and a different answer. + */ +function includeRecordTimestamp(state: ClaudeStreamState, timestamp: string | undefined): void { + if (!timestamp) return + const time = Date.parse(timestamp) + if (!Number.isFinite(time)) return + if (state.firstRecordAt === null || time < Date.parse(state.firstRecordAt)) state.firstRecordAt = timestamp + if (state.lastRecordAt === null || time > Date.parse(state.lastRecordAt)) state.lastRecordAt = timestamp +} + +/** + * The session's own record window, on the root span. + * + * A subagent's spans are folded into this trace but belong to the child's + * transcript, so they are not records of this session and do not move its + * window: one measured session ran for 3 h 28 m and its last subagent finished + * 8 minutes later, which is the subagent's end, not the session's. + * `recordWindow` is the window over the session's own records, including the + * ones that produce no span; the spans only widen it when it is absent. + */ +function setRootTimeBounds( + root: OtlpSpan, + spans: readonly OtlpSpan[], + recordWindow: { first: string | null; last: string | null }, +): void { let firstTimestamp: { value: number; source: string } | undefined let lastTimestamp: { value: number; source: string } | undefined + for (const source of [recordWindow.first, recordWindow.last]) { + if (!source) continue + const value = Date.parse(source) + if (!Number.isFinite(value)) continue + if (!firstTimestamp || value < firstTimestamp.value) firstTimestamp = { value, source } + if (!lastTimestamp || value > lastTimestamp.value) lastTimestamp = { value, source } + } + for (const item of spans) { - if (item === root) continue + if (item === root || isSubagentSpan(item.attributes)) continue for (const source of [item.start_time, item.end_time]) { if (!source) continue const value = Date.parse(source) @@ -850,7 +1200,10 @@ export class ClaudeAdapter implements HarnessTraceAdapter { selectedTurnFound = true } } - if (active) consumeClaudeEvent(accepted.projection, accepted.uid, ctx, state) + if (active) { + includeRecordTimestamp(state, event.timestamp) + consumeClaudeEvent(accepted.projection, accepted.uid, ctx, state) + } } options.signal?.throwIfAborted() if (taskScope === 'latest' && !selectedTurnFound) { @@ -897,7 +1250,9 @@ export class ClaudeAdapter implements HarnessTraceAdapter { ) options.signal?.throwIfAborted() const ordered = orderClaudeSpans(root, spans) - setRootTimeBounds(root, ordered) + setRootTimeBounds(root, ordered, { first: state.firstRecordAt, last: state.lastRecordAt }) + const subagentSpans = ordered.filter((item) => isSubagentSpan(item.attributes)).length + if (subagentSpans > 0) root.attributes[SUBAGENT_SPAN_COUNT_ATTR] = subagentSpans normalizeClaudeIds(ordered) return ordered } @@ -1048,8 +1403,15 @@ export class ClaudeAdapter implements HarnessTraceAdapter { const parentAgentMissing = Boolean( agent.meta.parentAgentId && !parsedByAgentId.has(agent.meta.parentAgentId), ) - for (const item of parsed.spans) { + const task = subagentTaskName(agent) + const lifecycle = subagentLifecycleSpan(agent, parsed, traceId, parent, task, subDir) + for (const item of [...parsed.spans, ...(lifecycle ? [lifecycle] : [])]) { if (item.parent_span_id === `root:${traceId}`) item.parent_span_id = parent + // Every span here came from the CHILD's transcript. Marking it says so, + // which is what keeps the parent's tool count, changed files, human + // turns and record window from absorbing work the parent never did. + item.attributes[SUBAGENT_SPAN_ATTR] = true + if (task) item.attributes[SUBAGENT_TASK_ATTR] = task if (agent.parentToolUseId && !parentSpan) { item.attributes['traces.claude.parent_tool_missing'] = true item.attributes['traces.claude.parent_tool_use_id'] = agent.parentToolUseId @@ -1060,6 +1422,80 @@ export class ClaudeAdapter implements HarnessTraceAdapter { } } appendAll(out, parsed.spans) + if (lifecycle) out.push(lifecycle) } } } + +/** The task the parent's spawn call gave this child, as the harness recorded it. */ +function subagentTaskName(agent: ClaudeSubagentFile): string | null { + // The metadata file is untrusted input: a field that is not a string names no + // task, and must not take the parse down. + for (const value of [agent.meta.description, agent.meta.agentType]) { + if (typeof value === 'string' && value.trim().length > 0) return value.trim() + } + return null +} + +/** + * One span standing for a child transcript, so the parent's `Task` call has + * something to point at. + * + * It is synthesized — no model issued it — and it belongs to the subagent's + * scope, so neither the parent's tool count nor the parent's record window + * absorbs it. Its value is evidence: it names the transcript the child's spans + * came from and the window they cover, which is what a reader checking "which + * subagents ran" needs and what the parent's TOOL span alone cannot say. + */ +function subagentLifecycleSpan( + agent: ClaudeSubagentFile, + parsed: ParsedStream, + traceId: string, + parentSpanId: string, + task: string | null, + subDir: string, +): OtlpSpan | undefined { + let first: string | undefined + let last: string | undefined + for (const item of parsed.spans) { + for (const stamp of [item.start_time, item.end_time]) { + const value = Date.parse(stamp) + if (!Number.isFinite(value)) continue + if (first === undefined || value < Date.parse(first)) first = stamp + if (last === undefined || value > Date.parse(last)) last = stamp + } + } + if (first === undefined || last === undefined) return undefined + return span({ + traceId, + // Same prefix as every other span from this transcript, so a reader + // grouping spans by source keeps the anchor with the spans it stands for. + spanId: `${agent.sourceKey}:lifecycle`, + parentSpanId, + name: 'subagent.lifecycle', + kind: 'AGENT', + startTime: first, + endTime: last, + // The transcript records what the child did, not whether the parent + // accepted it; the parent's own tool span carries that status. + status: 'UNSET', + service: SERVICE, + agent: agent.meta.agentType ? `subagent:${agent.meta.agentType}` : 'subagent', + extra: { + ...toolIoAttributes({ + input: { + agent_id: agent.agentId, + ...(agent.meta.agentType ? { subagent_type: agent.meta.agentType } : {}), + ...(task ? { task } : {}), + }, + }), + [SYNTHESIZED_SPAN_ATTR]: true, + [SYNTHESIZED_SOURCE_ATTR]: 'claude.subagent_transcript', + [SUBAGENT_SPAN_ATTR]: true, + ...(task ? { [SUBAGENT_TASK_ATTR]: task } : {}), + ...(agent.meta.agentType ? { [SPAWN_TYPE_ATTR]: agent.meta.agentType } : {}), + [SUBAGENT_AGENT_ID_ATTR]: agent.agentId, + [SUBAGENT_TRANSCRIPT_ATTR]: relative(subDir, agent.file), + }, + }) +} diff --git a/src/adapters/provenance.ts b/src/adapters/provenance.ts index d9a3405..3890ccc 100644 --- a/src/adapters/provenance.ts +++ b/src/adapters/provenance.ts @@ -2,7 +2,7 @@ * Provenance markers for spans an adapter did NOT take from an action the agent * performed inside the parsed scope. * - * Two cases, and both used to be invisible: + * Three cases, and all of them used to be invisible: * * - SYNTHESIZED — the adapter built the span from harness lifecycle events, * not from a call the model issued. A Codex subagent's start/finish stream @@ -13,9 +13,19 @@ * not produce: the prefix a fork copies from its parent, and the history a * `compacted` record retains. Keeping the human's words is the point; * counting them as turns of THIS scope is not. + * - SUBAGENT — the record came from a child agent's OWN transcript, folded + * into the parent's trace by an adapter that reads the whole session tree. + * Claude Code writes one file per spawned agent under the session + * directory and the adapter parses all of them into one trace, so the + * parent's TOOL spans and the children's sat in the same trace with + * nothing to tell them apart: one measured session showed 2,675 tool spans + * where the session's own agent made 332. The subagent did that work; the + * parent did not, and a fact about the parent must not claim it. * - * Both markers are additive attributes. A count that means "what the agent did - * in this scope" filters them out; a reader that wants the context selects them. + * All three markers are additive attributes. A count that means "what the agent + * did in this scope" filters them out; a reader that wants the context selects + * them. They are harness-neutral on purpose: the sheet that reads them must not + * carry a rule per harness. */ /** `true` on a span the adapter synthesized from lifecycle events. */ @@ -38,6 +48,25 @@ export const INHERITED_SPAN_COUNT_ATTR = 'traces.session.inherited_span_count' /** Inherited records the adapter's per-session cap dropped, stamped on the root. */ export const INHERITED_SPANS_OMITTED_ATTR = 'traces.session.inherited_spans_omitted' +/** `true` on a span an adapter read from a subagent's own transcript. */ +export const SUBAGENT_SPAN_ATTR = 'traces.span.subagent' + +/** + * The task the subagent whose record produced this span was given — the brief + * the parent's spawn call named, as the harness recorded it. Absent when the + * harness recorded no name for that child. + */ +export const SUBAGENT_TASK_ATTR = 'traces.span.subagent_task' + +/** Count of subagent spans in the batch, stamped on the root span. */ +export const SUBAGENT_SPAN_COUNT_ATTR = 'traces.session.subagent_span_count' + +/** `true` on the tool call with which this scope's agent spawned a subagent. */ +export const SUBAGENT_SPAWN_ATTR = 'traces.agent.spawn' + +/** The task name that spawn call gave the child. Absent when it named none. */ +export const SUBAGENT_SPAWN_TASK_ATTR = 'traces.agent.spawn_task' + export function isSynthesizedSpan(attributes: Readonly>): boolean { return attributes[SYNTHESIZED_SPAN_ATTR] === true } @@ -45,3 +74,11 @@ export function isSynthesizedSpan(attributes: Readonly>) export function isInheritedSpan(attributes: Readonly>): boolean { return attributes[INHERITED_SPAN_ATTR] === true } + +export function isSubagentSpan(attributes: Readonly>): boolean { + return attributes[SUBAGENT_SPAN_ATTR] === true +} + +export function isSubagentSpawn(attributes: Readonly>): boolean { + return attributes[SUBAGENT_SPAWN_ATTR] === true +} diff --git a/src/session-facts.ts b/src/session-facts.ts index 70950a4..848c46c 100644 --- a/src/session-facts.ts +++ b/src/session-facts.ts @@ -25,6 +25,15 @@ * filtered — a `user.prompt` turn that is not a human turn of this session * — is reported beside the count with the reason, never silently dropped. * + * Every fact below is about THE SESSION'S OWN AGENT. Some harnesses fold a + * spawned agent's transcript into the parent's trace (Claude Code writes one + * file per subagent under the session directory and the adapter reads them + * all), so a trace can hold two kinds of record: what this session's agent did, + * and what a child agent it spawned did. The child's work is the child's: it is + * excluded from this sheet's counts, named in `subagents` and counted in + * `subagentToolSpans`, never added to the parent's totals. A trace with no + * subagent records is unaffected — every one of those counts is zero. + * * The sheet is NOT a span and cannot be cited. It is prepared context, and * `trace://` citations still resolve against the raw spans — which is why every * fact names its span ids rather than asking the reader to trust the sheet. @@ -36,6 +45,10 @@ import { ACTOR_ATTR } from './adapters/conversation.js' import { INHERITED_SOURCE_ATTR, INHERITED_SPAN_ATTR, + SUBAGENT_SPAWN_ATTR, + SUBAGENT_SPAWN_TASK_ATTR, + SUBAGENT_TASK_ATTR, + isSubagentSpan, isSynthesizedSpan as isSynthesizedByProvenance, } from './adapters/provenance.js' import { indexSessionIdsByTrace } from './attributes.js' @@ -99,9 +112,9 @@ export interface SessionFact { readonly partial?: string } -/** One `spawn_agent` call, with the task name the adapter recorded for it. */ +/** One subagent-spawning call, with the task name the adapter recorded for it. */ export interface SubagentSpawnFact { - /** `traces.codex.spawn_agent_path`, verbatim. Null when the span carries none. */ + /** The task name the spawn span carries, verbatim. Null when it carries none. */ readonly taskName: string | null /** Why `taskName` is null. Null when it was recorded. */ readonly taskNameUnavailable: string | null @@ -181,10 +194,16 @@ export interface SessionFacts { readonly recordSpans: number /** Records the adapter could not read, from the session's integrity receipt. */ readonly unreadRecords: SessionFact - /** TOOL spans the agent actually invoked: synthesized lifecycle spans excluded. */ + /** + * TOOL spans THIS session's agent invoked. Synthesized lifecycle spans and + * the tool calls of subagents it spawned are excluded, and each exclusion is + * counted below so the reader can add them back. + */ readonly toolCalls: SessionFact /** Every synthesized span excluded from `toolCalls`, so the exclusion is checkable. */ readonly synthesizedToolSpans: SessionFact + /** TOOL spans excluded because a subagent, not this agent, made the call. */ + readonly subagentToolSpans: SessionFact /** Tool-call counts by tool name, over the same spans `toolCalls` counted. */ readonly toolCallsByName: SessionFact>> readonly subagents: SessionFact @@ -199,10 +218,11 @@ export interface SessionFacts { /** The last message of the session's own agent, and of each subagent task. */ readonly finalMessages: SessionFact readonly changedFiles: SessionFact - /** Earliest span start in the trace. Not the session file's first record when - * the adapter selected a task boundary inside the file. */ + /** Earliest span start among this session's own records. Not the session + * file's first record when the adapter selected a task boundary inside the + * file, and not a spawned subagent's first record. */ readonly firstRecordAt: SessionFact - /** Latest span end in the trace. */ + /** Latest span end among this session's own records. */ readonly lastRecordAt: SessionFact /** The harness's own cumulative token total, when a span carries it. */ readonly tokenTotal: SessionFact @@ -444,30 +464,52 @@ function changedFilesOf(toolSpans: readonly OtlpSpan[], spans: readonly OtlpSpan return { files, truncatedInputs, unresolvedPaths } } -function subagentsOf(spans: readonly OtlpSpan[]): SubagentSpawnFact[] { +/** + * The subagents THIS session's agent spawned, one entry per spawning call. + * + * `ownSpans` are the session's own records: a spawn a subagent itself made is + * that subagent's, not this session's. `spans` is the whole trace, because the + * lifecycle span a spawn joins to lives in the child's scope. + */ +function subagentsOf(ownSpans: readonly OtlpSpan[], spans: readonly OtlpSpan[]): SubagentSpawnFact[] { // A lifecycle span records the subagent's own path; joining it to the spawn // call by that path gives the reader both spans to check the task name with. const lifecycleByPath = new Map() + // An adapter that folds the child's transcript in parents the child's + // lifecycle span under the spawn call itself, which is an exact join and + // needs no name: two spawns may legitimately carry the same task name. + const lifecycleByParent = new Map() for (const span of spans) { + if (!isSynthesizedSpan(span)) continue const path = stringAttr(span, 'traces.codex.subagent_path') - if (path === null || !isSynthesizedSpan(span)) continue - lifecycleByPath.set(path, [...(lifecycleByPath.get(path) ?? []), span.span_id]) + if (path !== null) { + lifecycleByPath.set(path, [...(lifecycleByPath.get(path) ?? []), span.span_id]) + } + const parent = span.parent_span_id + if (parent !== null && span.attributes[SUBAGENT_TASK_ATTR] !== undefined) { + lifecycleByParent.set(parent, [...(lifecycleByParent.get(parent) ?? []), span.span_id]) + } } const spawns: SubagentSpawnFact[] = [] - for (const span of spans) { + for (const span of ownSpans) { const isSpawn = attr(span, 'traces.codex.agent_operation') === 'spawn_agent' || - stringAttr(span, 'traces.codex.spawn_agent_path') !== null + stringAttr(span, 'traces.codex.spawn_agent_path') !== null || + attr(span, SUBAGENT_SPAWN_ATTR) === true if (!isSpawn || isSynthesizedSpan(span)) continue - const taskName = stringAttr(span, 'traces.codex.spawn_agent_path') + const taskName = stringAttr(span, 'traces.codex.spawn_agent_path') ?? stringAttr(span, SUBAGENT_SPAWN_TASK_ATTR) spawns.push({ taskName, taskNameUnavailable: taskName === null - ? 'the spawn span carries no traces.codex.spawn_agent_path; the harness returned no task name for this call' + ? 'the spawn span carries no task name; the harness recorded none for this call' : null, startedAt: span.start_time, status: span.status.code, - spanIds: [span.span_id, ...(taskName ? lifecycleByPath.get(taskName) ?? [] : [])], + spanIds: [ + span.span_id, + ...(taskName ? lifecycleByPath.get(taskName) ?? [] : []), + ...(lifecycleByParent.get(span.span_id) ?? []), + ], }) } return spawns @@ -477,8 +519,13 @@ function finalMessagesOf(spans: readonly OtlpSpan[]): FinalMessageFact[] { const last = new Map() for (const span of spans) { let task: string | null | undefined - if (span.name === 'message.assistant') task = null - else if (span.name.startsWith('message.agent.')) { + if (span.name === 'message.assistant') { + // A folded subagent's transcript carries the same span name; the message + // is that subagent's last word, not the session agent's. + task = isSubagentSpan(span.attributes) + ? stringAttr(span, SUBAGENT_TASK_ATTR) ?? 'unattributed subagent' + : null + } else if (span.name.startsWith('message.agent.')) { task = stringAttr(span, 'traces.codex.agent_message_author') ?? 'unattributed subagent' } if (task === undefined) continue @@ -562,6 +609,10 @@ const DUPLICATE_TURN_REASON = 'a second record of the turn before it: the same text at the same instant, with no model call, tool call ' + 'or assistant message between them' +const SUBAGENT_TURN_REASON = + 'a turn inside a subagent this session spawned, not a turn of this session: the person addressed the ' + + 'session, and the brief and notifications the subagent received are the parent agent talking to it' + /** Spans that mean the agent acted: a person cannot have typed twice across one. */ function isAgentActivity(span: OtlpSpan): boolean { if (span.name === 'user.prompt') return false @@ -596,6 +647,12 @@ function humanTurnsOf(spans: readonly OtlpSpan[]): { const kept: OtlpSpan[] = [] let sinceKept: OtlpSpan[] = [] for (const span of spans) { + // A subagent's records are not this session's: its prompts are not human + // turns here, and its activity does not separate two turns of this session. + if (isSubagentSpan(span.attributes)) { + if (span.name === 'user.prompt') drop(SUBAGENT_TURN_REASON, span.span_id) + continue + } if (span.name !== 'user.prompt') { sinceKept.push(span) continue @@ -662,14 +719,21 @@ function sessionFactsForTrace( const spans = [...unordered].sort(byTraceOrder) const harness = spans.map((span) => stringAttr(span, 'service.name')).find((name) => name !== null) ?? null + // The session's own records. A spawned subagent's transcript may be folded + // into this trace; what it did is reported as the subagent's, never added to + // the totals below. + const ownSpans = spans.filter((span) => !isSubagentSpan(span.attributes)) const toolSpans = spans.filter(isToolSpan) const synthesized = toolSpans.filter(isSynthesizedSpan) - const invoked = toolSpans.filter((span) => !isSynthesizedSpan(span)) + const invoked = ownSpans.filter((span) => isToolSpan(span) && !isSynthesizedSpan(span)) + const subagentTools = toolSpans.filter( + (span) => isSubagentSpan(span.attributes) && !isSynthesizedSpan(span), + ) const byName: Record = {} for (const span of invoked) byName[toolName(span)] = (byName[toolName(span)] ?? 0) + 1 - const subagents = subagentsOf(spans) - const pullRequests = readPullRequests(spans) + const subagents = subagentsOf(ownSpans, spans) + const pullRequests = readPullRequests(ownSpans) const promptSpans = spans.filter((span) => span.name === 'user.prompt') const { turns: humanTurns, excluded: excludedTurns } = humanTurnsOf(spans) const actorCounts = new Map() @@ -678,10 +742,10 @@ function sessionFactsForTrace( actorCounts.set(actor, [...(actorCounts.get(actor) ?? []), span.span_id]) } const finalMessages = finalMessagesOf(spans) - const { files, truncatedInputs, unresolvedPaths } = changedFilesOf(invoked, spans) + const { files, truncatedInputs, unresolvedPaths } = changedFilesOf(invoked, ownSpans) - const starts = spans.filter((span) => Number.isFinite(Date.parse(span.start_time))) - const ends = spans.filter((span) => Number.isFinite(Date.parse(span.end_time))) + const starts = ownSpans.filter((span) => Number.isFinite(Date.parse(span.start_time))) + const ends = ownSpans.filter((span) => Number.isFinite(Date.parse(span.end_time))) const firstSpan = starts.reduce( (best, span) => (best === null || Date.parse(span.start_time) < Date.parse(best.start_time) ? span : best), null, @@ -729,6 +793,11 @@ function sessionFactsForTrace( spanIds: synthesized.map((span) => span.span_id), unavailable: null, }, + subagentToolSpans: { + value: subagentTools.length, + spanIds: subagentTools.map((span) => span.span_id), + unavailable: null, + }, toolCallsByName: { value: byName, spanIds: invoked.map((span) => span.span_id), @@ -755,10 +824,10 @@ function sessionFactsForTrace( changedFiles: changedFilesFact(files, truncatedInputs, unresolvedPaths), firstRecordAt: firstSpan ? { value: firstSpan.start_time, spanIds: [firstSpan.span_id], unavailable: null } - : { value: null, spanIds: [], unavailable: 'no span in this trace carries a parseable start time' }, + : { value: null, spanIds: [], unavailable: "no span of this session's own records carries a parseable start time" }, lastRecordAt: lastSpan ? { value: lastSpan.end_time, spanIds: [lastSpan.span_id], unavailable: null } - : { value: null, spanIds: [], unavailable: 'no span in this trace carries a parseable end time' }, + : { value: null, spanIds: [], unavailable: "no span of this session's own records carries a parseable end time" }, tokenTotal: tokenSpan ? { value: tokenSpan.attributes[SESSION_TOKEN_TOTAL_ATTR] as number, @@ -807,7 +876,8 @@ export function renderSessionFacts(report: SessionFactsReport): string { factLine( 'tool calls', facts.toolCalls, - `${facts.toolCalls.value} (${facts.synthesizedToolSpans.value ?? 0} synthesized span(s) excluded)`, + `${facts.toolCalls.value} (${facts.synthesizedToolSpans.value ?? 0} synthesized span(s) excluded` + + `${(facts.subagentToolSpans.value ?? 0) > 0 ? `, ${facts.subagentToolSpans.value} made by subagents` : ''})`, ), ) lines.push( @@ -971,7 +1041,12 @@ interface CompactFacts { session_id: string | null trace_id: string spans: number - tool_calls: { count: number | null; synthesized_excluded: number | null; span_ids: readonly string[] } + tool_calls: { + count: number | null + synthesized_excluded: number | null + subagent_excluded: number | null + span_ids: readonly string[] + } tool_calls_by_name?: Readonly> | null subagents: { count: number; entries?: readonly unknown[] } pull_requests: CompactPullRequests @@ -1017,6 +1092,7 @@ function compactFacts(facts: SessionFacts): CompactFacts { tool_calls: { count: facts.toolCalls.value, synthesized_excluded: facts.synthesizedToolSpans.value, + subagent_excluded: facts.subagentToolSpans.value, span_ids: facts.toolCalls.spanIds, }, tool_calls_by_name: facts.toolCallsByName.value, diff --git a/tests/adapters.test.ts b/tests/adapters.test.ts index 97b648a..5c321df 100644 --- a/tests/adapters.test.ts +++ b/tests/adapters.test.ts @@ -846,8 +846,12 @@ describe('claude adapter (conversation capture)', () => { taskScope: 'turn', taskTurnId: 'turn-old', }) + // A message span mirrors the content of the llm.turn it hangs from, so it + // is skipped here: this test is about which records each scope selected. const contents = (spans: OtlpSpan[]) => - spans.flatMap((item) => typeof item.attributes.content === 'string' ? [item.attributes.content] : []) + spans.flatMap((item) => item.name !== 'message.assistant' && typeof item.attributes.content === 'string' + ? [item.attributes.content] + : []) expect(contents(all)).toEqual([ 'OLD TASK', @@ -957,7 +961,8 @@ describe('claude adapter (conversation capture)', () => { const spans = await new ClaudeAdapter().parse(refFor(path, 'claude-code')) - expect(spans).toHaveLength(2) + // The session root, the one turn, and the message that turn produced. + expect(spans).toHaveLength(3) expect(new Set(spans.map((span) => span.trace_id))).toEqual( new Set([deriveHexId('canonical-session', 16)]), ) @@ -1137,7 +1142,10 @@ describe('claude adapter (conversation capture)', () => { const child = spans.find((item) => item.attributes['agent.name'] === 'subagent:child') const childCall = spans.find((item) => item.attributes['tool.name'] === 'Agent' && item.attributes['agent.name'] === 'subagent:parent') expect(child?.parent_span_id).toBe(childCall?.span_id) - expect(spans[0]?.end_time).toBe('2026-01-01T00:00:03Z') + // The root's window is the SESSION's own records, which end at its last + // one; the nested children ran on past it inside their own transcripts. + expect(spans[0]?.end_time).toBe('2026-01-01T00:00:01Z') + expect(child?.end_time).toBe('2026-01-01T00:00:03Z') }) // Was: rejects duplicate ids by throwing. The invariant it protected is unchanged — a @@ -1234,8 +1242,18 @@ describe('claude adapter (conversation capture)', () => { writeFileSync(join(subDir, 'agent-a.meta.json'), JSON.stringify({ agentType: 'Explore', toolUseId: 'agent-call' })) const spans = await new ClaudeAdapter().parse(refFor(path, 'claude-code')) - expect(traceShapeDigest(spans)).toBe('58ad7bae59004e9d6d36de7c5be70ab161cb0c6cad780c2f52b60868d8a4a18c') - expect(spans.map((item) => item.name)).toEqual(['session', 'user.prompt', 'llm.turn', 'tool.Agent', 'user.prompt', 'llm.turn']) + expect(traceShapeDigest(spans)).toBe('c884fc2b20dade6475b0452ff69f3c84c4e8588e68a47454e93e4be5d569ce8d') + expect(spans.map((item) => item.name)).toEqual([ + 'session', + 'user.prompt', + 'llm.turn', + 'message.assistant', + 'tool.Agent', + 'user.prompt', + 'subagent.lifecycle', + 'llm.turn', + 'message.assistant', + ]) expect(spans.every((item) => item.trace_id === deriveHexId('claude-trace', 16))).toBe(true) expect(spans[0]).toMatchObject({ start_time: '2026-01-01T00:00:00Z', end_time: '2026-01-01T00:00:02Z' }) const mainTurn = llm(spans) @@ -1246,7 +1264,13 @@ describe('claude adapter (conversation capture)', () => { expect(agentCall).toMatchObject({ end_time: '2026-01-01T00:00:02Z', status: { code: 'OK' } }) expect(agentCall?.attributes.content).toBeUndefined() expect(agentCall?.attributes['output.value']).toBe('done') - expect(spans.filter((item) => item.attributes['agent.name'] === 'subagent:Explore').every((item) => item.parent_span_id === agentCall?.span_id)).toBe(true) + // The child's own spans nest inside the child; what hangs from the Agent + // call is every span at the top of that child's transcript. + const explore = spans.filter((item) => item.attributes['agent.name'] === 'subagent:Explore') + const exploreIds = new Set(explore.map((item) => item.span_id)) + expect(explore.every((item) => item.parent_span_id === agentCall?.span_id + || exploreIds.has(item.parent_span_id ?? ''))).toBe(true) + expect(explore.filter((item) => item.parent_span_id === agentCall?.span_id).length).toBeGreaterThan(0) }) it('parses a session with more than 65k spans without array spread overflow', async () => { @@ -1275,9 +1299,10 @@ describe('claude adapter (conversation capture)', () => { const spans = await new ClaudeAdapter().parse(refFor(path, 'claude-code')) - expect(spans).toHaveLength(70_002) + // Each response is two spans: the call, and the message it produced. + expect(spans).toHaveLength(140_002) expect(spans[0]?.name).toBe('session') - expect(spans.at(-1)?.name).toBe('llm.turn') + expect(spans.at(-1)?.name).toBe('message.assistant') }) }) diff --git a/tests/claude-session-facts.test.ts b/tests/claude-session-facts.test.ts new file mode 100644 index 0000000..fd687d0 --- /dev/null +++ b/tests/claude-session-facts.test.ts @@ -0,0 +1,401 @@ +/** + * The session-facts sheet over a Claude Code transcript. + * + * The sheet's logic was already harness-neutral, but every fact it read was + * emitted by the Codex adapter alone, so the same sheet that answered a Codex + * session exactly answered a Claude Code session with a tool count eight times + * too high, no subagents, no final message and almost no changed files. The + * cause was not the sheet: the Claude adapter folds every spawned agent's + * transcript into the parent's trace and marked none of it, emitted no message + * span, no file-change span and no spawn marker, and classified turns from the + * text when the harness had already recorded who typed each one. + * + * These fixtures are written by hand so each fact can be checked by eye. + */ + +import { mkdirSync, mkdtempSync, rmSync, writeFileSync } from 'node:fs' +import { tmpdir } from 'node:os' +import { join } from 'node:path' +import { afterAll, describe, expect, it } from 'vitest' +import { ClaudeAdapter } from '../src/adapters/claude.js' +import { computeSessionFacts } from '../src/session-facts.js' +import type { SessionRef } from '../src/types.js' + +const dir = mkdtempSync(join(tmpdir(), 'traces-claude-session-facts-')) +afterAll(() => rmSync(dir, { recursive: true, force: true })) + +function refFor(path: string): SessionRef { + return { harness: 'claude-code', sessionId: 'fixture', path, cwd: null, mtimeMs: 0 } +} + +function writeJsonl(path: string, rows: readonly unknown[]): void { + writeFileSync(path, `${rows.map((row) => JSON.stringify(row)).join('\n')}\n`) +} + +/** Parse a fixture and return the single session's facts. */ +async function factsFor(path: string) { + const spans = await new ClaudeAdapter().parse(refFor(path)) + const sessions = computeSessionFacts(spans) + expect(sessions).toHaveLength(1) + return sessions[0]! +} + +/** + * One session whose agent typed at the keyboard, ran two tools, wrote one file + * and spawned one subagent that ran three tools and wrote two files of its own. + */ +function writeDelegatingSession(name: string): string { + const path = join(dir, `${name}.jsonl`) + writeJsonl(path, [ + // A record that produces no span, and the session's first: the window is + // over records, not spans. + { + type: 'file-history-snapshot', + messageId: 'snap-1', + snapshot: { messageId: 'snap-1', trackedFileBackups: {}, timestamp: '2026-02-01T00:00:00Z' }, + timestamp: '2026-02-01T00:00:00Z', + }, + { + type: 'user', + uuid: 'human-1', + sessionId: name, + timestamp: '2026-02-01T00:00:01Z', + userType: 'external', + origin: { kind: 'human' }, + message: { role: 'user', content: 'audit the release and delegate the review' }, + }, + { + type: 'assistant', + uuid: 'turn-1', + sessionId: name, + timestamp: '2026-02-01T00:00:02Z', + message: { + id: 'message-1', + role: 'assistant', + model: 'test-model', + content: [ + { type: 'text', text: 'Checking the release, then delegating the review.' }, + { type: 'tool_use', id: 'call-bash', name: 'Bash', input: { command: 'git status' } }, + { type: 'tool_use', id: 'call-edit', name: 'Edit', input: { file_path: '/repo/NOTES.md' } }, + { + type: 'tool_use', + id: 'call-agent', + name: 'Task', + input: { description: 'Review the release notes', prompt: 'Review it.', subagent_type: 'general-purpose' }, + }, + ], + }, + }, + { + type: 'file-history-delta', + messageId: 'delta-1', + snapshotMessageId: 'snap-1', + trackingPath: '/repo/NOTES.md', + backup: { backupFileName: null, version: 1, backupTime: '2026-02-01T00:00:03Z' }, + timestamp: '2026-02-01T00:00:03Z', + }, + { + type: 'user', + uuid: 'result-1', + sessionId: name, + timestamp: '2026-02-01T00:00:04Z', + message: { + role: 'user', + content: [{ type: 'tool_result', tool_use_id: 'call-agent', content: 'review done' }], + }, + }, + { + type: 'assistant', + uuid: 'turn-2', + sessionId: name, + timestamp: '2026-02-01T00:00:05Z', + message: { + id: 'message-2', + role: 'assistant', + model: 'test-model', + content: [{ type: 'text', text: 'The release is clean and the review is in.' }], + }, + }, + // The last record of the session, and it produces no span either. + { type: 'continued-in', sessionId: name, timestamp: '2026-02-01T00:00:06Z' }, + ]) + + const subDir = join(dir, name, 'subagents') + mkdirSync(subDir, { recursive: true }) + writeJsonl(join(subDir, 'agent-reviewer.jsonl'), [ + { + type: 'user', + uuid: 'child-brief', + timestamp: '2026-02-01T00:00:02.100Z', + isSidechain: true, + message: { role: 'user', content: 'Review it.' }, + }, + { + type: 'assistant', + uuid: 'child-turn', + timestamp: '2026-02-01T00:00:02.200Z', + message: { + id: 'child-message', + role: 'assistant', + model: 'test-model', + content: [ + { type: 'text', text: 'Read the notes; two nits.' }, + { type: 'tool_use', id: 'child-read', name: 'Read', input: { file_path: '/repo/NOTES.md' } }, + { type: 'tool_use', id: 'child-write', name: 'Write', input: { file_path: '/repo/child-a.md' } }, + { type: 'tool_use', id: 'child-edit', name: 'Edit', input: { file_path: '/repo/child-b.md' } }, + ], + }, + }, + // The child outlives the parent's last record; the parent's window must not + // stretch to cover it. + { + type: 'assistant', + uuid: 'child-final', + timestamp: '2026-02-01T00:09:00Z', + message: { + id: 'child-final-message', + role: 'assistant', + content: [{ type: 'text', text: 'Two nits, both fixed.' }], + }, + }, + ]) + writeFileSync( + join(subDir, 'agent-reviewer.meta.json'), + JSON.stringify({ agentType: 'general-purpose', description: 'Review the release notes', toolUseId: 'call-agent' }), + ) + return path +} + +describe('session facts from a Claude Code transcript', () => { + it('counts the session agent\'s tool calls and never the subagent\'s', async () => { + const facts = await factsFor(writeDelegatingSession('delegating')) + + // Bash, Edit and the Task call that spawned the subagent. + expect(facts.toolCalls.value).toBe(3) + expect(facts.toolCallsByName.value).toEqual({ Bash: 1, Edit: 1, Task: 1 }) + // Read, Write and Edit, all made by the child. + expect(facts.subagentToolSpans.value).toBe(3) + expect(facts.subagentToolSpans.spanIds).toHaveLength(3) + // The exclusion is checkable: no excluded span is in the counted list. + for (const id of facts.subagentToolSpans.spanIds) { + expect(facts.toolCalls.spanIds).not.toContain(id) + } + }) + + it('lists each spawned subagent with the task its call named', async () => { + const facts = await factsFor(writeDelegatingSession('spawned')) + + expect(facts.subagents.value).toHaveLength(1) + const spawn = facts.subagents.value![0]! + expect(spawn.taskName).toBe('Review the release notes') + expect(spawn.taskNameUnavailable).toBeNull() + expect(spawn.status).toBe('OK') + // The spawn call, plus the lifecycle span standing for the child transcript. + expect(spawn.spanIds).toHaveLength(2) + }) + + it('separates the session agent\'s final message from each subagent\'s', async () => { + const facts = await factsFor(writeDelegatingSession('final-messages')) + + const own = facts.finalMessages.value!.filter((entry) => entry.task === null) + expect(own).toHaveLength(1) + expect(own[0]!.text).toBe('The release is clean and the review is in.') + + const delegated = facts.finalMessages.value!.filter((entry) => entry.task !== null) + expect(delegated).toHaveLength(1) + expect(delegated[0]!.task).toBe('Review the release notes') + expect(delegated[0]!.text).toBe('Two nits, both fixed.') + }) + + it('reports the files this session changed, from the harness\'s own record', async () => { + const facts = await factsFor(writeDelegatingSession('changed-files')) + + expect(facts.changedFiles.value!.map((entry) => entry.path)).toEqual(['/repo/NOTES.md']) + // Two spans state the same change: the harness's file-history record and + // the Edit call whose argument named the same path. + expect(facts.changedFiles.value![0]!.spanIds).toHaveLength(2) + }) + + it('bounds the session by its own records, not by a subagent that outlived it', async () => { + const facts = await factsFor(writeDelegatingSession('record-window')) + + expect(facts.firstRecordAt.value).toBe('2026-02-01T00:00:00Z') + expect(facts.lastRecordAt.value).toBe('2026-02-01T00:00:06Z') + }) + + it('excludes the subagent\'s turns from the human count and says why', async () => { + const facts = await factsFor(writeDelegatingSession('subagent-turns')) + + expect(facts.humanTurns.value!.map((turn) => turn.text)).toEqual([ + 'audit the release and delegate the review', + ]) + const subagentExclusion = facts.excludedTurns.value!.find((entry) => + entry.reason.includes('subagent this session spawned')) + expect(subagentExclusion?.turns).toBe(1) + }) + + it('counts the turns the harness attributed to a person, including a queued one', async () => { + const path = join(dir, 'human-origin.jsonl') + writeJsonl(path, [ + { + type: 'user', + uuid: 'slash', + sessionId: 'human-origin', + timestamp: '2026-02-02T00:00:00Z', + userType: 'external', + origin: { kind: 'human' }, + message: { + role: 'user', + content: 'audit\n/audit', + }, + }, + { + type: 'assistant', + uuid: 'answer-1', + sessionId: 'human-origin', + timestamp: '2026-02-02T00:00:01Z', + message: { id: 'm1', role: 'assistant', content: [{ type: 'text', text: 'On it.' }] }, + }, + // A message sent while the turn was running: the CLI surfaces it inside + // the turn as an attachment and opens no conversation turn for it. + { + type: 'attachment', + uuid: 'queued-1', + sessionId: 'human-origin', + timestamp: '2026-02-02T00:00:02Z', + attachment: { + type: 'queued_command', + prompt: 'also check the changelog', + commandMode: 'prompt', + origin: { kind: 'human' }, + timestamp: '2026-02-02T00:00:02Z', + }, + }, + // A notification the harness wrote, which reads like a user turn. + { + type: 'user', + uuid: 'notified', + sessionId: 'human-origin', + timestamp: '2026-02-02T00:00:03Z', + userType: 'external', + origin: { kind: 'task-notification' }, + message: { role: 'user', content: 'worker complete' }, + }, + // The CLI's own record of a session command and of an interruption. Both + // pass every text heuristic; neither carries a human origin. + { + type: 'user', + uuid: 'login', + sessionId: 'human-origin', + timestamp: '2026-02-02T00:00:04Z', + userType: 'external', + message: { role: 'user', content: '/login\n' }, + }, + { + type: 'user', + uuid: 'interrupted', + sessionId: 'human-origin', + timestamp: '2026-02-02T00:00:05Z', + userType: 'external', + message: { role: 'user', content: '[Request interrupted by user]' }, + }, + ]) + + const facts = await factsFor(path) + + expect(facts.humanTurns.value!.map((turn) => turn.text)).toEqual([ + // The wrapper is how the CLI stores the line; the line is what was typed. + '/audit', + 'also check the changelog', + ]) + expect(facts.turnsByActor.value).toEqual([ + { actor: 'human', turns: 2, spanIds: expect.any(Array) }, + { actor: 'injected', turns: 3, spanIds: expect.any(Array) }, + ]) + }) + + it('reads a queued message that arrived as content blocks beside an image', async () => { + const path = join(dir, 'queued-blocks.jsonl') + writeJsonl(path, [ + { + type: 'user', + uuid: 'typed-1', + sessionId: 'queued-blocks', + timestamp: '2026-02-04T00:00:00Z', + userType: 'external', + origin: { kind: 'human' }, + message: { role: 'user', content: 'start the run' }, + }, + // A queued message is a message body, so it takes either shape a message + // body takes. This one carried a screenshot alongside the words. + { + type: 'attachment', + uuid: 'queued-blocks-1', + sessionId: 'queued-blocks', + timestamp: '2026-02-04T00:00:01Z', + attachment: { + type: 'queued_command', + prompt: [ + { type: 'text', text: 'the button is the wrong colour' }, + { type: 'image', source: { type: 'base64', media_type: 'image/png', data: 'iVBORw0KGgo=' } }, + ], + commandMode: 'prompt', + origin: { kind: 'human' }, + timestamp: '2026-02-04T00:00:01Z', + }, + }, + // A record whose origin is not a usable string falls back rather than + // being trusted as a label. + { + type: 'user', + uuid: 'odd-origin', + sessionId: 'queued-blocks', + timestamp: '2026-02-04T00:00:02Z', + userType: 'external', + origin: { kind: 7 }, + message: { role: 'user', content: 'budget is low' }, + }, + ]) + + const facts = await factsFor(path) + + expect(facts.humanTurns.value!.map((turn) => turn.text)).toEqual([ + 'start the run', + 'the button is the wrong colour', + ]) + }) + + it('falls back to the text heuristics when the transcript records no origin', async () => { + const path = join(dir, 'no-origin.jsonl') + writeJsonl(path, [ + { + type: 'user', + uuid: 'typed', + sessionId: 'no-origin', + timestamp: '2026-02-03T00:00:00Z', + userType: 'external', + message: { role: 'user', content: 'ship the release' }, + }, + { + type: 'user', + uuid: 'reminder', + sessionId: 'no-origin', + timestamp: '2026-02-03T00:00:01Z', + userType: 'external', + message: { role: 'user', content: 'budget is low' }, + }, + ]) + + const facts = await factsFor(path) + + expect(facts.humanTurns.value!.map((turn) => turn.text)).toEqual(['ship the release']) + expect(facts.excludedTurns.value!.map((entry) => entry.turns)).toEqual([1]) + }) + + it('states that the transcript carries no cumulative token total', async () => { + const facts = await factsFor(writeDelegatingSession('token-total')) + + expect(facts.tokenTotal.value).toBeNull() + expect(facts.tokenTotal.unavailable).toContain('traces.session.total_tokens') + }) +}) diff --git a/tests/claude-subagents.test.ts b/tests/claude-subagents.test.ts index b043dd3..300bcce 100644 --- a/tests/claude-subagents.test.ts +++ b/tests/claude-subagents.test.ts @@ -57,7 +57,11 @@ function writeChild(input: { function contentOrder(spans: readonly OtlpSpan[]): string[] { return spans.flatMap((item) => - typeof item.attributes.content === 'string' ? [item.attributes.content] : []) + // A message span mirrors the content of the llm.turn it hangs from, so + // listing it as well would say nothing about the order of the records. + item.name !== 'message.assistant' && typeof item.attributes.content === 'string' + ? [item.attributes.content] + : []) } describe('Claude subagent folding', () => { @@ -153,8 +157,13 @@ describe('Claude subagent folding', () => { (item) => item.attributes['agent.name'] === 'subagent:worker', ) - expect(stale).toHaveLength(2) - expect(stale.every( + // The child's own prompt, its llm.turn, the message that turn produced, and + // the lifecycle span standing for its transcript. + expect(stale).toHaveLength(4) + expect(stale.filter((item) => item.name === 'subagent.lifecycle')).toHaveLength(1) + const staleIds = new Set(stale.map((item) => item.span_id)) + const staleTop = stale.filter((item) => !staleIds.has(item.parent_span_id ?? '')) + expect(staleTop.every( (item) => item.attributes['traces.claude.source_parent_span_id'] === 'root:stale-child', )).toBe(true) expect(stale.every( diff --git a/tests/claude-workflow.test.ts b/tests/claude-workflow.test.ts index f4084f1..cc1a91f 100644 --- a/tests/claude-workflow.test.ts +++ b/tests/claude-workflow.test.ts @@ -19,7 +19,10 @@ function refFor(path: string): SessionRef { function contents(spans: readonly OtlpSpan[]): string[] { return spans.flatMap((item) => - typeof item.attributes.content === 'string' ? [item.attributes.content] : []) + // A message span mirrors the content of the llm.turn it hangs from. + item.name !== 'message.assistant' && typeof item.attributes.content === 'string' + ? [item.attributes.content] + : []) } function workflowEvents(input: { @@ -129,13 +132,22 @@ describe('Claude Workflow subagents', () => { (item) => item.attributes['agent.name'] === 'subagent:workflow-subagent', ) - expect(workflowSpans).toHaveLength(2) - expect(workflowSpans.every((item) => item.parent_span_id === workflowCall?.span_id)).toBe(true) + // The child's prompt, its llm.turn, the message that turn produced, and the + // lifecycle span standing for its transcript. + expect(workflowSpans).toHaveLength(4) + expect(workflowSpans.filter((item) => item.name === 'subagent.lifecycle')).toHaveLength(1) + const workflowTurn = workflowSpans.find((item) => item.name === 'llm.turn') + expect(workflowSpans.filter((item) => item.parent_span_id === workflowCall?.span_id)).toHaveLength(3) + expect(workflowSpans.filter((item) => item.parent_span_id === workflowTurn?.span_id)).toHaveLength(1) expect(workflowSpans.every( (item) => String(item.attributes['traces.claude.source_span_id']) .startsWith('workflows:wf-linked:agent-linked:'), )).toBe(true) - expect(spans[0]?.end_time).toBe('2026-01-01T00:00:04Z') + // The root's window is the SESSION's records, which end when the parent + // recorded the Workflow result; the child ran on past that, and its spans + // say so rather than being folded into the parent's duration. + expect(spans[0]?.end_time).toBe('2026-01-01T00:00:02Z') + expect(workflowSpans.some((item) => item.end_time === '2026-01-01T00:00:04Z')).toBe(true) }) it('scopes resumed workflows by run ID with structured and text results', async () => { diff --git a/tests/cli.test.ts b/tests/cli.test.ts index 9840ff6..adc3db1 100644 --- a/tests/cli.test.ts +++ b/tests/cli.test.ts @@ -712,7 +712,9 @@ describe('traces CLI', () => { totals: { sessions: number; spans: number } } expect(output.selection.latestTurn).toBe(true) - expect(output.totals).toMatchObject({ sessions: 1, spans: 4 }) + // Root, the new task, its llm.turn, the assistant message it produced, and + // the task notification that followed it. + expect(output.totals).toMatchObject({ sessions: 1, spans: 5 }) }) it('expands the active Codex session through recursively spawned child files', async () => { diff --git a/tests/traces.test.ts b/tests/traces.test.ts index 734bf05..174ddec 100644 --- a/tests/traces.test.ts +++ b/tests/traces.test.ts @@ -302,7 +302,13 @@ describe('claude transcript → spans', () => { const toolSpans = spans.filter((item) => item.attributes['openinference.span.kind'] === 'TOOL') expect(llmSpans).toHaveLength(1) expect(toolSpans).toHaveLength(1) - expect(nextStep).toBe(2) + // One response, so one message span too: the text fragments merge into it + // rather than each opening another message. + const messageSpans = spans.filter((item) => item.name === 'message.assistant') + expect(messageSpans).toHaveLength(1) + expect(messageSpans[0]?.attributes.content).toBe('running the check') + expect(messageSpans[0]?.parent_span_id).toBe(llmSpans[0]?.span_id) + expect(nextStep).toBe(3) expect(llmSpans[0]).toMatchObject({ start_time: '2026-01-01T00:00:00Z', end_time: '2026-01-01T00:00:02Z',