Why a trace, not a log, debugs an agent

A log line is a point in time; a trace is a shape in time. An agent’s failure modes are almost always about shape: the run took nine seconds — but was that one slow model call or six fast ones plus a stalled tool? The answer was wrong — but did the model hallucinate, or did a tool silently return an error payload the model trusted? A stream of log lines forces you to reconstruct the call tree in your head from timestamps and correlation guesses. A trace is that tree, already assembled.

Concretely, a trace is a set of spans — each a timed unit of work with a name, a start and end, attributes, events, and a parent — that share one trace_id and link to each other by span_id/parent_span_id. Rendered on a timeline, they become a waterfall: nested bars whose length is duration and whose indentation is causality. For an ADK agent, that waterfall maps one-to-one onto the thing you actually want to reason about — the reasoning loop — which is why tracing, of the three observability pillars, is the one that turns ‘the agent is misbehaving’ from an investigation into a glance.

Advertisement

OpenTelemetry: the backbone ADK builds on

ADK does not invent a bespoke tracing format; it emits OpenTelemetry (OTel), the vendor-neutral standard for traces, metrics, and logs. That single choice is what makes agent traces portable: the same spans flow to Google Cloud Trace, Arize Phoenix, Langfuse, Jaeger, Grafana Tempo, Datadog, or a plain OTLP collector, with no change to your agent code. You instrument once and choose the backend later — or several at once.

The mental model has three pieces. A Tracer creates spans. A TracerProvider owns the tracer and holds the pipeline. A SpanProcessor plus an Exporter decide how finished spans leave the process — batched and shipped over OTLP (the OpenTelemetry Protocol, gRPC or HTTP) to a collector or backend. ADK’s runtime is already instrumented: as the Runner drives an invocation, it opens and closes spans around the agent, each model call, and each tool call. Your job is not to write span code — it is to configure the provider and exporter so ADK’s built-in spans have somewhere to go. Everything downstream in this article is reading what ADK already emits.

Advertisement

The span tree one invocation produces

Send one message to an ADK agent and, under the hood, a nested tree of spans is born. The root is the invocation — the whole turn, from user input to final response. Beneath it sits an agent span (named for the agent that ran, e.g. agent_run [support_agent]). Inside that, the reasoning loop alternates between two kinds of children: LLM call spans (call_llm) and tool call spans (execute_tool [get_order]). A typical two-step run looks like:

invocation                         3.9s
└─ agent_run [support_agent]     3.9s
   ├─ call_llm                    1.1s   (model decides to call a tool)
   ├─ execute_tool [get_order]    0.3s   (tool runs, returns JSON)
   ├─ call_llm                    2.3s   (model reads result, drafts answer)
   └─ execute_tool [send_email]   0.2s   (final side effect)

The indentation is the causality: every execute_tool is a child of the agent span because the agent invoked it, and the two call_llm spans are siblings because they are separate round trips to the model in the same loop. Read top to bottom, the tree is a transcript of the agent’s decisions; read by width, it is a latency budget. Both readings come from the same structure, which is the whole point of tracing an agent rather than logging it.

What each span carries: attributes

A span’s name tells you what; its attributes (key/value pairs) tell you the detail you actually debug from. ADK follows the OpenTelemetry GenAI semantic conventions, so a call_llm span carries standardized keys rather than ad-hoc ones. The important attributes, by span kind:

SpanRepresentative attributes
call_llmgen_ai.system, gen_ai.request.model, gen_ai.usage.input_tokens, gen_ai.usage.output_tokens, finish reason, and (optionally) the request/response payload
execute_tooltool name, the call arguments, the returned result (or its shape/size), and an error status if it raised
agent_runagent name, and the correlating ids (invocation, session, user) shared by every child

Two attributes on the model span do most of the work in practice. Token counts (input_tokens/output_tokens) are your cost and context-bloat signal — an input-token count that climbs turn over turn is a context-engineering problem made visible. Span duration is your latency signal. Together they answer ‘which call was expensive, in money and in time?’ without leaving the span. On the tool side, the arguments and result attributes are what let you see that the model called get_order with the wrong id, or that the tool returned an error the model then treated as data.

