DEV Community

Cover image for Observability for AI agents: tracing tool calls, tokens, latency and failures
Amit Shukla
Amit Shukla

Posted on Originally published at amitshuklabag.hashnode.dev

Observability for AI agents: tracing tool calls, tokens, latency and failures

A user reports that your agent "just hung for a minute and then gave a weird answer." You open the logs. You find the request, a few lines of calling model... and tool returned, and the final response. You can't tell which of the nine model calls was slow, which tool returned the garbage that sent it sideways, or why this one run cost forty times more than usual.

A normal web request has one path through your code. An agent run is a loop: the model thinks, picks a tool, reads the result, thinks again, sometimes ten or twenty times, and every run takes a different path. Plain logs flatten that into a wall of lines. What you need is the shape of the run.

This article shows how to get that shape with tracing, using OpenTelemetry, which works with whatever backend you already have.

What you actually need to see

When an agent run goes wrong, the questions are almost always the same:

  • Which step failed or went off track? The third tool call, the seventh model call?
  • What did the model see at that point? Which tool result was in its context when it made the bad decision?
  • Where did the time go? Model latency, a slow tool, or simply too many steps?
  • What did it cost? Input and output tokens per call, and per run.
  • Is it looping? The same tool called with the same arguments again and again.

Every one of those is a question about structure and timing. That is exactly what distributed tracing was built for.

The mental model: one trace per run, one span per step

A trace is the whole agent run. Inside it are spans, each with a start time, a duration, a parent and some attributes:

invoke_agent "triage-issues"            12.4s
├── chat claude                          1.8s   in 2,310  out 140
├── execute_tool github.list_issues      0.6s
├── chat claude                          2.1s   in 6,904  out 212
├── execute_tool github.get_issue        0.4s
├── execute_tool github.get_issue        0.4s   ERROR 404
├── chat claude                          3.9s   in 9,877  out 518
└── execute_tool github.add_label        0.3s
Enter fullscreen mode Exit fullscreen mode

One glance tells you how many steps it took, which tool failed, and that the context grew from 2,310 to almost 10,000 tokens. That last detail is usually where your cost and latency are hiding.

OpenTelemetry has semantic conventions for exactly this kind of span, under the gen_ai namespace. They are still marked as in development, but most observability tools already understand them. The useful attributes:

Attribute Example
gen_ai.operation.name chat, execute_tool, invoke_agent
gen_ai.request.model claude-sonnet-4
gen_ai.usage.input_tokens 6904
gen_ai.usage.output_tokens 212
gen_ai.tool.name github.get_issue
gen_ai.response.finish_reasons ["tool_use"]

Using the standard names means you can switch backends later without rewriting your dashboards.

Step 1: Run a trace backend locally

For development, Jaeger runs as a single container with an OpenTelemetry endpoint and a UI:

docker run --rm -p 16686:16686 -p 4318:4318 jaegertracing/jaeger:latest
Enter fullscreen mode Exit fullscreen mode

Port 4318 receives traces over OTLP/HTTP. Port 16686 is the UI at http://localhost:16686. In production you would point the same code at Grafana Tempo, Honeycomb, Datadog or any other backend that speaks OTLP.

Step 2: Set up the tracer

pip install anthropic opentelemetry-sdk opentelemetry-exporter-otlp-proto-http
Enter fullscreen mode Exit fullscreen mode
from opentelemetry import trace
from opentelemetry.sdk.resources import Resource
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.exporter.otlp.proto.http.trace_exporter import OTLPSpanExporter

provider = TracerProvider(resource=Resource.create({"service.name": "issue-agent"}))
provider.add_span_processor(
    BatchSpanProcessor(OTLPSpanExporter(endpoint="http://localhost:4318/v1/traces"))
)
trace.set_tracer_provider(provider)
tracer = trace.get_tracer("issue-agent")
Enter fullscreen mode Exit fullscreen mode

Step 3: Wrap the agent loop

Here is a minimal tool-using agent loop with spans around the run, every model call and every tool call:

import json
import anthropic
from opentelemetry.trace import Status, StatusCode

client = anthropic.Anthropic()
MODEL = "claude-sonnet-4-20250514"

