Wall-clock order is not causal order. If you sort an agent run by timestamp on a shared or free endpoint, a tool span can appear to start before the prompt that issued it, and a retry can look like the original call. Debugging then becomes a study of the logger, not the agent. The reusable fix is a happens-before contract: every tool names its parent prompt, every retry names the failed attempt, and a test fails the run when those edges are missing or cyclic.
This is a data-model problem, not a dashboard theme. It shows up the moment two requests share a queue.
Why clocks invert on contended runtimes
A laptop makes timestamps feel trustworthy. The model returns, the tool runs, the next prompt starts, and the file order matches the work. Shared inference is different. A crowded collector can delay flush, batch spans, or stamp arrival time instead of produce time. The numbers still look precise. They are precise about arrival, not about cause.
Think of a station board that sorts train cars by when a clerk stamped the paper, not by which coupler joined them. You get a clean sequence. You cannot rebuild the train.
Agent loops make the inversion worse. A retry often gets a new span id and a fresh timestamp that lands between two children of the original prompt. Sorted views then show a tool from attempt one answering a prompt from attempt two. The summary looks decisive. The graph is wrong.
Recent developer talk about agents keeps circling a related failure: systems that assume. Timestamp sort is one of those assumptions. It survives review because every field is populated. It fails only when you ask whether A could have caused B.
A span record that carries cause
Do not start with a vendor schema. Start with four facts you can test. A span needs an id, an optional parent, a kind, and an explicit caused_by list. Timestamps stay as diagnostics. They do not decide order.
The record below is a proposal you can paste into a test file. It is not a production telemetry standard.
# causal_spans.py
from __future__ import annotations
from dataclasses import dataclass
from typing import Optional
ALLOWED_KINDS = frozenset({"prompt", "tool", "retry", "summary"})
@dataclass(frozen=True)
class Span:
span_id: str
parent_id: Optional[str]
kind: str
name: str
t_start_ms: int
t_end_ms: int
mutates: tuple[str, ...] = ()
caused_by: tuple[str, ...] = ()
def __post_init__(self) -> None:
if self.kind not in ALLOWED_KINDS:
raise ValueError(f"unknown kind: {self.kind}")
if not self.span_id:
raise ValueError("span_id is empty")
if self.t_end_ms < self.t_start_ms:
raise ValueError(f"{self.span_id} ends before it starts")
The mutates field is the other half of the story. Two tool spans may share a prompt parent and still conflict if they write the same path. Causal order is not only what triggered what. It is also what may not overlap.
Rules a debug loop can fail closed on
A validator should reject a run for missing edges before anyone reads a waterfall. Four checks cover the failure without pretending to be a full tracing product.
Parent integrity comes first. A non-root span must point at an id that exists in the same run. Orphans are not interesting unknowns. They are broken export.
Kind edges come next. A tool span must be caused_by a prompt or a retry. A retry must be caused_by the prompt or tool it replaces. A summary must name every prompt that contributed to it. If the summary cannot name those prompts, it is a caption, not a trace.
Acyclicity is the third cut. caused_by must form a DAG. Clock skew cannot be allowed to hide a cycle by making the later node look earlier.
Mutation exclusion is the last cut. If two tool spans share an ancestor prompt and their mutates sets intersect, they must be ordered by an explicit edge. Parallel read-only tools may overlap. Parallel writers to the same file may not.
Notice what is absent. There is no success boolean on the span. Completeness of edges is a different question from success of the task. Mixing them produces green runs with impossible histories.
A failing test you can keep
The example below is an unexecuted template. Point it at traces you already store. It does not need a vendor SDK.
# test_causal_spans.py
from collections import defaultdict, deque
from typing import Dict, List
from causal_spans import Span
class CausalTraceError(AssertionError):
pass
def index_spans(spans: List[Span]) -> Dict[str, Span]:
ids = [s.span_id for s in spans]
if len(ids) != len(set(ids)):
raise CausalTraceError("duplicate span_id")
return {s.span_id: s for s in spans}
def assert_parents_exist(by_id: Dict[str, Span]) -> None:
for span in by_id.values():
if span.parent_id and span.parent_id not in by_id:
raise CausalTraceError(f"{span.span_id} parent missing")
for cause in span.caused_by:
if cause not in by_id:
raise CausalTraceError(f"{span.span_id} cause {cause} missing")
def assert_kind_edges(by_id: Dict[str, Span]) -> None:
for span in by_id.values():
causes = [by_id[c] for c in span.caused_by]
if span.kind == "tool" and not any(
c.kind in {"prompt", "retry"} for c in causes
):
raise CausalTraceError(f"tool {span.span_id} lacks prompt cause")
if span.kind == "retry" and not any(
c.kind in {"prompt", "tool"} for c in causes
):
raise CausalTraceError(f"retry {span.span_id} lacks origin")
def assert_acyclic(by_id: Dict[str, Span]) -> None:
indeg = {sid: 0 for sid in by_id}
children: dict[str, list[str]] = defaultdict(list)
for span in by_id.values():
edges = list(span.caused_by)
if span.parent_id:
edges.append(span.parent_id)
for src in edges:
children[src].append(span.span_id)
indeg[span.span_id] += 1
q = deque([sid for sid, d in indeg.items() if d == 0])
seen = 0
while q:
node = q.popleft()
seen += 1
for nxt in children[node]:
indeg[nxt] -= 1
if indeg[nxt] == 0:
q.append(nxt)
if seen != len(by_id):
raise CausalTraceError("caused_by graph has a cycle")
def assert_writer_order(by_id: Dict[str, Span]) -> None:
writers: dict[str, list[Span]] = defaultdict(list)
for span in by_id.values():
if span.kind != "tool":
continue
for path in span.mutates:
writers[path].append(span)
for path, group in writers.items():
if len(group) < 2:
continue
ids = {s.span_id for s in group}
for span in group:
others = ids - {span.span_id}
linked = set(span.caused_by) | ({span.parent_id} if span.parent_id else set())
if others and not (others & linked):
raise CausalTraceError(f"unordered writers on {path}")
def validate_run(spans: List[Span]) -> None:
by_id = index_spans(spans)
assert_parents_exist(by_id)
assert_kind_edges(by_id)
assert_acyclic(by_id)
assert_writer_order(by_id)
def test_clock_skew_does_not_reorder_cause():
prompt = Span("p1", None, "prompt", "plan", 1000, 1400)
tool = Span(
"t1",
"p1",
"tool",
"edit",
900, # collector stamped this earlier than the prompt
1100,
mutates=("src/app.py",),
caused_by=("p1",),
)
validate_run([prompt, tool]) # must pass: cause is explicit
def test_retry_without_origin_fails():
prompt = Span("p1", None, "prompt", "plan", 1000, 1200)
retry = Span("r1", "p1", "retry", "plan", 1300, 1500, caused_by=())
try:
validate_run([prompt, retry])
raise AssertionError("expected CausalTraceError")
except CausalTraceError:
pass
Run the file with a boring command.
python -m pytest test_causal_spans.py -q
If your exporter already writes JSON, inspect cardinality before you argue about latency.
python - <<'PY'
import json, pathlib
raw = json.loads(pathlib.Path("run.json").read_text())
spans = raw["spans"]
print(len(spans), "spans")
print("kinds", sorted({s["kind"] for s in spans}))
print("missing caused_by", sum(1 for s in spans if s["kind"] != "prompt" and not s.get("caused_by")))
PY
The first test is the point. The tool's t_start_ms is earlier than the prompt. A waterfall sorted by clock would draw the tool on the left. The validator still accepts the run because caused_by names p1. The second test rejects a retry that only has a parent pointer. Parent is structure. Cause is history. You need both.
How this changes the debug loop
A reusable loop does not start in the model output. It starts by assembling the span list for one run id, running validate_run, and only then reading names. If validation fails, the human job is to repair export, not to interpret the agent. That split sounds petty until a night of "the tool hallucinated a path" turns out to be two writers with overlapping clocks.
After the graph is legal, diffs belong on the mutated paths, not on the concatenated log. Compare the mutates tuple to git diff -- path or to a working-tree snapshot keyed by span_id. A tool span that mutates nothing should not appear in a code-change review. A tool span that mutates a path with no causal edge should not appear either.
Retries are the usual source of duplicated narrative. Keep the failed tool span. Add a retry span that lists the failed tool in caused_by. Do not delete the first attempt to make the waterfall pretty. Deletion is how teams lose the only evidence that the second attempt was not the first.
A small shell check keeps the habit cheap.
git diff --name-only HEAD | sort > /tmp/changed.txt
python - <<'PY'
import json, pathlib
mut = set()
for s in json.loads(pathlib.Path("run.json").read_text())["spans"]:
if s.get("kind") == "tool":
mut.update(s.get("mutates") or [])
changed = set(pathlib.Path("/tmp/changed.txt").read_text().split())
print("traced but not in git", sorted(mut - changed))
print("in git but not traced", sorted(changed - mut))
PY
None of this requires a particular vendor. It requires that whatever emits spans can add three fields: kind, caused_by, mutates. If an exporter cannot, treat its timestamps as comments.
Where a free model path fits, and where it does not
Shared free inference is a good generator of the bug this article is about. Queue delay and batched logs show up there first. They also show up on busy paid clusters, which is why the tests are not a free-tier workaround. They are a contract.
Disclosure: This article was prepared as part of MonkeyCode's product outreach. MonkeyCode's free model access and free server option can emit agent runs that you then validate locally with the snippet above. Keep the validator next to your tests, not next to the model. If the server is gone tomorrow, the happens-before rules remain.
Do not send prompt bodies to a shared collector if the run includes secrets. This article is about order, not about data boundaries. Keep stored fields small: ids, kinds, paths, edges. Leave payload off the trace you keep for CI.
Limitations, and who should skip this
The DAG check does not prove the agent was right. It proves the story of the run is internally possible. A legal graph can still encode a bad plan.
The writer rule is conservative. It will flag parallel formatters that touch the same file even when the operations commute. If your tools are proven commutative, add an allow-list of names rather than deleting the check.
Clock fields remain useful for latency once cause is known. Computing a distribution on t_end_ms - t_start_ms for tool spans is fine after validate_run passes. Doing it before is how a skew outlier becomes a performance myth.
Skip this approach if you run a single synchronous agent on one machine with one writer and you already block on each tool. Your wall clock is probably causal, and the extra schema is noise. Also skip it if you cannot add fields to the exporter. Wrapping broken traces in a prettier test only produces prettier fiction.
If you already dump spans from a local loop, point the tests at one free-server run and one laptop run and compare which edges go missing. That difference is the observability gap. The model choice is secondary.
Top comments (0)