Written on by Ephraim Duncan

How to debug slow AI agents with OpenTelemetry

Debug slow AI agents with an OpenTelemetry trace. Tell model latency, tool timeouts, and retrieval delays apart, and find the step to fix first.

A customer writes in: the support agent took 40 seconds to answer a refund question. Your dashboard says the p95 for agent runs is 38 seconds. Neither number tells you what to change. The model could be slow. A tool could be stuck on a timeout. The vector search could be slow, or the agent could make five model calls where two would do.

The model is the first thing most people blame. A trace tells you whether that is fair. In an OpenTelemetry trace, each step of the run is a span with a start time, a duration, and a status, and the spans nest under the agent run that started them. To debug slow AI agents, read the trace from the outside in: the whole run first, then the step that holds the time, then the errors and token counts behind that step.

The screens described here are from telemetry.dev. The method works in any tool that shows OpenTelemetry spans as a tree with a timeline, and I point out the parts that are specific to telemetry.dev.

Total run time and step time are different numbers

Start in the traces list. Sort by Duration and open the slowest trace from the time the customer reported. That Duration is the whole run, from the start of the first span to the end of the last. It tells you that a run was slow. It does not tell you why.

Inside the trace, each row of the span tree is one step. The bar shows when the step ran, and the number on the right is how long it took. Steps that run one after another add up, so the run takes about as long as their sum. Steps that run at the same time overlap, so three parallel tool calls cost the run the time of the slowest one.

Here is a trace from a support agent that answers order questions. The numbers are made up, but the shape is common:

invoke_agent support-agent         38.2 s
├─ chat gpt-4.1                     2.1 s
├─ execute_tool search_orders      30.0 s   TimeoutError
├─ chat gpt-4.1                     1.8 s
├─ retrieval help-center            3.9 s
└─ chat gpt-4.1                     0.4 s

One tool call that timed out holds 30 of the 38 seconds. The three model calls add up to 4.3 seconds. A faster model would take a few seconds off this run at most, and the customer would still wait more than half a minute.

In telemetry.dev, select the agent span to get the same answer as a bar. Its Metrics section splits the run time into Model, Tools, and Other. Model and Tools add up the durations of the agent's direct model and tool spans. Other is what is left: your own code between steps, waits between retries, and steps that are neither a model call nor a tool, like the retrieval above. For this trace, the split is Model 4.3 s, Tools 30.0 s, and Other 3.9 s.

Read the split together with the timeline. It adds child durations, so tool calls that run in parallel can add up to more than the run itself. When a tool starts a subagent, the subagent's model time counts as tool time, and the panel says so.

Inspect model calls, tool steps, and retrievals

The type of the slow step tells you where to look next.

Model calls

A model span, shown as Chat in the span tree, holds two waits: the wait for the first token, and the time to write the rest of the answer. When your instrumentation records time to first chunk, the span panel shows both as First token and Output speed, in tokens per second. If you do not stream, First token stays empty and the duration is one number.

A long wait for the first token with a short answer points at the input. Look at the input token count. A prompt that grows with every tool result can take seconds before the first token comes back. Reasoning models also think before they answer, and the token split on the span shows those tokens as Reasoning.

A fast first token with a long duration points at the output. 2,000 output tokens at 50 tokens per second is 40 seconds, whatever else you change. Look at the output count and at the output limit you send.

More model calls than you expected points at the agent loop, not the model. Count the Chat rows. Each extra turn adds a full round trip, and the model reads the whole conversation so far as input again.

If you instrument your HTTP client, the HTTP spans under a model call show retries, and the subtitle of each one shows the response status. A row of 429 responses is a rate limit, not a slow model.

Tool steps

A tool span, shown as Tool, wraps a function that the agent called. Most tool latency belongs to something else: an internal API, a database, or a third-party service.

A timeout has a shape that you learn to spot. The duration is a round number that matches a timeout in your code, such as 10.0 s or 30.0 s, and the span has an error status. If several spans for the same tool follow each other and each one stops at the same duration, your code retried the timeout and the run waited for every attempt.

A slow tool that succeeds is a different problem. Compare its duration with the same tool in a fast trace. With content capture on, the span panel shows the arguments that the model sent. When a tool is fast for one customer and slow for another, the arguments often explain it, for example a date range of three years instead of three days.

Look out for the timeout that does not look like an error. If the tool catches the timeout and returns an empty result, its span ends with an OK status. The model gets nothing useful back, so it calls the tool again or writes a vague answer. Each span looks fine on its own. The tool output and the next model call show what happened.

Retrievals

A retrieval span, shown as Retrieval, is a search against a vector store or a search index. Slow retrieval often comes from the work around the search, such as the embedding call for the query or a rerank of a large result set. If you trace those steps as their own spans, they appear as Embeddings and Rerank rows next to the search, and you can see which part is slow.

In telemetry.dev, the retrieval panel shows the data source from gen_ai.data_source.id. When the agent searches more than one index, that tells you which one was slow.

Where the retrieval sits also matters. A retrieval before the first model call delays everything after it. A retrieval that the model calls as a tool is a tool span and counts as Tools in the agent's time split. A retrieval that your own code runs between turns counts as Other.

Set gen_ai.operation.name to retrieval on these spans yourself. When the attribute is missing, telemetry.dev guesses the operation, and any gen_ai.* attribute makes it guess a model call. A retrieval span that has gen_ai.data_source.id but no operation name shows up as a model call.