def run_agent(task, tools, tool_impls, max_steps=15):
    with tracer.start_as_current_span("invoke_agent issue-agent") as run_span:
        run_span.set_attribute("gen_ai.operation.name", "invoke_agent")
        messages = [{"role": "user", "content": task}]
        total_in = total_out = 0

        for step in range(max_steps):
            with tracer.start_as_current_span(f"chat {MODEL}") as span:
                span.set_attribute("gen_ai.operation.name", "chat")
                span.set_attribute("gen_ai.request.model", MODEL)
                resp = client.messages.create(
                    model=MODEL, max_tokens=1024, tools=tools, messages=messages
                )
                span.set_attribute("gen_ai.usage.input_tokens", resp.usage.input_tokens)
                span.set_attribute("gen_ai.usage.output_tokens", resp.usage.output_tokens)
                span.set_attribute("gen_ai.response.finish_reasons", [resp.stop_reason])
                total_in += resp.usage.input_tokens
                total_out += resp.usage.output_tokens

            messages.append({"role": "assistant", "content": resp.content})
            if resp.stop_reason != "tool_use":
                run_span.set_attribute("agent.steps", step + 1)
                run_span.set_attribute("gen_ai.usage.input_tokens", total_in)
                run_span.set_attribute("gen_ai.usage.output_tokens", total_out)
                return resp

            results = []
            for block in resp.content:
                if block.type != "tool_use":
                    continue
                with tracer.start_as_current_span(f"execute_tool {block.name}") as tspan:
                    tspan.set_attribute("gen_ai.operation.name", "execute_tool")
                    tspan.set_attribute("gen_ai.tool.name", block.name)
                    tspan.set_attribute("agent.tool.args", json.dumps(block.input)[:500])
                    try:
                        output = tool_impls<a href="**block.input">block.name</a>
                        is_error = False
                    except Exception as e:
                        output, is_error = f"error: {e}", True
                        tspan.record_exception(e)
                        tspan.set_status(Status(StatusCode.ERROR))
                    tspan.set_attribute("agent.tool.result_chars", len(str(output)))
                results.append({"type": "tool_result", "tool_use_id": block.id,
                                "content": str(output), "is_error": is_error})
            messages.append({"role": "user", "content": results})

        run_span.set_status(Status(StatusCode.ERROR, "max steps reached"))
        raise RuntimeError("agent hit max_steps")
Enter fullscreen mode Exit fullscreen mode

A few deliberate choices in there:

  • Tool arguments are truncated to 500 characters. Enough to debug, not enough to fill your trace store.
  • Tool results are recorded by size, not content. A tool that returns 40,000 characters is a cost and latency problem you want to spot. You usually don't want the full content in every span.
  • Totals go on the root span. That makes "tokens per run" and "steps per run" one query away.
  • Hitting max_steps marks the run as an error. An agent that never finishes should show up red, not quietly time out.

Run it, open Jaeger, pick the issue-agent service, and every run shows up as a waterfall like the one above.

Step 4: Decide what not to record

Prompts and tool results are the most useful debugging data and also the most dangerous. They contain customer data, internal documents, sometimes secrets a tool returned by accident.

A sensible default:

  • Always record structure, timing, model, token counts, tool names, finish reasons, errors.
  • Record truncated arguments for tools, with obvious secrets redacted.
  • Record full prompt and response content only in development, or behind a flag, or sampled for a small share of runs with a short retention period.

The OpenTelemetry GenAI conventions follow the same idea: content capture is opt in, not on by default.

Step 5: Turn traces into the numbers that matter

Once spans are flowing, a handful of metrics tells you most of what you need about agent health:

  • Steps per run, as a distribution. A sudden shift to the right usually means a prompt change or a tool change confused the model.
  • Tokens per run, input and output separately. Input tokens grow with every step because the whole history is resent. That is often the biggest cost driver.
  • Tool error rate per tool. One flaky tool can make the whole agent look unreliable.
  • Repeated identical tool calls within a run. Count spans with the same tool name and the same arguments. More than two is almost always a loop.
  • p95 run duration, broken down by model time versus tool time.
  • Runs that hit max steps. These should be rare. When they are not, something changed.

Most backends can derive these from span attributes directly. If yours can't, emit a few OpenTelemetry metrics at the end of each run from the totals you already compute.

Debugging a real failure with this

Back to the user whose agent "hung and gave a weird answer." With tracing, you search for their run and see:

  • 14 steps instead of the usual 4
  • execute_tool search_docs called 6 times with nearly the same query
  • each result around 30,000 characters
  • input tokens climbing to 120,000 by the last model call, with that call alone taking 19 seconds

Now you have a real fix to make. search_docs returns too much text, and the model keeps rephrasing the same search because the results don't contain what it needs. The fix is to trim and rank the tool's output and add a max_results parameter, not to tweak the system prompt.

Without traces, you would have spent an afternoon guessing.

Takeaway

An agent run is a tree of decisions, not a single request, so observe it like one. Put a span around every model call and every tool call, record tokens and timing on each, keep the sensitive content off by default, and watch steps, tokens and tool errors per run. The first time an agent misbehaves in production, you will know exactly which step to look at.


Keep reading

Let's stay in touch

I'm Amit Shukla, a software engineer working across DevOps, cloud and applied AI. Behind the Stack is where I write up the things I learn the hard way, with working code and honest tradeoffs.

If this saved you some time, a reaction or a comment helps more people find it.

Top comments (0)