Keyboard shortcuts

Press ← or → to navigate between chapters

Press S or / to search in the book

Press ? to show this help

Press Esc to hide this help

6. Observability and traces

From cognokratos/simple-agent-template · docs/concepts/06-observability.md · pinned revision c66ce19d7b0c

This page covers learning-path stage 7.

Why logs are not enough for agents

In a conventional service, the code path for a request is fixed. You read logs to see which branch it took. In an agent, the model chooses the code path at runtime: which tools, in which order, how many times. Logs scattered across four services cannot answer the questions you actually ask when an agent misbehaves:

  • What did the model see when it chose that tool?
  • Which tool call returned the data the wrong answer was built from?
  • Did the input rail decide, or the model? Which layer of the rail?
  • Where did the 17 seconds go?

A trace answers these questions by recording the whole request as one tree of timed spans, so the shape of the agent's decision appears directly.

ConceptImplementation in this repo
Tracing standardOpenTelemetry (OTLP/HTTP)
Span source: agentNAT intermediate steps → NAT spans → agent_otlp exporter (otlp_exporter.py)
Span source: guardrailsNeMo Guardrails, through the process-wide OTel SDK
CollectorOpenTelemetry Collector (observability/otel-collector.yml)
Trace store and UIMLflow

One request, one trace

NAT and NeMo Guardrails emit spans through two different exporters. Left alone, they produce two unrelated traces per request. trace_context.py establishes one (trace_id, root_span_id) at the HTTP boundary, before either sees the request, so both join the same tree. This took some engineering. The reasons, and the private NAT attributes it relies on, are documented in OBSERVABILITY.md.

The trace recorded for the request walkthrough ("Show me the complete details and history for ticket TKT-1001", default model, local Ollama):

support-tickets-agent.invoke                        17.6 s   workflow root (NAT)
  fastapi.dependencies / fastapi.endpoint
  <workflow>                                        17.6 s   the ReAct loop (NAT)
    guardrail_input_self_check_decision                      decision event
    tickets_mcp__get_ticket                         0.03 s   MCP tool call
    guardrail_output_regex_presidio_decision                 decision event
  guardrail.input.self_check     outcome=passed     2.79 s   input rail
    guardrails.request
      guardrails.rail
        guardrails.action
          self_check_input qwen3:8b                 2.78 s   guard-model call
  guardrail.output.regex_presidio  outcome=passed   0.05 s   output rails
    guardrails.request
      guardrails.rail → guardrails.action                    regex check
      guardrails.rail → guardrails.action           0.04 s   Presidio masking

The trace answers the latency question. The tool call took 30 ms and the rails under 3 s combined, so most of the remaining ~14.7 s was the agent model. A warm repeat on commit af29ce0 had the same shape: 12.8 s total, 0.24 s input rail, and still ~12.5 s of agent model. A one-tool ReAct turn makes at least two model calls: one to choose the tool, one to write the answer. In these runs, agent latency was model latency, so the fix is fewer model round trips, not faster SQL.

In this observed trace, the agent model's own calls did not appear as separately named spans. Their time shows up only inside <workflow>. The guard-model call did appear (self_check_input qwen3:8b). Check what your trace contains rather than assuming.

What gets recorded, and what does not

Traces carry the questions and answers people send. That makes the trace store a data store with a retention and access problem. Decisions this repository makes:

DataDefaultWhy
Readable question and released answer on the root spanon (NAT_TRACE_CAPTURE_CONTENT)The answer is captured where the output rail releases it, so a masked or blocked answer never leaks into the root span
Credential headers (authorization, cookie, x-api-key, x-csrf-token, ...)redactedSensitiveHeaderRedactionProcessor in trace_processor.py
Raw gateway identity (x-authenticated-user-id, -username, -email)redacted, whatever OTEL_TRACE_USER_ID saysNAT copies request headers into span metadata; attribution is the pseudonym below, never the raw subject
Per-user identifieroff (OTEL_TRACE_USER_ID=false)A stable pseudonym turns a trace corpus into a per-person history
Pre-mask guardrail outputoff (GUARDRAILS_TRACE_CAPTURE_RAW_OUTPUT=false)It contains exactly what the rails exist to stop
Raw tool results in tool spansrecordedNot covered by output rails. Use synthetic data, or add tool-span redaction before real PII reaches a shared backend.

The last row is the honest gap. Header redaction is not content redaction. See OBSERVABILITY.md — redaction.

Traces and evaluations reinforce each other

  • An evaluation tells you that a case failed. The trace for that run tells you why: which tool, which arguments, which rail decision.
  • The guardrail spans carry structured attributes (guardrail.outcome, guardrail.decision_source, guardrail.deterministic.matches) that you can assert on. TEST-SCENARIOS.md lists them per scenario.
  • make trace-test (scripts/verify_traces_e2e.py) sends real requests and asserts on the resulting trace shape: one tree, guardrail spans present, readable I/O, no credentials.

Go deeper