Why console.log Isn't Enough When Building AI Agents
An AI agent fails, so you add a few log statements: console.log('starting agent'); console.log('tool result', result); console.log('final answer', answer); That works until the agent calls tools in parallel, retries one of them, falls back to cached data, and makes several model calls for different purposes. The terminal still contains the events, but it no longer explains the run. The limitation is not console.log() itself. The limitation is flat, uncorrelated events. Agent debugging needs identity, parent-child relationships, lifecycle, and safe metadata. Without those, more log lines often create more noise rather than more understanding. The Questions Flat Logs Cannot Answer Naturally Consider this output: 10:00:01 search started 10:00:01 search started 10:00:02 model started 10:00:02 search completed 10:00:03 search timed out 10:00:03 cache fallback used 10:00:04 model completed Several important questions remain: - Which search completed and which timed out? - Were the searches siblings or was one a retry? - Which model call depended on which search result? - Did the model begin before retrieval finished? - Did the final answer use live or cached data? - Which user request produced these events? Timestamps describe when events were written. They do not describe causality. Agent Runs Have More Than One Shape Some request paths are short and sequential, and flat logs are perfectly adequate. Agents become harder to observe because their control flow is often dynamic: - A model selects a tool at runtime. - Several retrieval strategies run concurrently. - A failed tool is retried with different arguments. - A fallback returns stale but valid data. - One agent hands work to another. - A stream begins before the complete result or usage is known. The useful representation is usually a tree: support_agent โโ classify_question โ โโ model_call โโ retrieve_context โ โโ vector_search โ โโ keyword_search โโ check_account โ โโ billing_api timeout โ โโ cached_account fallback โโ generate_answer โโ model_call The two model calls now have different roles. The fallback belongs to check_account , and the searches are parallel children of retrieval. The same events are easier to reason about because their relationships are explicit. Silent Failures Make Structure Essential The hardest agent failures do not always throw exceptions. A workflow can complete successfully while using the wrong path. Imagine a quote agent that reports an item as available. Every top-level operation says success , but the inventory service timed out and the agent used a cache that was a day old. The response is syntactically valid and the HTTP status is 200. The behavior is still wrong for the current user. A trace can make the path visible: generate_quote ok โโ find_product ok โโ check_inventory ok โ โโ live_inventory error: timeout โ โโ cached_inventory ok: age_hours=24 โโ compose_quote ok: inventory_source=cache Flat logs can capture all of these facts, but only if every line carries enough context to reconstruct the relationships. At that point, you are already building a tracing model. Add Correlation Before Adding Volume The first improvement is to give every run and step stable identity. type AgentEvent = { traceId: string; spanId: string; parentSpanId: string | null; event: 'started' | 'completed'; name: string; kind: 'run' | 'model' | 'tool' | 'retrieval' | 'fallback'; timestamp: string; status?: 'ok' | 'error' | 'cancelled'; durationMs?: number; metadata?: Record ; }; function writeEvent(event: AgentEvent): void { console.log(JSON.stringify(event)); } console.log() is still the output mechanism. The difference is that the event has a contract. A local script, log processor, test, or trace viewer can group events by traceId and rebuild the tree from parentSpanId . Structured events also make filtering reliable. Searching for a step name in prose logs is fragile; querying kind=tool and status=error is not. Record Lifecycles, Not Messages About Lifecycles Use one start and one completion event for each meaningful span. Completion should include status and duration. const startedAt = Date.now(); writeEvent({ traceId, spanId, parentSpanId, event: 'started', name: 'search_docs', kind: 'retrieval', timestamp: new Date(startedAt).toISOString(), }); try { const documents = await searchDocuments(query); writeEvent({ traceId, spanId, parentSpanId, event: 'completed', name: 'search_docs', kind: 'retrieval', timestamp: new Date().toISOString(), status: 'ok', durationMs: Date.now() - startedAt, metadata: { resultCount: documents.length }, }); } catch (error) { writeEvent({ traceId, spanId, parentSpanId, event: 'completed', name: 'search_docs', kind: 'retrieval', timestamp: new Date().toISOString(), status: 'error', durationMs: Date.now() - startedAt, metadata: { errorCategory: error instanceof Error ? error.name : 'UnknownError', }, }); throw error; } This is verbose when written manually, which is why real tracing libraries provide span helpers and async context propagation. The example exposes the information those helpers manage. Capture the Smallest Useful Metadata Useful metadata explains behavior without copying the payload: - Model name, input tokens, output tokens, and finish reason - Tool name, attempt number, and outcome category - Retrieval result count, score range, and context token count - Timeout, cancellation, or fallback status - Cache age and data-source category - Validation and authorization outcome Avoid raw user messages, prompts, model output, tool arguments, tool results, headers, credentials, and retrieved documents by default. They increase risk and often make traces harder to scan. For example, this metadata is enough to identify a broken context assembly step: retrieve_docs result_count=5 build_context context_tokens=0 generate_answer input_tokens=412 output_tokens=96 The trace narrows the problem without storing any document text. Use One Vocabulary Random log wording creates accidental complexity: tool finished tool done completed tool search returned Choose controlled names and statuses instead. A small vocabulary such as started , ok , error , cancelled , and blocked is easier to aggregate and test. Use a separate error category for timeout, validation, authorization, rate limit, or dependency failure. Consistency matters more than clever formatting. When Structured Logs Are Enough Structured logs may be all you need when the agent is small, runs in one process, has a few sequential operations, and does not need a visual timeline or distributed context. They are a good starting point when: - You are still learning the workflow. - Runs are short and low-volume. - One developer inspects the output locally. - Parent-child relationships are simple. - Retention and team-wide analysis are not required. The important step is to establish the event contract early. Moving structured events to a richer sink later is much easier than parsing years of inconsistent prose logs. When to Move to Tracing Use a tracing system when the agent has concurrent branches, retries, handoffs, streaming lifecycles, several services, or shared CI rules. Tracing adds capabilities that a terminal stream does not provide naturally: - Automatic context propagation - Parent-child span management - Timelines and execution trees - Trace-level sampling and retention - Cross-service correlation - Open-span and incomplete-run detection - Aggregation by model, tool, status, or error category OpenTelemetry, framework-native integrations, local trace tools, and hosted observability products all use variations of this model. The destination can change; the core mental model remains the same. A Practical Progression - Name the major agent boundaries. - Emit structured JSON rather than prose messages. - Add trace, span, and parent identifiers. - Record start/end lifecycle, status, and duration. - Use metadata-first capture and controlled vocabularies. - Add async context propagation when manual parent IDs become error-prone. - Move to a trace viewer or backend when volume and collaboration justify it. This progression avoids a large platform investment before the execution model is understood. Final Thought console.log() remains useful. It is available everywhere and can be a perfectly good sink for structured local events. What it cannot provide by itself is the causal model of an agent run. Do not respond to a confusing agent by printing more uncorrelated payloads. Add identity, lifecycle, parentage, and safe metadata. Once those relationships are visible, parallel tools, retries, fallbacks, and silent failures become much easier to explain. The next article will focus on the representation itself: how execution trees differ from flat event streams and how to reconstruct them reliably from span data. Top comments (0)
Comments
No comments yet. Start the discussion.