feat(harness): write chat and execute_tool spans from the runtime by xytian315 · Pull Request #3121 · kagent-dev/kagent

xytian315 · 2026-10-09T05:07:37Z

The Claude Code and Codex harness runtimes now write a GenAI chat span for each model call. They also write
an execute_tool span for each tool call. Both spans are children of invoke_agent. Each driver turns its
harness output into common runtime events. The shared executor writes the spans and metrics from these events.

The runtime marks the harness process with kagent.genai.producer=runtime. A trace backend can use this marker
to skip the native spans of the same process. The Weaver registry defines the marker, the spans and the metrics.

Special cases

Call times: a Claude chat span starts when Claude Code sends the request, not at the first token.
Retries: a retried call stays one chat span, with kagent.inference.retry.count and the tokens of each attempt.
Cancel: the runtime keeps the calls that the harness reported before the cancel. A Claude call that a cancel
stops gets kagent.inference.usage_partial=true and no error status.
Approval: the span of an approved tool starts at the approval, in the resumed segment. A denied or declined
tool call gets no span.
Errors: a tool with no result gets error.type unfinished. A failed call gets the harness error type, such as model_not_found, or model_error when the harness gives none.
Claude subagents: Claude and Codex subagent calls and tools are children of the tool call that started them.
Codex: Codex reports usage as running totals. The runtime changes these totals into per-call counts.
Token counters: at the end of a Claude turn, the runtime also adds the tokens that Claude's own total shows but no chat span has, such as most of a subagent's output.
Metrics: each restored session gets its own service.instance.id, so sessions do not overwrite each other.

Known limits

Claude subagent chat spans can have too few output tokens (kagent.inference.usage_partial). The token counters are exact.
The runtime writes no span for a Claude Code request outside the main stream.
Codex reports no call times. A Codex chat span starts at the end of the previous call and ends at the usage
report. The span can include tool time.

Testing

Driver tests replay captured output from Claude Code 2.1.285 and Codex 0.148.0. The tests cover normal turns, tools, subagents, retries, cancel, approval and failure.
A local kind cluster ran 34 turns. The runtime spans match the native spans for calls, tokens and tools,
except for the known limits. Approval, cancel, a killed Claude Code process and a bad model name also pass.

The Claude and Codex drivers report each model call and tool call, and the executor records them under invoke_agent. The native child resource sets kagent.genai.producer=adapter so the collector skips its own chat and tool spans. Signed-off-by: Kristy Tian <[email protected]>

krisztianfekete

Thank you, this is really awesome work! I tested it locally with Claude (will do a run with Codex later) and left some comments!

krisztianfekete · 2026-10-09T09:06:47Z

+	if t.Runtime.NativeHarness() {
+		attributes = append(attributes, attribute.String(AttributeGenAIProducer, conv.KagentGenaiProducerAdapter))
+	}


Nothing reads kagent.genai.producer yet. Should we ship the collector rule that uses it, or drop it?

ResourceIdentity (L233-234) puts gen_ai.provider.name and gen_ai.request.model on the child resource, and Claude Code copies resource attributes onto every native span, so consumers with a legacy semconv fallback count every claude_code.* span as a model call (38 vs. 9 in my run). Can we keep gen_ai.* off ChildResource?

krisztianfekete · 2026-10-09T09:11:09Z

+  - key: kagent.genai.producer
+    brief: The component that writes the GenAI model and tool spans of an agent.
+    note: >
+      Set on the resource of a native harness process. With the value `adapter`, the
+      collector counts the spans of the kagent harness adapter for that agent. When absent,
+      the harness writes its own native spans, as in older images.


Which collector? Codex handle_responses already has gen_ai.usage.*, so usage counts twice. Can we add a transform to collector-values.yaml that gets rid of it?

krisztianfekete · 2026-10-09T09:27:04Z

+    type:
+      members:
+        - id: adapter
+          value: adapter
+          brief: The kagent harness adapter writes the model and tool spans.


adapter clashes with the internal/adapter package. Maybe runtime?

yeah, I changed from runtime to adapter, because I found runtime a bit confusing since we also got kagent.runtime as enum. I can change it back to runtime

krisztianfekete · 2026-10-09T09:27:57Z

+	if failed {
+		span.SetStatus(codes.Error, errorTypeModel)
+	}
+	span.End(trace.WithTimestamp(event.End))
+	return nil


Can we also record gen_ai.client.inference.duration and the usage counters here, as proposed in #2943?

krisztianfekete · 2026-10-09T09:28:40Z

