Nested Agent Failures Hide in Flat Logs. Build a Span Tree.

A checkout agent passed every unit test. Production still dropped the refund.

Ops pasted a 400-line tool log. Every call returned HTTP 200.

Two write_order events sat back to back. Neither row named a parent span.

A retry had spawned a nested planner. That planner spawned a second writer.

Flat logs showed success twice. The database showed one orphan order.

Treat that incident as a tracing problem. Do not treat it as a prompt problem.

The failure mode

Most agent traces are arrays. Each row stores name, args, and latency.

That shape works for one loop. Nested agents break this flat shape in production.

Those rows drop three causal facts at once:

• which planner spawned the tool call
• which retry still owns the write
• which spans never closed at all

Wall-clock order is not causal order. Two tools can overlap in time.

A child can finish after its parent. A retry can outlive the user request.

What a span tree records

Use one record per attempt. Do not use one row per tool name.

Minimum fields for a worked example:

{
  "trace_id": "tr_9f2c",
  "span_id": "sp_44a1",
  "parent_span_id": "sp_110c",
  "name": "tool.write_order",
  "kind": "tool",
  "status": "ok",
  "start_ms": 1725621000120,
  "end_ms": 1725621000488,
  "attrs": {
    "retry": 1,
    "agent": "refund-planner"
  }
}

trace_id ties the user request together. span_id names this single attempt.

parent_span_id names the caller span. Root spans store null for parent.

Label this schema as an example. It is not a vendor standard.

Why this is not another JSONL dump

A JSONL file can still be flat. Nesting lives only in the identifiers.

You may keep JSONL on disk. You must join on parent_span_id at read time.

The debug question then changes. You no longer ask what ran last.

You ask which child of this planner failed. You ask which retry is still open.

A collector you can run tonight

The snippet below is a worked example. Run it locally before any remote host.

# span_tree.py — example collector, not production telemetry
from __future__ import annotations

import json
import time
import uuid
from contextlib import contextmanager
from dataclasses import dataclass, field, asdict
from typing import Iterator, Optional


def _id(prefix: str) -> str:
    return f"{prefix}_{uuid.uuid4().hex[:8]}"


@dataclass
class Span:
    trace_id: str
    span_id: str
    parent_span_id: Optional[str]
    name: str
    kind: str
    start_ms: int
    end_ms: Optional[int] = None
    status: str = "unset"
    attrs: dict = field(default_factory=dict)

    def close(self, status: str = "ok") -> None:
        self.end_ms = int(time.time() * 1000)
        self.status = status


class SpanForest:
    def __init__(self) -> None:
        self.spans: list[Span] = []

    @contextmanager
    def span(
        self,
        name: str,
        *,
        kind: str,
        trace_id: str,
        parent_span_id: Optional[str],
        **attrs,
    ) -> Iterator[Span]:
        rec = Span(
            trace_id=trace_id,
            span_id=_id("sp"),
            parent_span_id=parent_span_id,
            name=name,
            kind=kind,
            start_ms=int(time.time() * 1000),
            attrs=dict(attrs),
        )
        self.spans.append(rec)
        try:
            yield rec
            if rec.status == "unset":
                rec.close("ok")
        except Exception as exc:
            rec.attrs["error"] = type(exc).__name__
            rec.close("error")
            raise

    def dump(self, path: str) -> None:
        with open(path, "w", encoding="utf-8") as fh:
            for rec in self.spans:
                fh.write(json.dumps(asdict(rec)) + "\n")

Wrap each planner step. Wrap each tool. Wrap each retry.

# example_agent.py — labeled sketch of a nested loop
from span_tree import SpanForest, _id