Correlation: trace ids, span ids, invocation ids

Spans are only useful because they link. Three id layers do the stitching, and knowing which is which is what lets you pivot from a metric to a trace to a session. First, OpenTelemetry’s own ids: every span in one invocation shares a trace_id, and each span records its span_id and its parent_span_id — that parent pointer is exactly what the waterfall renders as indentation. Second, ADK’s domain ids, attached as attributes on the spans: the invocation id (one turn), the session id (the whole conversation across many turns), and the user/app ids.

The two layers answer different questions. The trace_id answers ‘show me this one turn as a tree.’ The session id answers ‘show me every turn in this conversation’ — multiple traces, ordered, which is how you debug a failure that only emerges after forty turns of accumulated state. Because ADK stamps these ids onto spans and onto its structured logs and event log, the same identifier threads all three: a cost-anomaly alert carries a session id, you look up that session’s traces, you open the slow turn’s waterfall, you drop to the exact call_llm span. One correlation contract, enforced by the runtime, is what makes that pivot a matter of copying an id rather than a forensic reconstruction.

Turning tracing on and exporting over OTLP

Because ADK emits standard OTel, enabling tracing is standard OTel setup: build a TracerProvider, attach a batch processor with an OTLP exporter, and register it globally before you run the agent. Any collector or backend that speaks OTLP then receives ADK’s spans.

from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.sdk.resources import Resource
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter

provider = TracerProvider(
    resource=Resource.create({"service.name": "support-agent"}),
)
provider.add_span_processor(
    BatchSpanProcessor(OTLPSpanExporter(endpoint="http://localhost:4317")),
)
trace.set_tracer_provider(provider)

# ...now build and run your ADK agent as usual; the Runner's
# built-in spans flow through this provider to the collector.
runner.run(user_id="u1", session_id="s1", new_message=msg)

Two details matter operationally. Use a batch processor, not a simple one — the simple processor exports synchronously on every span end and adds latency to the hot path; the batch processor buffers and ships in the background. And set a real service.name on the resource: backends group and filter by it, so a meaningful name is the difference between one findable service and an anonymous blob. The OTLP endpoint here points at a local collector; in production it points at your collector’s address, and the collector fans out to whatever backends you configure.

Shipping to real backends: Cloud Trace, Phoenix, Langfuse

The exporter is the only thing that changes per backend; the spans are identical. Three common destinations for ADK traces:

BackendHow the spans get thereBest at
Google Cloud TraceCloud Trace OTLP endpoint / exporter (native on Vertex AI Agent Engine)GCP-native latency waterfalls, tie-in with Cloud Logging
Arize PhoenixOTLP / OpenInference instrumentation; phoenix.otel.register()LLM-native trace views, prompt/response inspection, evals
LangfuseOTLP HTTP endpoint with an auth header (env vars)Session grouping, cost dashboards, prompt management
Any OTLP collectorOTLP gRPC/HTTP to the collector, fan-out downstreamVendor-neutral routing, sampling, redaction in one place

Langfuse is representative of the OTLP-endpoint pattern — you point the same exporter at its ingest URL and supply credentials by environment:

export OTEL_EXPORTER_OTLP_ENDPOINT="https://cloud.langfuse.com/api/public/otel"
export OTEL_EXPORTER_OTLP_HEADERS="Authorization=Basic <base64 pk:sk>"

Arize Phoenix flips the ergonomics: a one-call register() stands up the provider and exporter for you, after which ADK’s spans appear in Phoenix’s LLM-aware trace UI. The lesson is that ‘which backend’ is a late, reversible decision. Instrument to OTLP, route through a collector, and you can send the same trace to Cloud Trace for the on-call view and Phoenix for the prompt-debugging view at the same time.

Reading the waterfall: the anatomy of the view

Open one trace and you get a waterfall: a vertical list of spans, each a horizontal bar positioned by start time and sized by duration, indented under its parent. Learning to read it fast is a small, learnable skill. Scan three things in order. First, the total width — the root span’s length is the end-to-end latency the user felt; everything else is a breakdown of it. Second, the widest child bars — your eye goes straight to the longest bar, because that is where the time went; in agent traces it is almost always a call_llm span, occasionally a slow tool.

Third, the gaps and the counts. A gap — dead space where no child span is running but the parent still is — is time spent in your own orchestration code, serialization, or queueing, and it is easy to miss because nothing ‘shows.’ A high count of near-identical sibling spans is the fingerprint of a loop. Color and status round it out: most UIs tint errored spans red, so a failing tool announces itself. The discipline is to resist reading the transcript first; read the shape first — width, gaps, counts, colors — because the shape localizes the problem before you have read a single attribute.

Debugging a slow run: find the expensive call

A run takes eight seconds and someone wants to know why. The trace answers structurally. Sort or scan the child spans by duration; one call_llm at 5.4s dwarfs the rest. That single fact reframes the whole investigation — it is not ‘the agent is slow,’ it is ‘one model call is slow,’ and now you open that span’s attributes. Check input_tokens: if it is 40,000, the call is slow because the context is enormous — the fix is context engineering (trim history, summarize, move facts to state), not a faster model. If input tokens are modest but output_tokens is 3,000, the model is generating a wall of text — constrain the output. If both are small and the span is still slow, the latency is upstream (model-provider queueing, a cold route), which is a capacity or routing conversation, not a prompt one.

The same method catches the subtler case: no single span is huge, but there are seven call_llm spans where you expected two. The agent is taking more reasoning steps than intended — a vague instruction, a tool whose result nudges another lookup, a planner that over-decomposes. The waterfall makes step-count a visible quantity, so ‘too many round trips’ stops being a hunch and becomes something you can see and then reduce.

Debugging a wrong run: find the failing tool

Wrong answers are harder than slow ones because nothing crashes. The trace still localizes them. Walk the spans in order and read the execute_tool attributes at each step. The failure is usually one of three shapes, each visible in a span. Wrong arguments: the model called get_order with {id: "last one"} instead of a real order id — the args attribute shows it, and the cause is upstream, in how the prompt or the previous tool result described the id. A failing tool that looks successful: the span carries a result like {error: "not found"} but no error status, so the model read an error string as data and confidently built an answer on it — this is the most common silent wrong-answer cause, and it is invisible without the result attribute.

A genuinely errored span: the tool raised, the span is red with an exception event, and the model either retried or apologized. In every case the method is the same — do not stare at the final answer trying to infer the cause; find the earliest span where the data going into the model was already wrong. Tracing turns ‘why did it say that?’ into ‘which span first contained the bad value?’, and the second question has an answer you can point at.

Spotting the retry storm and the loop

Some of the most expensive agent failures are not one big thing but a small thing repeated. The trace makes them unmistakable. A retry storm shows up as a run of near-identical sibling spans — ten execute_tool [search_kb] calls with almost the same arguments, interleaved with call_llm spans — because a tool started returning something the model reads as ‘try again.’ The classic trigger is a downstream change in a tool’s empty-result shape (say, from {results: []} to {error: "no matches"}): every call looks like a transient failure worth retrying, so the agent retries in good faith, per turn, until it hits a step limit or burns the budget.

You spot it by count and by width: a normally two-span turn is suddenly twenty spans wide, and the token total (sum the call_llm spans) is a multiple of normal. A related pattern is the transfer ping-pong in multi-agent systems — agent A transfers to B, B transfers back to A, forever — visible as alternating agent_run spans with no forward progress. The fix is rarely at the model: normalize the tool result so the retry signal disappears, add a per-turn tool-call budget, and mint an eval case from the traced session so the loop cannot come back unnoticed.