import { SpanKind, trace } from "@opentelemetry/api";

const tracer = trace.getTracer("support-agent");

export async function searchHelpCenter(query: string) {
  return tracer.startActiveSpan(
    "retrieval help-center",
    {
      kind: SpanKind.CLIENT,
      attributes: {
        "gen_ai.operation.name": "retrieval",
        "gen_ai.data_source.id": "help-center",
      },
    },
    async (span) => {
      try {
        return await vectorStore.search(query, { topK: 8 });
      } finally {
        span.end();
      }
    },
  );
}

Investigate the slow span and its errors

Slow steps and failed steps are often the same steps. A timeout is both, and a retry after an error makes the run longer. Read the errors in the trace before you decide that something is only slow.

In telemetry.dev, failed spans are red in the span tree, and the tree shows how many spans failed. The Filters menu has Errors only, which keeps the failed spans and the spans above them. The same menu lists the span types, so you can hide the ones that you have ruled out.

Select a failed span to open its Error section. It shows the exception type, the message, and the stack trace from the span's exception event. If you select the agent span of a failed run, the Error section shows the error of the child that failed, with a link to that span.

That section can only show what your spans record. For a tool that can time out, record the exception, set the error status, and set error.type:

import { SpanStatusCode, trace } from "@opentelemetry/api";

const tracer = trace.getTracer("support-agent");

export async function searchOrders(customerId: string) {
  return tracer.startActiveSpan("execute_tool search_orders", async (span) => {
    span.setAttributes({
      "gen_ai.operation.name": "execute_tool",
      "gen_ai.tool.name": "search_orders",
    });

    try {
      const response = await fetch(`${ordersApi}/customers/${customerId}/orders`, {
        signal: AbortSignal.timeout(10_000),
      });

      if (!response.ok) throw new Error(`Orders API returned ${response.status}`);

      return await response.json();
    } catch (error) {
      if (error instanceof Error) {
        span.recordException(error);
        span.setAttribute("error.type", error.name);
      }

      span.setStatus({ code: SpanStatusCode.ERROR });
      throw error;
    } finally {
      span.end();
    }
  });
}

When the timeout fires, fetch rejects with a TimeoutError, so the trace shows TimeoutError as the error type of the span.

Compare latency with token and cost evidence

Duration says where the time went. Tokens and cost often say why. In the traces list, the Tokens and Cost columns sit next to Duration and sort the same way. The Spans view of the list puts each span on its own row with its type, model, status, duration, tokens, and cost, so you can sort every model call in a time range by duration, not only whole runs.

What you seeWhere to look
A slow run with few tokens and a low costOutside the model: tools, retrieval, or your own code
A slow model call with a large input countTool results or history that grow with each turn
A slow model call with many output or reasoning tokensThe output limit and the reasoning setting
Run time and cost that grow with the number of turnsThe agent loop, which takes more turns than the task needs

The token split on a model span shows input, cache write, cached input, reasoning, and output. When a large prompt is the problem, it also shows how much of that prompt came from the provider's prompt cache.

Treat cost in telemetry.dev as an estimate. It comes from the token counts on each span and a snapshot of model prices, and it does not include discounts or fees that your provider bills outside token counts. If the snapshot has no price for a model, or a span reports no token usage, the cost of that span is unknown. The trace total leaves it out instead of counting it as zero. To use your own prices, send gen_ai.usage.cost on the span. The cost reference has the full rules.

Connect existing OpenTelemetry instrumentation to telemetry.dev

If your agent already exports OpenTelemetry spans, you can keep that instrumentation and send the same spans to telemetry.dev. There are two ways.

The first is the telemetry.dev span processor. Add it to the tracer provider that you already have. It reads your API key from TELEMETRY_DEV_API_KEY, and Python has the same processor in the telemetry-dev package.

import { NodeSDK } from "@opentelemetry/sdk-node";
import { TelemetrySpanProcessor } from "@telemetry-dev/otel";

const sdk = new NodeSDK({
  spanProcessors: [new TelemetrySpanProcessor()],
});

sdk.start();

The second needs no telemetry.dev package. Point a standard OTLP/HTTP exporter at the ingest API with these environment variables:

OTEL_EXPORTER_OTLP_PROTOCOL=http/protobuf
OTEL_EXPORTER_OTLP_ENDPOINT=https://ingest.telemetry.dev
OTEL_EXPORTER_OTLP_HEADERS=Authorization=Bearer%20td_live_...

On the spans that you create yourself, set gen_ai.operation.name as in the examples above: chat, execute_tool, retrieval, or invoke_agent. The telemetry.dev SDKs set it for you. The OpenTelemetry guide covers both setups in TypeScript, Python, and other languages. The integrations index has a guide for each framework and model provider.

The order to work in

When the next slow run comes in:

  1. Sort the traces by duration and open the slowest one from the reported time.
  2. Use the time split or the timeline to find the step that holds the time.
  3. Check that step for an error before you treat it as slow.
  4. For a model call, compare the first token, the output speed, and the token counts.
  5. For a tool, compare the duration with your timeout and count the retries.
  6. For a retrieval, check the data source and where the step sits in the run.

Then change one thing, and compare the next trace with this one.

Share this article: