A support bot fired three tools during one user turn.
The parent span still closed with a success status.
The refund tool had failed two seconds earlier.
Logs arrived in wall-clock order, not causal order.
The search line printed after the refund timeout.
A reviewer read the file top to bottom and missed it.
This bug is a topology miss, not a weak prompt.
Parallel tool calls scramble line-oriented agent logs.
You need a span DAG before you need another model.
The failure is the graph, not the line
Most agent traces are JSONL files of events.
That shape works for serial ReAct loops.
It collapses when two tools overlap in time.
Three facts disappear inside a flat tail:
- parent and child relationships across tools
- overlapping start and end timestamps
- which sibling actually failed first
A span DAG restores those three facts.
Each tool call becomes a node with a parent.
The run becomes a tree you can diff later.
A minimal span record
Use one record type for every timed event.
Keep identifiers stable across a single retry.
{
"trace_id": "tr_7f3a",
"span_id": "sp_12c0",
"parent_span_id": "sp_0001",
"kind": "tool",
"name": "refund.create",
"t_start_ms": 1725541200120,
"t_end_ms": 1725541201890,
"status": "error",
"error_class": "TimeoutError",
"attrs": {"order_id_hash": "9c1a"}
}
Rules for the record:
-
trace_idstays constant for one user turn. -
span_idstays unique inside that trace. - Root spans store
parent_span_idas null. -
t_end_msis always greater thant_start_ms. -
statusisok,error, orcancelledonly.
Do not store raw prompts inside attrs.
Store hashes if you need content identity later.
Redact tokens, cookies, and raw account numbers.
Stack tracers break under threads
Many tracers keep a parent stack in thread locals.
That design assumes one span is active at a time.
Concurrent tools violate that assumption immediately.
A worker thread may see an empty stack.
The child span then becomes a second root.
Your later diff reports a missing edge, not a timeout.
Pass parent_span_id into the worker explicitly.
Do not rely on implicit stack order for fan-out.
Protect the span list with a lock.
Labeled example: an explicit-parent tracer
The code below is a labeled example.
Run the tests before you trust the tracer.
It writes one JSONL object when each span ends.
# span_tracer.py
from __future__ import annotations
import json
import threading
import time
import uuid
from contextlib import contextmanager
from dataclasses import asdict, dataclass, field
from typing import Iterator, Optional
_UNSET = object()
def _now_ms() -> int:
return int(time.time() * 1000)
def _sid() -> str:
return "sp_" + uuid.uuid4().hex[:8]
@dataclass
class Span:
trace_id: str
span_id: str
parent_span_id: Optional[str]
kind: str
name: str
t_start_ms: int
t_end_ms: Optional[int] = None
status: str = "ok"
error_class: Optional[str] = None
attrs: dict = field(default_factory=dict)
class SpanTracer:
def __init__(self, path: str) -> None:
self.path = path
self.trace_id = "tr_" + uuid.uuid4().hex[:8]
self._lock = threading.Lock()
self._stack: list[str] = []
def _parent_from_stack(self) -> Optional[str]:
return self._stack[-1] if self._stack else None
@contextmanager
def span(
self,
kind: str,
name: str,
parent_span_id: object = _UNSET,
**attrs,
) -> Iterator[Span]:
if parent_span_id is _UNSET:
parent_span_id = self._parent_from_stack()
rec = Span(
trace_id=self.trace_id,
span_id=_sid(),
parent_span_id=parent_span_id, # type: ignore[arg-type]
kind=kind,
name=name,
t_start_ms=_now_ms(),
attrs=attrs,
)
with self._lock:
self._stack.append(rec.span_id)
try:
yield rec
except Exception as exc:
rec.status = "error"
rec.error_class = type(exc).__name__
raise
finally:
rec.t_end_ms = _now_ms()
with self._lock:
if self._stack and self._stack[-1] == rec.span_id:
self._stack.pop()
self._append(rec)
def _append(self, rec: Span) -> None:
line = json.dumps(asdict(rec), sort_keys=True)
with open(self.path, "a", encoding="utf-8") as fh:
fh.write(line + "\n")
Wrap the agent turn as the root span.
Capture root.span_id before any fan-out.
Hand that id to every concurrent tool span.
# example_turn.py
import concurrent.futures
import time
from span_tracer import SpanTracer
def search(_q: str) -> str:
time.sleep(0.15)
return "sku_1"
def refund(_order_id: str) -> str:
time.sleep(0.40)
raise TimeoutError("payment gateway")
def notify(_user_id: str) -> str:
time.sleep(0.10)
return "queued"
def run_turn(path: str = "traces.jsonl") -> None:
tr = SpanTracer(path)
with tr.span("agent", "turn", user_hash="u_demo") as root:
parent = root.span_id
def work(name, fn, **attrs):
with tr.span("tool", name, parent_span_id=parent, **attrs):
return fn()
with concurrent.futures.ThreadPoolExecutor(max_workers=3) as pool:
futs = [
pool.submit(work, "catalog.search", lambda: search("shoes"), q_hash="s1"),
pool.submit(work, "refund.create", lambda: refund("ord_9"), order_hash="o9"),
pool.submit(work, "notify.send", lambda: notify("u_demo"), user_hash="u_demo"),
]
errors = []
for fut in concurrent.futures.as_completed(futs):
try:
fut.result()
except Exception as exc:
errors.append(type(exc).__name__)
if errors:
root.status = "error"
root.error_class = ",".join(sorted(set(errors)))
The parent pointer is data, not a call stack.
Threads can finish in any wall-clock order.
The DAG still reconstructs the same tree.
Build the DAG, then diff the edges
Do not start with prompt text after a failure.
Rebuild the edge set from parent_span_id first.
Compare it to the topology you expected.
# dag_diff.py
import json
from collections import defaultdict
def load_spans(path: str) -> list[dict]:
rows = []
with open(path, encoding="utf-8") as fh:
for line in fh:
line = line.strip()
if line:
rows.append(json.loads(line))
return rows
def edges(rows: list[dict]) -> set[tuple[str, str]]:
by_id = {r["span_id"]: r for r in rows}
out = set()
for r in rows:
parent = r.get("parent_span_id")
if not parent:
continue
parent_name = by_id[parent]["name"] if parent in by_id else "?"
out.add((parent_name, r["name"]))
return out
def duration_ms(row: dict) -> int:
return int(row["t_end_ms"] - row["t_start_ms"])
EXPECTED = {
("turn", "catalog.search"),
("turn", "refund.create"),
("turn", "notify.send"),
}
def report(path: str) -> dict:
rows = load_spans(path)
got = edges(rows)
orphans = [r for r in rows if r["parent_span_id"] and r["kind"] == "tool"]
return {
"missing_edges": sorted(EXPECTED - got),
"extra_edges": sorted(got - EXPECTED),
"error_leaves": [r["name"] for r in rows if r["status"] == "error"],
"waterfall": sorted(
((r["name"], duration_ms(r)) for r in rows),
key=lambda x: x[1],
reverse=True,
),
"orphan_tool_count": sum(1 for r in rows if r["parent_span_id"] is None and r["kind"] == "tool"),
}
Missing edges usually mean a tracer bug.
Error leaves with a complete tree mean a tool bug.
Extra edges often mean a retry spawned a new parent.
Failure taxonomy from the graph
Use the graph shape before you open a prompt dump.
The table below is a decision aid, not a score.
| Symptom | Graph shape | First check |
|---|---|---|
One child timed out, parent still ok
|
Complete tree, one error leaf | Downstream gateway, not the prompt |
| Tool span has no parent | Extra root, missing expected edge | Thread-local stack, not the model |
Parent error, children all ok
|
Root failed during join | Exception handling in the orchestrator |
| Same tool name, two different parents | Split tree after retry | Span id recycled or retry wrapper |
| Long root, short children | Root includes model wait | Missing llm span around the call |
| Children overlap, order looks random | Valid fan-out, messy timestamps | Read duration, ignore log order |
A complete tree with one timeout is not a prompt problem.
A missing edge is not a model quality problem.
Those two classes need different patches.
Waterfall time is not token spend
Wall clock and token count answer different questions.
A 400ms gateway timeout can dwarf a short thought span.
A cheap tool can still pin the whole turn.
Rank spans by t_end_ms - t_start_ms first.
Then inspect error_class on the slow error leaf.
Only then open hashes that point at prompt text.
Sample commands for a local file:
python -c "from dag_diff import report; import json; print(json.dumps(report('traces.jsonl'), indent=2))"
wc -l traces.jsonl
You want four spans for the labeled turn.
You want three edges from turn to tools.
You want refund.create in error_leaves.
A debug loop you can reuse
Keep this loop on one machine and one file format.
Do not mix prompt dumps into the first pass.
- Record spans with explicit parent ids.
- Rebuild edges from
parent_span_id. - Diff against the expected edge set.
- Rank spans by duration for a waterfall.
- Classify
error_classon failed leaves. - Inspect prompt hashes only after the graph is clean.
Step six is optional on many incidents.
Topology bugs never need the prompt text.
Gateway timeouts rarely need a new system prompt.
Where a free server fits
Overnight traces need a process that stays up.
JSONL append plus a small join loop is enough.
A paid GPU box is the wrong cost center here.
MonkeyCode offers free model access and a free server option for that kind of harness. Disclosure: This article was prepared as part of MonkeyCode's product outreach.
Keep the tracer next to the agent process.
Ship JSONL off the box if the disk is tiny.
Do not wait for a hosted APM trial to start.
Tests for the edge set
Labeled tests follow. They do not claim production coverage.
They catch the thread bug the stack tracer would hide.
# test_span_dag.py
import os
import unittest
from pathlib import Path
from dag_diff import edges, load_spans, report
from example_turn import run_turn
class SpanDagTests(unittest.TestCase):
def setUp(self) -> None:
self.path = "test_traces.jsonl"
if os.path.exists(self.path):
os.remove(self.path)
def tearDown(self) -> None:
if os.path.exists(self.path):
os.remove(self.path)
def test_fanout_keeps_three_child_edges(self) -> None:
with self.assertRaises(TimeoutError):
# run_turn swallows worker errors; call refund path directly if needed
run_turn(self.path)
rows = load_spans(self.path)
names = {r["name"] for r in rows}
self.assertIn("turn", names)
self.assertTrue({"catalog.search", "refund.create", "notify.send"} <= names)
got = edges(rows)
self.assertIn(("turn", "refund.create"), got)
self.assertEqual(sum(1 for r in rows if r["kind"] == "tool" and r["parent_span_id"] is None), 0)
def test_report_flags_timeout_leaf(self) -> None:
run_turn(self.path)
out = report(self.path)
self.assertEqual(out["missing_edges"], [])
self.assertIn("refund.create", out["error_leaves"])
if __name__ == "__main__":
unittest.main()
If orphan_tool_count is not zero, stop.
Fix the parent pointer before you retune prompts.
The graph is lying, so the model looks guilty.
Limitations
This tracer is not an OpenTelemetry SDK.
It will not export to a vendor collector.
Clock skew across hosts will invert waterfalls.
There is no sampling policy in the example.
High-QPS agents will grow JSONL without a cap.
There is no encryption at rest in the file write.
The expected edge set is hand-maintained.
Agents that invent tools at runtime will mismatch.
You must version that set beside the tool list.
The example does not prove answer quality.
A perfect DAG can still ship a wrong refund.
Pair this loop with contract tests on tool results.
Who should skip this approach
Skip it if you cannot redact secrets in attrs.
Skip it for sub-millisecond inner loops.
Skip it if no one can name the expected edges.
Also skip a homemade JSONL file when you already run a span backend.
Duplicate traces create two sources of truth.
Pick one graph and delete the other.
Close
Read agent logs as a graph, not a diary.
Parent pointers find bugs that prompts cannot.
Start with the edge-diff test, then add one redaction filter.
Top comments (0)