+			if invocation == nil && !flushed {
+				flushed = true
+				if err := tracing.InvocationFromContext(ctx).Flush(ctx); err != nil {
+					a2alog.Error(ctx, "failed to flush runtime spans", err)
+				}


Can TestE2ECompletedChatFlushesTraces assert one chat span with the mock token counts before suspension?

krisztianfekete · 2026-10-09T09:42:32Z

+	failed := event.StopReason == tracing.FinishReasonError && !event.Canceled
+	if event.StopReason != "" {
+		attributes = append(attributes, conv.GenAIResponseFinishReasonsKey.StringSlice([]string{event.StopReason}))
+	}


Chat spans have raw end_turn/tool_use, but output messages use stop/tool_call. Let's normalize these?

krisztianfekete · 2026-10-09T09:43:16Z

+  - key: kagent.model_call.usage_partial
+    brief: Whether the call ended without final usage, so its output tokens are a lower bound.
+    note: >


Upstream now prefers "inference". Maybe kagent.inference.usage_partial?

krisztianfekete · 2026-10-09T09:46:02Z

+      - ref: gen_ai.usage.input_tokens
+        requirement_level: opt_in
+        note: Never set here. Token usage is on the chat spans.
+      - ref: gen_ai.usage.output_tokens
+        requirement_level: opt_in


Can we drop these opt_in overrides and state "usage and finish reasons are only on inference spans" once in the telemetry.md Usage section?

krisztianfekete · 2026-10-09T10:06:13Z

+// holdSnapshot keeps a subagent call until a newer message replaces it, so it carries the latest usage.
+// Subagent calls arrive only as assistant snapshots whose usage predates the final delta.
+func (p *parser) holdSnapshot(parent, messageID string, call runtime.ModelCall, emit func(Event) error) error {
+	// Subagent calls carry no timing, so the span runs from the first to the last snapshot of one message.


Subagent lines have timestamps. Can we use it instead of the time we parse the line?

krisztianfekete · 2026-10-09T10:06:58Z

+	// Usage can arrive after an approval pause; keep the call under the segment it ran in.
+	if s.paused != nil && !event.Start.IsZero() && event.Start.Before(owner.began) {
+		owner = *s.paused
+	}
+	span := owner.start(strings.TrimSpace("chat "+event.RequestModel), trace.SpanKindClient, event.Start, attributes...)


Can we nest subagent calls under execute_tool Agent?

krisztianfekete · 2026-10-09T10:20:55Z

+	if s.tools == nil {
+		s.tools = map[string]pendingTool{}
+	}
+	s.tools[event.ID] = pendingTool{id: event.ID, name: event.Name, start: time.Now(), owner: s.owner}


event.Arguments is dropped here. With content capture on, can we record gen_ai.tool.call.arguments and gen_ai.tool.call.result on the execute_tool span, under the same capture budget as invoke_agent?

krisztianfekete · 2026-10-09T10:21:25Z

+	}{
+		{conv.GenAIProviderNameKey, event.Provider},
+		{conv.GenAIRequestModelKey, event.RequestModel},
+		{conv.GenAIResponseModelKey, event.ResponseModel},


Can we add gen_ai.response.id here from the Claude message id (and keep its request_id)? It lets backends join a chat span with provider logs or a proxy span of the same request, and dedupe.

krisztianfekete · 2026-10-09T10:23:22Z

+	if t.Runtime.NativeHarness() {
+		attributes = append(attributes, attribute.String(AttributeGenAIProducer, conv.KagentGenaiProducerAdapter))
+	}


ResourceIdentity (L233-234) puts gen_ai.provider.name and gen_ai.request.model on the child resource, and Claude Code copies resource attributes onto every native span, so consumers with a legacy semconv fallback count every claude_code.* span as a model call (38 vs. 9 in my run). Can we keep gen_ai.* off ChildResource?

krisztianfekete · 2026-10-09T10:24:12Z

+func (tool pendingTool) record(end time.Time, errorType string) {
+	span := tool.owner.start("execute_tool "+tool.name, trace.SpanKindInternal, tool.start,
+		attribute.String(tracing.AttributeOperationName, conv.GenAIOperationNameExecuteTool),
+		conv.GenAIToolNameKey.String(tool.name),


Claude names MCP tools mcp__<server>__<tool>, while adk-go reports the actual MCP tool name for the same tool. Should gen_ai.tool.name be the MCP tool name, with the server in its own attribute, so tools group the same across runtimes?

dhaifley

This is looking great. Nice work. I've added a few comments that I found running some AI tests.

dhaifley · 2026-10-10T16:30:49Z

 		return runtime.Outcome{}, err
 	}
+	// The next call's span must not include the human wait for this input.
+	p.session.translator.lastCallEnd = p.session.translator.now()


If I'm reading the captures right, Codex reports a call's usage only after that call's tools finish. In codex-tools.jsonl each thread/tokenUsage/updated comes right after the tool's item/completed. For an approval-gated tool, that puts the usage of the call that asked for the approval after the resume. This line moves lastCallEnd to the resume time before that frame is read, so the call starts at the resume, and I think the s.paused check at tracing.go:206 can never fire for Codex. I tried it with a scratch test that runs the real ProcessDriver under a2a.New against a fake app server (item/started, elicitation, usage, then after the approval item/completed, usage, turn/completed). The first segment's trace held only invoke_agent. Both chat spans landed in the resumed trace, and the first one started at the resume and lasted 54 microseconds. So the segment that made the call would show zero model calls, and its tokens would sit in another trace, which seems to go against the resume_origin note that a link does not move token usage. TestModelCallReportedAfterThePauseStaysInItsSegment uses Claude-style start times, and the approval scripts in process_test.go send no token usage, so I don't think anything covers this yet. If the span ended at the first item/started, as Krisztian suggested on events.go:144, I think that would also fix this, as long as the reset here doesn't move the start past that end. Another option might be to remember when the turn paused, and give the first usage after the resume the pre-pause start and the pause time as its end.

dhaifley · 2026-10-10T16:31:34Z

 // Cancel resolves the outstanding request when possible, interrupts the Codex
 // turn, and always reaps the App Server process.
-func (p *pendingTurn) Cancel(ctx context.Context) error {
+func (p *pendingTurn) Cancel(ctx context.Context, _ runtime.ModelCallSink) error {


The new doc at runtime.go:115 says Cancel emits every ModelCall the harness reported before it returns, but this Cancel ignores the sink. Frames already buffered in client.frames are never read before stopSession reaps the process, and rpcClient.call skips notifications while it waits for the turn/interrupt reply (rpc.go:110-116). In a scratch test with a parked approval, one usage frame buffered and one more sent between reading the interrupt and replying to it, Cancel recorded 0 of 2 calls. Together with the comment on line 384, I think a cancel at an approval would always lose the tokens of the call that asked for it, while the description says the runtime keeps the calls the harness reported before the cancel. The ctx.Done() path in consume (lines 200 to 215) has the same gap, with 0 of 1 calls kept in the same kind of test. Would it make sense for Cancel to drain the frames through the sink, the way the Claude stopSession now does, and for call to pass the notifications it skips to the sink while it waits?

dhaifley · 2026-10-10T16:32:46Z

+		if subagent {
+			return nil
+		}
+		if err := p.flushOpenCall(emit); err != nil {


If I'm reading Claude Code's retry paths right, an attempt it gives up on mid-stream ends with message_stop and no message_delta. That covers a mid-stream 529, a stale connection, and the fallback to non-streaming. I looked at a newer 2.1.296 build, not the pinned 2.1.285. The message_stop case at line 283 leaves the open call alone, so it stays open until this line closes it at the next message_start. With a fake clock through parseLine, a retry after an 8 s backoff gave the abandoned attempt an end 10 s after its start, error as its finish reason, and the full prompt's 15002 input tokens. The retry then reported the same 15002 again. The same thing happened when Claude Code finalizes a partial response and carries on with a tool. There the open call stayed open across a 30s tool run and was then marked as a failed call in a turn that succeeded. So I think a successful turn could show a failed chat span with the wrong duration, and the summed input tokens would run one prompt over Claude's own result.usage per retry. Would closing the open call at a message_stop that had no message_delta fix most of this? Whether the abandoned attempt should keep its input tokens probably depends on whether it is billed, which I don't know.

dhaifley · 2026-10-10T16:34:20Z

+		call := p.openCall
+		p.openCall = nil
+		p.openUsage.merge(event.Usage).apply(call)
+		call.StopReason, call.End = event.Delta.StopReason, p.now()


The start and end here come from p.now() when the line is parsed, not when Claude printed it. While a turn is parked for an approval, the parser goroutine is blocked on an earlier emit, so anything Claude has already printed waits in the pipe until the resume. I tried a fake Claude that prints one message with two tool_use blocks, the first one gated, and then message_delta, and approved after 1.5s. The chat span came out 1.52s long, with its end 1.50s after the delta line was printed, in 3 of 3 runs. Because the start predates the pause, tracing.go:206 keeps the span in the first segment, so it ends after its invoke_agent parent, which could be hours later for a slow approval. A single-tool message seemed fine, since its delta is parsed before the park. I don't think the subagent timestamp comment covers this, because main-thread stream_event lines carry no timestamp. Maybe a reader that stamps each line when it arrives, ahead of the emit, would fix it? That would matter more if the inference duration metric lands.

dhaifley · 2026-10-10T16:34:41Z

+	// Claude Code writes "<synthetic>" messages itself, without a model call.
+	unstreamed := message.ID != "" && !streamed && message.Model != "<synthetic>"
+	if unstreamed {
+		call := runtime.ModelCall{ResponseModel: message.Model, StopReason: message.StopReason, UsagePartial: true}


A main-thread message that was never streamed also lands here, with parent "". I think that is what Claude Code prints when it falls back to non-streaming mode. Its usage is final, but it is marked usage_partial, and its start equals its end, since both come from the parse time. It is counted once, so the token totals are right. If I'm reading Claude Code right, it also falls back on every call when the streaming endpoint returns 404, so behind a gateway like that every main-thread call would be partial and zero-length. The registry note names only calls cut short and subagent calls. Would it make sense to treat an unstreamed message with parent "" as a complete call, and keep UsagePartial for the subagent snapshots?

Signed-off-by: Kristy Tian <[email protected]>

Claude Agent and Codex spawnAgent subagents write their chat and tool spans under the parent tool span. Signed-off-by: Kristy Tian <[email protected]>

Model call duration and token usage, tool duration, and model and tool calls per invocation, following the GenAI conventions. Codex call times are estimated per thread, so subagent calls get durations too. Signed-off-by: Kristy Tian <[email protected]>

One chat span covers a call and its retries, with kagent.inference.retry.count. Codex error notifications give failed calls, and Claude retried or cut-off attempts no longer show as separate failed calls. Signed-off-by: Kristy Tian <[email protected]>

…enai-spans Signed-off-by: Kristy Tian <[email protected]>

Substrate restores every session from one snapshot, so metrics built at startup made all sessions one writer and their totals overwrote each other. Signed-off-by: Kristy Tian <[email protected]>

Signed-off-by: Kristy Tian <[email protected]>

krisztianfekete

This is great and it's very close to get merged! Did some testing with Codex as well and I couldn't find any issues. Added some smaller comments on Claude Code as currently call durations seems to be shorter, and subagent calls are undercounted.

krisztianfekete · 2026-10-12T09:36:49Z

+		p.openCallDone = false
+		p.streamedMessages[event.Message.ID] = struct{}{}
+		p.openCall = &runtime.ModelCall{ResponseModel: event.Message.Model, ResponseID: event.Message.ID, Start: p.now()}
+		p.openUsage = event.Message.Usage
+		event.Message.Usage.apply(p.openCall)


The span starts at message_start, so it leaves out time to first token. On my local kind cluster it started exactly native ttft_ms late on every call I ran (692/696/520/529ms), and model time came out 36% low (3.998s vs. 6.255s). Can it start at the status: requesting line Claude Code prints before each request?

krisztianfekete · 2026-10-12T09:37:29Z

+		lineTime := p.lineTime(envelope.Timestamp)
+		// A prompt or tool result: that thread's next model call starts here.
+		p.callStart[envelope.ParentToolUseID] = lineTime
+		if envelope.ParentToolUseID == "" && p.openCall != nil {
+			p.openCallDone = true
+		}


callStart already tracks when the next mai -thread call starts, but only failed and retried calls use it. Should normal calls use it too, if status: requesting doesn't work out?

krisztianfekete · 2026-10-12T09:38:18Z

+	// A Codex call from a thread not known yet has no duration, so it adds only its tokens.
+	if event.End.After(event.Start) {
+		m.inferenceDuration.Record(ctx, event.End.Sub(event.Start).Seconds(), withError(attributes, errorType))
+	}
+	// A partial call's input count is exact, but its output count is only a lower bound.
+	perCall := metric.WithAttributes(attributes...)


This metric copies the span duration, so Claude's gen_ai.client.inference.duration is low by the same amount. The conventions measure it from when the request is sent.

krisztianfekete · 2026-10-12T09:40:03Z

+		// token count is final. A subagent's count can still grow, so it stays partial.
+		call := runtime.ModelCall{ResponseModel: message.Model, ResponseID: message.ID, RequestID: requestID,
+			StopReason: claudeFinishReason(message.StopReason), UsagePartial: parent != ""}
+		message.Usage.apply(&call)
+		// A main-thread stream cut off without an end is retried without streaming.
+		if parent == "" && p.openCall != nil {
+			p.retry()
+		}


Did some local testing:
Partial subagent calls only get the 1 to 4 output tokens from the snapshot, against 205 to 698 in native in my testing. On kind the turn came out 34% low in the foreground (792 vs. 1200) and 66% low in the background (706 vs. 2100), and Claude picks background mode on its own.

krisztianfekete · 2026-10-12T09:41:00Z

+		if err := p.flushCalls(emit); err != nil {
+			return err
+		}


The result line's modelUsage has exact per-model totals, subagents included. Can we reconcile the usage counters against it here and keep the spans marked partial?

krisztianfekete · 2026-10-12T09:43:26Z

+		{m.input, event.InputTokens},
+		{m.output, event.OutputTokens},
+		{m.cacheRead, event.CacheReadTokens},
+		{m.cacheWrite, event.CacheWriteTokens},
+		{m.reasoning, event.ReasoningOutputTokens},


The counters could be exact if the Claude driver emits result.modelUsage minus what its calls already reported as a usage-only event, recorded on the counters only. Spans and the per-call histogram stay partial. Wdyt?

yes, agree. modeUsage isn't per turn. So a turn could still report earlier turn tokens. So before each turn we read the total Claude saved in its session file (the cost-state line it restores on resume). At the end of the turn we add modelUsage − saved total − what our calls already reported

On kind testing: 15 sessions (5 per case) output-token counters vs native Claude counts

foreground subagent plus a resumed turn: counter was 27–34% low, now exact in 5 of 5

background subagent: counter was 38–50% low, now exact in 5 of 5

subagent plus an approval pause: counter was 18–24% low, now exact in 5 of 5

plain and tool turns: still exact

…okens from session totals Signed-off-by: Kristy Tian <[email protected]>

krisztianfekete

Thanks @xytian315, LGTM!

xytian315 requested a review from a team as a code owner October 9, 2026 05:07

github-actions Bot added the enhancement New feature or request label Oct 9, 2026

krisztianfekete reviewed Oct 9, 2026

View reviewed changes

dhaifley approved these changes Oct 10, 2026

View reviewed changes

xytian315 added 7 commits October 10, 2026 21:12

fix(harness): address review feedback on runtime GenAI spans

56f1c4a

Signed-off-by: Kristy Tian <[email protected]>

feat(harness): nest subagent spans under the tool that started them

9987b77

Claude Agent and Codex spawnAgent subagents write their chat and tool spans under the parent tool span. Signed-off-by: Kristy Tian <[email protected]>

Merge remote-tracking branch 'upstream/main' into xytian315/runtime-g…

c26201f

…enai-spans Signed-off-by: Kristy Tian <[email protected]>

fix(harness): give each restored session its own metric identity

1949617

Substrate restores every session from one snapshot, so metrics built at startup made all sessions one writer and their totals overwrote each other. Signed-off-by: Kristy Tian <[email protected]>

fix(harness): count model calls right across pauses, retries and cancels

e31cb1f

Signed-off-by: Kristy Tian <[email protected]>

xytian315 force-pushed the xytian315/runtime-genai-spans branch from d89e3d2 to e31cb1f Compare October 12, 2026 05:56

krisztianfekete reviewed Oct 12, 2026

View reviewed changes

fix(harness): time Claude calls from the request and count subagent t…

cac2609

…okens from session totals Signed-off-by: Kristy Tian <[email protected]>

github-actions Bot added enhancement New feature or request and removed enhancement New feature or request labels Oct 12, 2026

krisztianfekete approved these changes Oct 12, 2026

View reviewed changes

EItanya added this pull request to the merge queue Oct 12, 2026

Merged via the queue into kagent-dev:main with commit 4c320cf Oct 12, 2026
59 of 60 checks passed

QuentinBisson mentioned this pull request Oct 13, 2026

[FEATURE] Per-execution token usage on A2A and on the scheduled execution record, for every runtime #2855

Open

1 task done

BrewTestBot mentioned this pull request Nov 9, 2026

kagent 1.0.0 Homebrew/homebrew-core#324443

Merged

Conversation

xytian315 commented Oct 9, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Special cases

Known limits

Testing

Uh oh!

krisztianfekete left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

xytian315 Oct 9, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

dhaifley left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

krisztianfekete left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

xytian315 Oct 12, 2026 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

krisztianfekete left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

xytian315 commented Oct 9, 2026 •

edited

Loading

xytian315 Oct 9, 2026 •

edited

Loading

xytian315 Oct 12, 2026 •

edited

Loading