The support triage agent had a bug for a month and nobody could find it. About one ticket in fifty, it produced a reply that referred to a knowledge base article that did not 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 was not.

We read the logs for hours. We added more logs. We asked the model to explain itself in the output, which produced confident explanations that were also wrong. The bug stayed.

What found it was a trace. Not a log line, a trace, 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 looked at for a bad ticket had the answer in it, and the answer was a retry that the logs did not show.

An agent is a distributed system#

The reason logs fail here is the reason they fail for microservices. A log line is a point. An agent run is a tree. The model is called, it decides on a tool, the tool runs, the result goes back into the model, the model is called again, and this repeats for as many turns as it takes. Some of those tool calls fan out. Some fail and are retried. Some are made by a sub agent the top level agent spawned. If you flatten that tree into a sequence of log lines, you lose the structure, and the structure 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 that the request took four seconds because one span out of forty took three of them, and that span was a retry of a span that failed. That is exactly the question you have about an agent run: which turn went wrong, what did the model see when it made that decision, and how long did each step take.

OpenTelemetry has semantic conventions for GenAI now, stable enough to build on since late 2025. They define span names and attributes for model calls, tool executions and agent runs so that the tree comes out in a shape that any backend can render. The attributes matter because they are what let you ask questions across runs rather than one at a time.

What the tree looks like#

Here is the trace of a normal triage run, simplified:

flowchart TD
  A["invoke_agent triage (12.4s)"] --> B["chat claude-sonnet-5 (1.1s)"]
  A --> C["execute_tool kb.search (0.3s)"]
  A --> D["chat claude-sonnet-5 (0.9s)"]
  A --> E["execute_tool kb.read (0.2s)"]
  A --> F["chat claude-sonnet-5 (2.8s)"]
  A --> G["execute_tool ticket.reply (0.4s)"]

Each chat span is one model call. Its attributes include the model name, the 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 find the trace from the ticket.

Now the trace of a bad run:

flowchart TD
  A["invoke_agent triage (31.7s)"] --> B["chat (1.2s)"]
  A --> C["execute_tool kb.search (0.3s)"]
  A --> D["chat (1.0s)"]
  A --> E["execute_tool kb.read, error 503 (8.0s)"]
  A --> E2["execute_tool kb.read, retry (0.2s)"]
  A --> F["chat (3.1s)"]
  A --> G["execute_tool ticket.reply (0.4s)"]

The knowledge base service timed out on the first read. The tool client retried and succeeded. Correct behaviour. Except that the tool client's retry returned the result to the agent loop, and the agent loop, which had been written before the retry was added, had already appended the error to the conversation as the tool result. So the model saw two tool results for one call: an error, then the article. And the model, doing its best with a confusing history, sometimes blended the error text, which included a fallback article id from the error response, into its citation.

One trace. The tree showed a span with an error and a sibling with the same name right after it, the attributes on the chat span that followed showed two tool result messages for one tool call id, and the bug was obvious. In the logs, the retry was a single line saying "retrying kb.read" that 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, rather than one of the LLM observability products, because the traces go to the same backend as everything else and we did not want a second tool. The instrumentation is not 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 decide about. It puts the full message list on the span, which is what made the retry bug visible, and it is also the customer's ticket text going into your tracing backend. 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 retention of seven days and the backend's field level redaction on the ticket body. That is a decision for your data protection people, not for the person writing the instrumentation, and it should be made before the first span is sent.

The tool spans are the same shape, with gen_ai.tool.name and the arguments and result as attributes, truncated at 4 KB.

The questions you can ask once the attributes exist#

The trace found the bug. The attributes are what changed how we run the thing.

Cost per ticket is a 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 the histogram had a tail: 3 percent of tickets cost ten times the median, and every one of them was a run that hit the max turn limit and gave up. Those were a separate bug, a loop where the model kept re-searching with the same query, visible as twenty identical kb.search spans in a row.

Latency per turn told us that the third model call in a run was consistently the slowest, because that is the one that writes the reply, and that we could stream it and cut the perceived time by half.

Tool error rates by tool name told us the knowledge base service was flaky in a way its own dashboard did not show, because its dashboard measured availability from a health check and not from the calls the agent actually made.

And the finish reason attribute told us how often the model stopped because it hit the output token limit mid reply, which was 1 in 200 and had been silently producing truncated replies that got sent.

None of those were 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 is 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 its own tools, waits, and uses the result. In logs that is two interleaved streams with different run ids. In a trace it is a child invoke_agent span under the parent's execute_tool span, with the whole sub tree below it. The trace context propagates through the same mechanism it uses across services, and the sub agent's model calls and tool calls appear exactly where they happened in the parent's timeline. Nothing about the instrumentation changes for this case. That is the strongest argument for doing it this way rather than inventing an agent specific log format.

What I would do from the start#

Put the agent loop under a root span with the business id on it, so a trace can be found from the thing the user cares about.

One span per model call with the model, the token counts and the finish reason. One span per tool call with the name, and the arguments and result, truncated.

Decide about content capture with whoever owns data handling, and if you capture it, sample it and set retention.

Send it to the backend you already have. The GenAI conventions exist so that Datadog, Honeycomb, Grafana and the rest render the tree without a custom integration, and a second observability tool for one component is a second 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.