From Flat Logs to Execution Trees: Debugging Modern AI Agents

A developer detailed a method for reconstructing execution trees from flat event logs in AI agent debugging, addressing challenges like out-of-order events and incomplete spans. The approach uses stable trace and span identity, explicit assembly state, and diagnostics for anomalies such as duplicate starts or ends.

An agent trace is usually written as a sequence of events because append-only data is simple to produce: span started span started span ended span started span ended span ended Developers do not want to debug that sequence directly. They want to see the causal structure: research agent ├─ search web ├─ query database ├─ call finance api │ ├─ attempt 1 timeout │ └─ attempt 2 ok └─ summarize results The event stream is optimized for writing. The execution tree is optimized for understanding. Building a reliable tree requires more than sorting by timestamp: events may arrive out of order, siblings may run concurrently, spans may be incomplete, and retries may fail while the parent operation still succeeds. Every event needs stable trace and span identity. Start events establish parentage; end events establish outcome and duration. type SpanKind = 'run' | 'model' | 'tool' | 'retrieval' | 'decision' | 'fallback'; type TraceEvent = | { event: 'span started'; traceId: string; spanId: string; parentSpanId: string | null; name: string; kind: SpanKind; timestampMs: number; } | { event: 'span ended'; traceId: string; spanId: string; timestampMs: number; status: 'ok' | 'error' | 'cancelled'; errorCategory?: string; metadata?: Record<string, string | number | boolean | null ; }; Timestamps alone cannot establish parentage. Two events that occur next to each other may be siblings, unrelated concurrent work, or operations from different traces. Start and end events may not arrive together. A buffered exporter can deliver the end first, and a crashed process may never deliver an end at all. Represent assembly state explicitly: type AssembledSpan = { traceId: string; spanId: string; parentSpanId: string | null; name: string; kind: SpanKind; startedAtMs: number; endedAtMs?: number; status: 'open' | 'ok' | 'error' | 'cancelled'; errorCategory?: string; metadata: Record<string, string | number | boolean | null ; }; type AssemblyDiagnostic = { code: | 'duplicate start' | 'duplicate end' | 'end without start' | 'span left open'; spanId: string; }; class SpanAssembler { private readonly spans = new Map<string, AssembledSpan ; private readonly pendingEnds = new Map< string, Extract<TraceEvent, { event: 'span ended' } ; readonly diagnostics: AssemblyDiagnostic = ; accept event: TraceEvent : void { if event.event === 'span started' { if this.spans.has event.spanId { this.diagnostics.push { code: 'duplicate start', spanId: event.spanId } ; return; } const span: AssembledSpan = { traceId: event.traceId, spanId: event.spanId, parentSpanId: event.parentSpanId, name: event.name, kind: event.kind, startedAtMs: event.timestampMs, status: 'open', metadata: {}, }; this.spans.set event.spanId, span ; const pending = this.pendingEnds.get event.spanId ; if pending { this.pendingEnds.delete event.spanId ; this.applyEnd span, pending ; } return; } const span = this.spans.get event.spanId ; if span { if this.pendingEnds.has event.spanId { this.diagnostics.push { code: 'duplicate end', spanId: event.spanId } ; return; } this.pendingEnds.set event.spanId, event ; return; } if span.status == 'open' { this.diagnostics.push { code: 'duplicate end', spanId: event.spanId } ; return; } this.applyEnd span, event ; } private applyEnd span: AssembledSpan, event: Extract<TraceEvent, { event: 'span ended' } , : void { span.endedAtMs = Math.max span.startedAtMs, event.timestampMs ; span.status = event.status; span.errorCategory = event.errorCategory; span.metadata = event.metadata ?? {}; } finish : { spans: AssembledSpan ; diagnostics: AssemblyDiagnostic } { for const spanId of this.pendingEnds.keys { this.diagnostics.push { code: 'end without start', spanId } ; } for const span of this.spans.values { if span.status === 'open' { this.diagnostics.push { code: 'span left open', spanId: span.spanId } ; } } return { spans: ...this.spans.values , diagnostics: ...this.diagnostics , }; } } This assembler buffers an end event until its start arrives. At finalization, unmatched ends and open spans remain visible as diagnostics. It does not invent timestamps or mark incomplete work successful. For an unbounded live stream, pending events need a size limit and expiration policy. Otherwise malformed or hostile input can create an unbounded map. A valid trace normally has one root, but a renderer should handle multiple roots and orphans without crashing. type SpanNode = AssembledSpan & { children: SpanNode }; type TraceForest = { roots: SpanNode ; orphans: SpanNode ; duplicateIds: string ; }; function buildForest spans: AssembledSpan : TraceForest { const nodes = new Map<string, SpanNode ; const duplicateIds: string = ; for const span of spans { if nodes.has span.spanId { duplicateIds.push span.spanId ; continue; } nodes.set span.spanId, { ...span, children: } ; } const roots: SpanNode = ; const orphans: SpanNode = ; for const node of nodes.values { if node.parentSpanId === null { roots.push node ; continue; } const parent = nodes.get node.parentSpanId ; if parent { orphans.push node ; continue; } parent.children.push node ; } const sortChildren = node: SpanNode : void = { node.children.sort a, b = { return a.startedAtMs - b.startedAtMs || a.spanId.localeCompare b.spanId ; } ; node.children.forEach sortChildren ; }; roots.sort a, b = a.startedAtMs - b.startedAtMs ; roots.forEach sortChildren ; return { roots, orphans, duplicateIds }; } Validate parent links for cycles before recursively sorting or rendering. A malformed trace where A is the parent of B and B is the parent of A can otherwise cause infinite recursion. Cycle detection can use a depth-first search with visiting and visited sets. Orphans should appear in a separate “unattached spans” section with diagnostics. Hiding them makes instrumentation gaps look like missing work. Sort siblings by start time for a stable display, but do not imply that one caused the next. Parallel children can overlap completely. A useful UI combines two views: tree timeline research agent |----------------------| ├─ search web |-----| ├─ query database |-------------| ├─ finance api |--------| │ └─ retry |----| └─ summarize results |------| The tree explains why work happened. The timeline explains when it happened. Adding every span duration usually overstates trace time for two reasons: If a root lasts 2 seconds and contains two parallel 1-second tools, summing all three spans reports 4 seconds. The wall-clock run still lasted 2 seconds. Use separate metrics: Computing a true critical path requires dependency semantics, not just parentage. Sibling tools may all be required, any one may be sufficient, or one may be cancelled after another succeeds. The trace schema needs to represent those decision rules before a UI can label a critical path confidently. Retries are separate attempts with separate outcomes: load pricing ok ├─ attempt 1 error: timeout ├─ attempt 2 error: invalid response └─ fallback to cache ok: age minutes=18 The parent can legitimately succeed even when children fail. Do not automatically propagate the worst child status to the parent. The parent’s status should describe whether the operation fulfilled its contract; child statuses explain how. Quality gates can still warn when a successful parent depended on stale fallback data or exceeded an attempt budget. Processes crash, clients disconnect, serverless invocations end, and exporters drop events. An open span is evidence, not clutter. Render incomplete spans distinctly and include the reason when known: generate answer open: completion event missing stream response cancelled: client disconnected tool call unknown: adapter ended before callback Do not silently close every open span at the trace’s last timestamp. That invents duration and status. A UI may estimate a visible range, but it should label the estimate. Execution trees are useful regression artifacts, but exact snapshots are brittle. Compare durable properties: Ignore random IDs and normalize timestamps. For concurrent siblings, compare sets or parentage rather than one exact ordering. Newline-delimited JSON works well for local traces because each event is independently appendable and replayable. A reader can stream events through the assembler rather than loading every run into memory. Index or partition by trace ID when files become large. Bound retention and avoid storing raw prompts, tool payloads, retrieved documents, credentials, or user data by default. Tree reconstruction needs identity and lifecycle, not complete application content. Before trusting an execution tree, verify: Validation errors should be separate from agent errors. A malformed trace may describe a successful agent run while still being unusable for debugging. Flat events are not the enemy; they are the practical storage format. The mistake is treating their arrival order as the execution model. Assemble lifecycle events into spans, validate identity and parentage, preserve incomplete data honestly, and render both tree and timeline views. Then retries, fallbacks, parallel work, and silent failures become properties of a system you can inspect rather than clues scattered through a terminal transcript. That is the real shift from flat logs to execution trees: not more telemetry, but trustworthy structure.