DEV Community

Amit
Amit

Posted on Originally published at artificialcuriositylabs.ai

What the Trace Knew That the Logs Didn't

The short version

Most observability posts break something on purpose and show the dashboard light up. I started differently: observability was the lens that caught failures in other experiments for months before I ran dedicated observability tests. That turned out to be the honest way to learn what observability actually buys — the failures weren't designed to be visible, so what showed up mattered.

Four accidental lessons came first (observability catching failures from unrelated experiments), then four deliberate ones (dedicated observability tests that each turned up something the previous tests had missed or misunderstood):

  1. An agent that logged a complete answer while dead.
  2. A tool invisible to evaluation systems because it didn't emit spans.
  3. A two-agent loop only visible from the shared trace, never from either agent's logs.
  4. A delegation where 95% of the trace was protocol noise.
  5. A latency gap that looked like broken tracing but wasn't.
  6. A loop-detection signal that's visible in traces but isn't proof on count alone.
  7. A cross-agent correlator that works on two telemetry backends but hands you the wrong trace first.
  8. An agent running as a plain local process showing up in the same observability pipeline as a Runtime-hosted one.

Each maps to a rule for debugging a misbehaving agent.


How AgentCore observability is wired

When you enable observability on AgentCore Runtime, every invocation emits OpenTelemetry (OTel) spans to CloudWatch — the same span/trace model any instrumented service uses. Agent frameworks emit these automatically: a span per model call, a span per tool execution, nested under a trace, all tagged with a session.id. The spans land in account-wide logs and a per-runtime log group. On top of the spans sit CloudWatch metricsInvocations, Errors, SystemErrors, Latency — all queryable in the CloudWatch GenAI Observability console.

Two prerequisites: you must enable CloudWatch Transaction Search once per account (the docs don't mention it, but span queries silently return nothing without it), and there's a 2–10 minute ingestion lag between an invocation and its spans being queryable. Both cost me time because neither is documented loudly.

Lesson 1: logs lie, metrics don't

The first real lesson came from a deployment that looked successful and wasn't.

An early version of the deployment had a __main__ block that ran a one-shot test — print(json.dumps(triage(...))) — instead of starting the HTTP server. The agent called the model, escalated, produced a correct answer, and printed it to stdout. The logs showed a complete, correct response. But the process exited without ever starting the HTTP server. /ping had nothing listening, so the platform reported initialization failure. The agent was simultaneously working (logic ran, logged a perfect answer) and broken (nothing served, health check dead).

If I'd debugged from the logs, I'd have wasted hours. The metrics told the truth instantly: Invocations and a failure signature that didn't match the happy log line. Logs capture what the code printed; the platform contract is HTTP. A correct-looking log line is not proof the agent is serving.

Rule 1: Logs capture what the code printed. Metrics capture what the platform observed. When they disagree, the metrics are right. Check Invocations/Errors/SystemErrors and the client's actual HTTP response before you trust a log line.

Lesson 2: if there's no span, it didn't happen (as far as tooling is concerned)

The second lesson came from evaluation work, and nothing "failed" in the obvious sense.

I was scoring an agent with a trajectory evaluator, which grades whether the agent called the expected tools in order. The scenarios kept returning the correct outcome (a refund was approved or blocked as policy required) but showed an empty tool trajectory[] — as if no tool had been called at all. The refund tool clearly had run; its effect was in the response.

The root cause: the tool was a plain Python function, not a framework-native one. Plain function calls don't emit OTel spans. The trajectory evaluator reads spans; if there are none, the trajectory is empty. The tool was working and completely invisible to the observability layer simultaneously.

Once I promoted it to a framework-native tool, the same scenarios showed a full trajectory. The deeper lesson: an empty trajectory is not proof the tool didn't run. It's proof the tool isn't instrumented. Understanding that made "empty trajectory" a useful signal in its own right — it tells you exactly which parts of your agent are invisible to everything downstream (evaluators, dashboards, audits), which is far more dangerous than a tool that visibly fails.

Rule 2: In an agent, "observable" is a property you opt into. Framework-native tools emit spans; raw function calls don't. Anything not emitting a span is a blind spot — not just for debugging, but for evaluation and audit. Instrument the actions that matter before you need to see them.

Lesson 3: some failures are only visible from above

This one would cost real money in production, and it's the clearest argument for tracing over logging.

Two agents — a frontline and a specialist — can each make locally-correct routing decisions and still form a global loop: frontline escalates to specialist, specialist decides it's out of scope and routes back, forever. There's a documented incident where exactly this ran for four weeks and roughly $47K before anyone noticed. No single agent's logs contain the loop. The frontline's logs show "I escalated." The specialist's logs show "I routed back." Neither shows the cycle.

The only place the loop is visible is a view that spans both agents. With a shared correlation id propagated across every hop — the same session.id on both agents' spans — you can see the entire path in one trace. Without cross-agent tracing, you're debugging a distributed failure from two half-views that each look fine.

Rule 3: Single-agent logs can't see multi-agent failures. Propagate one correlation id (session.id) across every hop so a single trace shows the whole path — that's the substrate that makes loops, dropped context, and delegation failures detectable at all.

Lesson 4: observability has a volume problem too

The fourth lesson is the counterweight, because more spans is not strictly better.

When I put a frontline→specialist delegation under evaluation, the shared session came back with 207 spans — and 197 of them were protocol plumbing (queue operations, fired dozens of times). The eight spans that actually mattered — the model calls and the tool execution — were buried in protocol noise, and the evaluator choked trying to reconstruct a coherent trace from the flood.

The fix was a span filter that dropped the protocol scope before analysis. The general point: an agent's trace is not automatically useful. Frameworks and protocols emit spans at wildly different granularities, and a naive "capture everything" posture produces traces where signal is a rounding error. You end up filtering by instrumentation scope to get back to the spans a human or an evaluator can reason about.

Rule 4: Capture-everything is not a strategy. Know which instrumentation scopes carry the signal for your question and filter to them. The goal is a trace you can read, not the most spans.

Lesson 5: a latency gap isn't proof the trace is lying

This came from a dedicated test, and it's a mistake I made and caught in the same session — worth keeping because it corrected its own first conclusion.

I invoked a deployed agent twice, once with a prompt that triggers a tool call and once with pure reasoning, and compared wall-clock against the trace's duration. Both showed the same pattern: the client measured roughly 6.5–7 seconds more than the trace accounted for. My first conclusion: a real gap in trace attribution, latency the trace simply couldn't see.

It wasn't. Both calls minted a fresh runtimeSessionId. AWS documents plainly that every unique session provisions a new, dedicated microVM. Startup splits into a platform-managed phase (microVM provisioning, before your instrumentation exists) and an application phase (your code). I confirmed directly: two calls on the same session collapsed the gap to about 0.2 seconds (replicated 3x). Cold-call wall-clock stayed at 9–12 seconds, but the attribution changed — the platform overhead was invisible to the trace by structural design, not by accident.

Rule 5: A latency gap between client wall-clock and trace duration is not automatically a tracing defect. Check whether you're minting a new runtimeSessionId per call first. A fresh session is a fresh microVM, and cold-start provisioning happens before your instrumentation exists, so it will never show as a span. Reuse session ids across real calls in a conversation.

Lesson 6: a repeated span isn't provably a loop

Tracing can show you a pattern, but a pattern isn't proof of a cause.

I forced an agent to make three tool calls in one turn (a three-part research prompt) and checked whether the trace showed a distinct signal. It did: three identically named spans, cross-confirmed by the runtime's logs. But a real stuck loop — the same call repeated because the agent isn't making progress — would produce the exact same span count. Neither the trace nor the application log carries the actual tool-call arguments, so span count alone can't tell the two apart.

AWS's own debugging guide resolves this cleanly: the primary infinite-loop signal is a volume anomaly — high token usage combined with a low or zero error rate, plus a span count and session duration far outside the normal range — not argument-level inspection as a first move. I confirmed this by temporarily enabling Bedrock model invocation logging (disposable, account-wide, so I disabled it immediately after) and re-ran the same test. The recovered model completion showed the real, distinct query strings behind each tool call — proof, not inference, that this was legitimate parallel tool use and not a loop.

Rule 6: Repeated identically-named spans are a real, countable loop symptom — but not proof by themselves, because legitimate parallel tool use produces the same shape. Reach for the volume signal first (token usage, span count, session duration vs. normal range). Only drop into argument-level inspection via Bedrock model invocation logging once a session already looks suspicious, and treat that logging as temporary — it has no per-agent scope.

Lesson 7: the correlator is real, but the first trace it hands you is a decoy

This came from a dedicated test run a month after Lesson 3, specifically to check whether that finding still held and on what infrastructure.

Lesson 3 established that a shared session.id correlates a two-agent A2A handoff on CloudWatch logs. The open question: does that correlation also work through AWS X-Ray? I invoked the same kind of delegation and checked X-Ray directly: it returned the session's spans just as reliably as CloudWatch had.

But checking twice surfaced a real gotcha. My first pass came back with zero matching rows — for a few minutes, that looked like the correlation had broken or the platform had moved this telemetry. It hadn't. A wider query window (my first check waited 45 seconds and searched a narrow slice of time; a retry with several more minutes of margin) found the rows, right in line with what I'd measured before. The lesson: "zero results" from an observability query is frequently just a too-tight window, not proof a backend has no data.

The second, more durable finding: the correlated session always contains at least two distinct traces, not one. The first is the A2A discovery handshake — the receiving agent fetching the caller's metadata — and it's essentially empty: near-instant, no model calls. The actual work is the second trace. Any tooling that assumes "the first trace in a session is the interesting one" will silently grab the handshake and miss the substance every time.

Rule 7: Don't trust a single empty query result as proof a telemetry backend has no data — widen the window before you conclude that. When correlating a multi-agent session, don't assume the first trace is the one that matters; the A2A discovery handshake produces a real, separate, empty trace ahead of the actual work.

Lesson 8: the pipeline doesn't care who deployed the agent

Does AgentCore Observability only work for agents AgentCore itself deployed, or does it reach agents running anywhere?

AWS's August 2026 blog answers plainly: agents on-premises, on other clouds, anywhere with internet access and IAM credentials, all land in the same dashboard as Runtime-hosted agents. I tested the plainest version of that claim: a local Python script on this machine, zero AgentCore Runtime involvement, calling Bedrock directly via boto3. Wrapped in opentelemetry-instrument with the documented AWS Distro for OpenTelemetry environment variables, it appeared in both telemetry backends tagged aws.service.type: gen_ai_agent, with the same gen_ai.* semantic-convention spans, the same token-usage metrics, and the same structured logs a Runtime-hosted agent produces — indistinguishable in the telemetry.

It wasn't frictionless. The first run threw a 400: The specified log stream does not exist on its first export batches — the log stream doesn't pre-exist, and ADOT creates it lazily on first write. That's a one-time, self-resolving cost, structurally the same as Lesson 5's cold start: an artifact of first contact with infrastructure that provisions itself lazily, not a persistent defect. A second run, after the stream existed, produced no errors.

Rule 8: AgentCore Observability's reach isn't bounded by AgentCore Runtime. The same ADOT SDK plus IAM credentials plus documented OTEL environment variables that instrument a Runtime-hosted agent will land a plain local process in the identical pipeline, tagged the same way. Expect a one-time, self-resolving provisioning hiccup on first contact with a new log group — the non-Runtime cousin of a cold start.


The operational workflow this leaves you with

Put the eight lessons together and you get a concrete way to debug a misbehaving AgentCore agent:

  1. Start at metrics, not logs. Errors/SystemErrors/Latency on the runtime tell you whether the platform saw a failure. A clean-looking log line proves nothing (Lesson 1).
  2. Pull the trace for the failed invocation by session.id. Wait out the ingestion lag — spans aren't instant.
  3. Filter to the scopes that carry signal before you read it, or the protocol noise will bury the failure (Lesson 4).
  4. Find the first span with an error status — that's your root-cause step. If the step you expect isn't in the trace at all, it isn't instrumented, which is its own bug (Lesson 2).
  5. For multi-agent paths, confirm the correlation id propagated across every hop, or you're only seeing half the failure (Lesson 3) — and skip the first trace in the session, which is usually just A2A's discovery handshake (Lesson 7).
  6. Before treating a latency gap as a tracing bug, rule out cold start. A fresh runtimeSessionId is a fresh microVM (Lesson 5).
  7. Don't call a repeated span "a loop" on count alone. Reach for the token-usage/span-count volume signal first; only turn on model invocation logging, temporarily, if you need to prove it with actual tool arguments (Lesson 6).
  8. Widen the query window before trusting a zero-result answer. An empty result from a telemetry query is frequently just a too-tight window (Lesson 7).
  9. Set a CloudWatch alarm on Errors/SystemErrors so the next one pages you instead of hiding in a log that looks fine.
  10. Don't assume Runtime deployment is a prerequisite for visibility. If part of your system runs outside AgentCore Runtime entirely (on-prem, another cloud, a plain process), the same ADOT-based setup gets it into the same dashboard — expect one lazy-provisioning hiccup on first contact (Lesson 8).

What's still open

Four of these eight lessons came from experiments that broke in ways I didn't plan for, and a trace (or missing one) that explained why. The other four came from finally testing observability directly — and two of those corrected their own first conclusion within the same session.

One thing I didn't test: the sequential "stuck, retrying across turns" pattern specifically. Lessons 2 and 6 tested parallel tool-calling and multi-step tool use, but not the case where an agent makes the same tool call, fails, and retries it turn after turn until the token budget runs out. That pattern is a real, non-redundant gap — AWS's own canonical loop-detection example uses a sequential loop, not a parallel one. The volume signals that work for detecting high token usage with low error rates apply to it, but whether the trace shape itself gives you a distinct signal for sequential retries (beyond volume) is something I haven't confirmed yet. That's the open thread I'm leaving with: the same observability pipeline that caught and distinguished the other seven patterns hasn't been tested against the one loop shape it's hardest to debug.

Top comments (0)