The support triage agent had a bug for a month and nobody could find it. About one ticket in fifty got a reply that pointed to a knowledge base article that didn't exist. The logs showed the model's final output and the tool calls in between, and the tool calls looked fine: search the knowledge base, get results, read an article, draft a reply. The article it read was real. The article it cited wasn't.
We read the logs for hours, then added more logs. We asked the model to explain itself in the output, which got us confident explanations that were also wrong. The bug stayed.
A trace found it, the kind with spans and parent ids and durations, the same shape we use for a request that crosses six services. The first one I opened for a bad ticket had the answer in it, and the answer was a retry the logs didn't show.
An agent is a distributed system
Logs fail here for the same reason they fail for microservices. A log line is a point, and an agent run is a tree. The model gets called and picks a tool, the tool runs, the result goes back to the model, the model gets called again, and that repeats for as many turns as it takes. Some tool calls fan out. Some fail and get retried. Some come from a sub agent the top level agent started. Flatten that tree into a list of log lines and you lose the structure, which is where the bugs are.
We solved this for services with distributed tracing. A trace is the tree. Every unit of work is a span with a start, an end, a parent and attributes. You can see the request took four seconds because one span out of forty took three of them, and that span was a retry of one that failed. That's exactly what you want to know about an agent run: which turn went wrong, what the model saw when it made that decision, and how long each step took.
OpenTelemetry now has semantic conventions for GenAI, stable enough to build on since late 2025. They define span names and attributes for model calls, tool executions and agent runs, so the tree comes out in a shape any backend can draw. The attributes matter, because they're what let you ask questions across many runs instead of one at a time.
What the tree looks like
Here's the trace of a normal triage run, simplified:
Each chat span is one model call. Its attributes include the model name, token counts in and out, the finish reason and, in our setup, the messages that went in and came out. Each execute_tool span has the tool name, the arguments and the result. The root invoke_agent span has the agent name, the run id, and the ticket id as a custom attribute so we can get from the ticket to the trace.
And here's the trace of a bad run:
The knowledge base service timed out on the first read. The tool client retried and succeeded, which is correct. But the retry handed its result back to the agent loop, and the agent loop, written before the retry existed, had already appended the error to the conversation as the tool result. So the model saw two tool results for one call, an error and then the article. Doing its best with a confusing history, it sometimes mixed the error text into its citation, and the error response happened to include a fallback article id.
One trace did it. The tree showed a span with an error and a sibling with the same name straight after it, the attributes on the following chat span showed two tool result messages for one tool call id, and the bug was obvious. In the logs, the retry was a single "retrying kb.read" line nobody had connected to anything, and the message list was never logged because it was too big.
Instrumenting it
We use the OpenTelemetry SDK directly with the GenAI conventions, instead of one of the LLM observability products, because the traces go to the same backend as everything else and we didn't want a second tool. It isn't much code. The agent loop looks roughly like this:
import { trace, SpanStatusCode } from "@opentelemetry/api";
const tracer = trace.getTracer("triage-agent");
export async function runAgent(ticket: Ticket) {
return tracer.startActiveSpan("invoke_agent triage", async (root) => {
root.setAttributes({
"gen_ai.operation.name": "invoke_agent",
"gen_ai.agent.name": "triage",
"app.ticket.id": ticket.id,
});
try {
let messages = initialMessages(ticket);
for (let turn = 0; turn < MAX_TURNS; turn++) {
const reply = await chat(messages); // its own span
if (reply.stop) return reply.text;
for (const call of reply.toolCalls) {
const result = await executeTool(call); // its own span
messages = append(messages, call, result);
}
}
throw new Error("max turns");
} catch (err) {
root.recordException(err as Error);
root.setStatus({ code: SpanStatusCode.ERROR });
throw err;
} finally {
root.end();
}
});
}
async function chat(messages: Message[]) {
return tracer.startActiveSpan("chat claude-sonnet-5", async (span) => {
span.setAttributes({
"gen_ai.operation.name": "chat",
"gen_ai.request.model": "claude-sonnet-5",
});
const res = await client.messages.create({ model: "claude-sonnet-5", messages });
span.setAttributes({
"gen_ai.usage.input_tokens": res.usage.input_tokens,
"gen_ai.usage.output_tokens": res.usage.output_tokens,
"gen_ai.response.finish_reasons": [res.stop_reason],
});
span.addEvent("gen_ai.content", { messages: JSON.stringify(messages) });
span.end();
return parse(res);
});
}
The gen_ai.content event is the one you have to make a call on. It puts the full message list on the span, which is what made the retry bug visible, and it also sends the customer's ticket text into your tracing backend.1 Your data protection people should make that decision, not whoever writes the instrumentation, and it should be made before the first span goes out.
Tool spans have the same shape, with gen_ai.tool.name and the arguments and result as attributes, cut off at 4 KB.
The questions you can ask once the attributes exist
The trace found the bug. The attributes changed how we run the thing.
Cost per ticket is the sum of gen_ai.usage.input_tokens across the chat spans under a root, grouped by day. Before tracing we had a monthly bill and a guess. After, we had a histogram, and it had a tail: 3 percent of tickets cost ten times the median, and every one was a run that hit the max turn limit and gave up.2
Latency per turn showed that the third model call in a run was always the slowest, because that's the one writing the reply, and that streaming it could halve how long it felt.
Tool error rates by tool name showed the knowledge base service was flaky in a way its own dashboard missed, because that dashboard measured availability with a health check, not from the calls the agent actually made.
And the finish reason attribute showed how often the model stopped mid reply because it hit the output token limit. It was 1 in 200, and those truncated replies had been going out without anyone noticing.
None of those was the bug we were looking for. All of them came out of the same week of looking at traces.
The sub agent case
One last shape, because it's the one that breaks naive logging completely. When the triage agent decides a ticket needs a code lookup, it starts a second agent with its own loop and tools, waits, and uses the result. In logs that's two interleaved streams with different run ids. In a trace it's a child invoke_agent span under the parent's execute_tool span, with the whole sub tree beneath it. Trace context propagates the same way it does across services, and the sub agent's model and tool calls show up exactly where they happened on the parent's timeline. The instrumentation doesn't change at all for this case, and that's the strongest argument for doing it this way instead of inventing a log format just for agents.
What I would do from the start
Put the agent loop under a root span with the business id on it, so you can find a trace from the thing the user cares about.
Give every model call a span with the model, the token counts and the finish reason, and every tool call a span with the name plus the arguments and result, truncated.
Decide about capturing content with whoever owns data handling, and if you do capture it, sample it and set retention.
Send it all to the backend you already have. The GenAI conventions exist so that Datadog, Honeycomb, Grafana and the rest can draw the tree without a custom integration, and a second observability tool for one component is one more place to look during an incident.
Then open the first trace for a run that went wrong. In my experience the bug is in it.
Originally published at zeybek.dev.
-
We keep it on, sampled at 100 percent for runs that end in an error or a low confidence score and at 5 percent otherwise, with seven days of retention and the backend's field level redaction on the ticket body. ↩
-
That was a separate bug, a loop where the model kept searching again with the same query, which showed up as twenty identical
kb.searchspans in a row. ↩
Top comments (0)