def run_refund(forest: SpanForest, order_id: str) -> None:
    trace_id = _id("tr")
    with forest.span(
        "agent.refund", kind="agent", trace_id=trace_id, parent_span_id=None
    ) as root:
        with forest.span(
            "planner.decide",
            kind="agent",
            trace_id=trace_id,
            parent_span_id=root.span_id,
            order_id=order_id,
        ) as planner:
            for attempt in (0, 1):
                with forest.span(
                    "tool.write_order",
                    kind="tool",
                    trace_id=trace_id,
                    parent_span_id=planner.span_id,
                    retry=attempt,
                ) as tool:
                    # replace this branch with your real tool client
                    if attempt == 0:
                        tool.close("error")
                        tool.attrs["reason"] = "timeout"
                    else:
                        tool.close("ok")

Capture one run with a short command:

python -c "from span_tree import SpanForest; from example_agent import run_refund; f=SpanForest(); run_refund(f, 'ord_22'); f.dump('spans.jsonl'); print(len(f.spans))"

Rebuild the tree, then score it

A dump is not a diagnosis. Join parent ids next.

# analyze_spans.py — example checks, not a full APM product
from collections import defaultdict
import json
import sys


def load(path: str) -> list[dict]:
    rows = []
    with open(path, encoding="utf-8") as fh:
        for line in fh:
            rows.append(json.loads(line))
    return rows


def index_by_parent(rows: list[dict]) -> dict:
    tree = defaultdict(list)
    for row in rows:
        tree[row["parent_span_id"]].append(row)
    return tree


def duration_ms(row: dict):
    if row["end_ms"] is None:
        return None
    return row["end_ms"] - row["start_ms"]


def find_orphans(rows: list[dict]) -> list[str]:
    ids = {row["span_id"] for row in rows}
    bad = []
    for row in rows:
        parent = row["parent_span_id"]
        if parent and parent not in ids:
            bad.append(row["span_id"])
    return bad


def find_open(rows: list[dict]) -> list[str]:
    return [row["span_id"] for row in rows if row["end_ms"] is None]


def find_overlap(rows: list[dict], name: str) -> list[tuple[str, str]]:
    tools = [r for r in rows if r["name"] == name and r["end_ms"]]
    hits = []
    for i, a in enumerate(tools):
        for b in tools[i + 1 :]:
            if a["trace_id"] != b["trace_id"]:
                continue
            if a["start_ms"] < b["end_ms"] and b["start_ms"] < a["end_ms"]:
                hits.append((a["span_id"], b["span_id"]))
    return hits


def print_tree(tree: dict, parent, depth: int = 0) -> None:
    for row in sorted(tree[parent], key=lambda r: r["start_ms"]):
        dur = duration_ms(row)
        pad = "  " * depth
        print(f"{pad}{row['name']} {row['status']} {dur}ms span={row['span_id']}")
        print_tree(tree, row["span_id"], depth + 1)


if __name__ == "__main__":
    rows = load(sys.argv[1])
    tree = index_by_parent(rows)
    print("== waterfall ==")
    print_tree(tree, None)
    print("orphans", find_orphans(rows))
    print("open", find_open(rows))
    print("overlap write_order", find_overlap(rows, "tool.write_order"))

Run the analyzer on the dump:

python analyze_spans.py spans.jsonl

Expected shape for the refund case:

== waterfall ==
agent.refund ok 410ms span=sp_...
  planner.decide ok 390ms span=sp_...
    tool.write_order error 180ms span=sp_...
    tool.write_order ok 200ms span=sp_...
orphans []
open []
overlap write_order []

Read the three scores as alarms. Empty lists mean the tree is internally consistent.

• Non-empty overlap write_order: two writers shared one order.
• Non-empty orphans: a child outlived the collector process.
• Non-empty open: a tool never returned a close event.

Hung nested agents show up as open spans. Racy retries show up as overlaps.

A reusable debug loop

Use the same four steps on every incident. Do not start with a new prompt.

1. Capture one trace_id from the failing request.
2. Rebuild the span tree. Print the waterfall.
3. Score orphans, open spans, and exclusive overlaps.
4. Replay only the failing subtree. Leave the rest frozen.

Decision table for step four:

Finding	Likely cause	Next action
Overlap on a write tool	Nested retry without a lock	Serialize that tool per trace_id
Orphan child	Collector crashed mid-retry	Flush spans on exception paths
Open span past SLA	Tool client has no timeout	Bound the span, then fail closed
Child ok, parent error	Parent ignored child status	Propagate child error upward
Two roots, one user	Missing trace_id on fan-out	Pass the id into sub-agents

This loop is the reusable artifact. Keep the table beside the collector.

A small test plan

Do not trust the collector without tests. These cases are labeled examples.

# test_span_tree.py — example tests
from span_tree import SpanForest


def test_parent_links_nested_tool():
    forest = SpanForest()
    with forest.span(
        "agent.refund", kind="agent", trace_id="tr_1", parent_span_id=None
    ) as root:
        with forest.span(
            "tool.write_order",
            kind="tool",
            trace_id="tr_1",
            parent_span_id=root.span_id,
        ):
            pass
    child = forest.spans[1]
    assert child.parent_span_id == forest.spans[0].span_id
    assert child.end_ms is not None


def test_error_closes_span():
    forest = SpanForest()
    try:
        with forest.span(
            "tool.x", kind="tool", trace_id="tr_2", parent_span_id=None
        ):
            raise TimeoutError("boom")
    except TimeoutError:
        pass
    assert forest.spans[0].status == "error"
    assert forest.spans[0].end_ms is not None

python -m pytest test_span_tree.py -q

If the parent assertion fails, context was dropped. Fix the wrapper before any host deploy.

Where a free server fits

Local files work for one crash. They fail under concurrent nested agents.

You need a process that accepts spans. You need disk that survives SSH drops.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.

MonkeyCode is an open-source project. It currently offers free model access and a free server option.

Use that pair only as a place to run the collector. The span schema does not depend on it.

Remove the product and the analyzer still works. Reader value should survive that removal.

A small host is enough here. The collector writes JSONL. The analyzer reads JSONL.

Do not ship raw tool arguments to any host. Redact tokens, secrets, and PII first.

Redact before you trace

Observability can leak more than the agent. Treat spans as public logs.

Minimum redaction rules:

• drop Authorization headers
• hash account ids
• truncate tool payloads over 2 KB
• never store raw card or session tokens

SENSITIVE = ("token", "password", "authorization", "cookie", "secret")


def redact(attrs: dict) -> dict:
    clean = {}
    for key, value in attrs.items():
        low = key.lower()
        if any(s in low for s in SENSITIVE):
            clean[key] = "[redacted]"
        elif isinstance(value, str) and len(value) > 2048:
            clean[key] = value[:2048] + "…"
        else:
            clean[key] = value
    return clean

Call redact before dump. Do this on a free server too.

Clock skew is a second leak of truth. Do not compare start_ms across two machines.

Keep one collector process per host. Join traces later by trace_id, not by time.

Limitations

This is not distributed tracing. There is no sampler or baggage header.

The overlap check is O(n²) per tool name. It is fine under a few hundred spans.

It is not fine for a 50k-span overnight soak. Shard files by trace_id first.

The example does not persist across processes. You must append JSONL yourself.

A perfect tree can still write the wrong order. The tree proves structure, not business correctness.

Who should not use this

Skip this if your agent is one tool call. A request log is enough.

Skip this if OpenTelemetry already carries parent context. Do not duplicate span ids.

Skip this if legal blocks any tool-arg storage. The redactor is not a compliance program.

Skip this if you need live dashboards. The artifact is a file and a script.

What to measure next

Count three numbers per day. Add nothing else during week one.

• orphan rate per 100 traces
• open-span rate past 30 seconds
• exclusive-tool overlap count

If orphan rate rises, nested planners are dropping context. If overlap count rises, retries are racing writes.

Fix those two before you tune prompts. The tree shows which subtree to replay.

If a host is already running, point the dump path there. If not, the free server option is one way to keep this collector alive without standing up GPUs.