The Correct Timestamp Was in the Prompt: An SRE Field Guide to Observing Non-Deterministic LLM Agents

When an LLM agent answers "the current time is 14:32" and your dashboard insists the request landed at 14:35, one of two things is true: either the model hallucinated, or your observability pipeline is lying to you. In production, it is almost always the second. Non-deterministic agents quietly break every assumption classical SRE instrumentation was built on — stable timestamps, idempotent retries, bounded label cardinality, and reproducible execution paths. This field guide is about rebuilding observability from first principles for systems whose behavior is a probability distribution rather than a pure function.

Everything below is tooling-agnostic in principle and concrete in practice: OpenTelemetry, hybrid logical clocks, tail-based sampling, structured logs with content hashes, and task-level SLOs. If you currently debug agents by grepping raw prompt dumps out of a log aggregator, this article is the intervention.

Table of Contents

• 1. Why Your Monitoring Lies: Broken Assumptions
• 2. A Data Model for Agent Observability
• 3. Instrumenting an Agent End-to-End
• 4. Time, Ordering, and Watermarks
• 5. Tracing Branchy, Non-Deterministic Execution
• 6. Metrics That Survive Non-Determinism
• 7. Continuous Evaluation as a First-Class Signal
• 8. Alerting and SLOs for Agents
• 9. Storage Economics: What to Keep, What to Hash
• 10. Field Checklist
• Frequently Asked Questions

1. Why Your Monitoring Lies: Broken Assumptions

Classical observability was designed for services that are, most of the time, deterministic. Given the same input, a REST handler returns the same status code; a database query returns the same rows; a retry is safe because the operation is idempotent. LLM agents violate all three, and the violations are invisible until an incident.

The timestamp paradox

The failure in the title is worth dissecting because it generalizes. A user asks an agent "what time is it?" The agent replies "14:32." Your trace says the request arrived at 14:35:01. Four explanations, in decreasing order of likelihood:

1. Stale context injection. The system prompt was templated at session start (14:30) and the agent is reasoning over a timestamp minutes old.
2. Clock skew across replicas. Three pods, three NTP states, one load balancer. The "correct" wall time is whichever replica's clock you happen to trust.
3. Model-emitted time treated as truth. The agent called a get_time() tool, got a result, and paraphrased it badly — or the tool result was truncated out of context.
4. Actual hallucination. Rarest, and the only case your current dashboard can detect.

The engineering rule that falls out of this: a timestamp produced by an LLM is data, not metadata. It belongs in the payload you hash and store, never in the span attribute you sort by. Ordering must come from clocks you control at ingress.

Idempotency and retries

Agents retry naturally: the model re-plans after a tool error, your framework retries a rate-limited LLM call, your orchestrator retries a failed step. In deterministic systems, retries collapse cleanly into one logical operation. In agent systems, a retry produces a different trajectory — different tokens, different tool arguments, different side effects. If your tracing deduplicates by request_id alone, you will silently lose the divergent branch that caused the incident.

Cardinality explosion

http.status_code=200 has bounded cardinality. agent.completion="I have scheduled your meeting for Tuesday" does not. Naively promoting prompt/completion text to metric labels is the fastest way to bankrupt your metrics backend. The fix is a strict split: hashes and bounded enums go in attributes and labels; raw text goes in a small, sampled payload store linked by hash.

2. A Data Model for Agent Observability

Before writing code, fix the taxonomy. An agent run is a tree, not a line. Three span kinds, nested:

agent.run  (SERVER)                     ← one user task, one trace
├── agent.step  (INTERNAL)              ← one reasoning iteration
│   ├── llm.plan  (CLIENT)              ← one model call
│   └── tool.search  (INTERNAL)         ← one tool invocation
├── agent.step  (INTERNAL)              ← retry after tool error
│   ├── llm.plan  (CLIENT)
│   └── tool.email  (INTERNAL)
└── agent.eval.llm_judge  (INTERNAL)    ← sampled quality check

Map this onto the OpenTelemetry GenAI semantic conventions so your data is portable across vendors and backends:

Two attributes deserve emphasis. agent.prompt.sha256 is your join key: it lets you link a trace span to a sampled full payload in object storage without shipping megabytes through your telemetry pipeline. agent.started_at.hybrid (covered in §4) is your ordering key, and it is the direct fix for the timestamp paradox.

3. Instrumenting an Agent End-to-End

Prerequisites

• Python 3.10+
• pip install opentelemetry-api opentelemetry-sdk structlog
• Any OTLP-compatible backend (Jaeger, Tempo, Honeycomb, Datadog) — the examples below use the console exporter so they run standalone.

The patterns translate directly to TypeScript/Node or Go; the semantic attributes are language-independent.

Step 1 — Tracing and metrics bootstrap

# otel_setup.py
from opentelemetry import trace, metrics
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import ConsoleSpanExporter, SimpleSpanProcessor
from opentelemetry.sdk.metrics import MeterProvider
from opentelemetry.sdk.metrics.export import ConsoleMetricExporter, PeriodicExportingMetricReader

def init_telemetry(service_name: str = "llm-agent"):
    trace_provider = TracerProvider()
    trace_provider.add_span_processor(SimpleSpanProcessor(ConsoleSpanExporter()))
    trace.set_tracer_provider(trace_provider)

    reader = PeriodicExportingMetricReader(
        ConsoleMetricExporter(), export_interval_millis=60_000
    )
    metrics.set_meter_provider(MeterProvider(metric_readers=[reader]))

    return trace.get_tracer(service_name), metrics.get_meter(service_name)

In production, swap the console exporters for OTLPSpanExporter / PeriodicExportingMetricReader(OTLPMetricExporter()) and let the Collector handle tail sampling and redaction.

Step 2 — A clock you can defend

# clocks.py
import time
from dataclasses import dataclass

@dataclass(frozen=True)
class HybridTimestamp:
    wall: float      # physical clock reading (event time)
    logical: int     # tie-breaker for identical wall readings

    def __str__(self) -> str:
        return f"{self.wall:.6f}:{self.logical}"

class HybridClock:
    """
    Lamport-style hybrid clock. Guarantees monotonic, unique ordering even when
    NTP steps backwards or two replicas emit within the same microsecond.
    """
    def __init__(self) -> None:
        self._last_wall = 0.0
        self._logical = 0

    def now(self) -> HybridTimestamp:
        wall = time.time()
        if wall > self._last_wall:
            self._last_wall = wall
            self._logical = 0
        else:
            self._logical += 1
        return HybridTimestamp(self._last_wall, self._logical)

Call clock.now() at ingress, before any model I/O. That single discipline resolves most "the monitoring lied" incidents.

Step 3 — GenAI span attributes with content hashing

# genai_spans.py
import hashlib, json

def sha256(text: str) -> str:
    return hashlib.sha256(text.encode("utf-8")).hexdigest()

def record_llm_io(span, *, model: str, prompt: str, completion: str,
                  prompt_tokens: int, completion_tokens: int, latency_ms: float):
    span.set_attribute("gen_ai.system", "openai")
    span.set_attribute("gen_ai.request.model", model)
    span.set_attribute("gen_ai.operation.name", "chat")
    span.set_attribute("gen_ai.usage.prompt_tokens", prompt_tokens)
    span.set_attribute("gen_ai.usage.completion_tokens", completion_tokens)
    # Hash by default. Sample full payloads separately (see section 9).
    span.set_attribute("agent.prompt.sha256", sha256(prompt))
    span.set_attribute("agent.completion.sha256", sha256(completion))
    span.set_attribute("agent.llm.latency_ms", latency_ms)

Step 4 — Tool spans with exception capture

# tools.py
import time
from opentelemetry.trace import SpanKind, Status, StatusCode
from genai_spans import sha256

def run_tool(tracer, name: str, args: dict, fn):
    with tracer.start_as_current_span(f"tool.{name}", kind=SpanKind.INTERNAL) as span:
        span.set_attribute("agent.tool.name", name)
        span.set_attribute(
            "agent.tool.args.sha256", sha256(json.dumps(args, sort_keys=True))
        )
        started = time.perf_counter()
        try:
            result = fn(**args)
            span.set_attribute(
                "agent.tool.duration_ms", (time.perf_counter() - started) * 1000
            )
            span.set_status(Status(StatusCode.OK))
            return result
        except Exception as exc:
            span.record_exception(exc)
            span.set_status(Status(StatusCode.ERROR, str(exc)))
            raise

Note what is not here: the tool output. Tool results are the largest, most sensitive payload in an agent system. Hash them; store a sample.

Step 5 — The agent loop

# agent.py
import json, time, random
from dataclasses import dataclass
from typing import Callable

from opentelemetry.trace import SpanKind
from otel_setup import init_telemetry
from clocks import HybridClock
from genai_spans import record_llm_io, sha256

tracer, meter = init_telemetry()
clock = HybridClock()

task_success = meter.create_counter("agent.task.success", unit="1")
step_latency = meter.create_histogram("agent.step.duration", unit="ms")
tool_errors   = meter.create_counter("agent.tool.errors", unit="1")

@dataclass
class Step:
    kind: str          # "llm" | "tool"
    name: str
    ok: bool
    duration_ms: float

def fake_llm(prompt: str, model: str = "gpt-4o-mini"):
    """Stand-in for a real client. Swap in openai/anthropic here."""
    time.sleep(random.uniform(0.05, 0.2))
    if "time" in prompt.lower():
        # Model emits a timestamp from its own context. Data, not ordering truth.
        return "The current time is 14:32.", 12, 9
    if "search" in prompt.lower():
        return '{"tool": "search", "args": {"q": "otel genai conventions"}}', 18, 14
    return "Task complete.", 22, 6

class ObservabilityFirstAgent:
    def __init__(self, llm: Callable, tools: dict, max_steps: int = 8):
        self.llm = llm
        self.tools = tools
        self.max_steps = max_steps

    def run(self, task_id: str, objective: str):
        ts = clock.now()  # capture BEFORE any model I/O
        with tracer.start_as_current_span("agent.run", kind=SpanKind.SERVER) as run:
            run.set_attribute("agent.task_id", task_id)
            run.set_attribute("agent.objective.sha256", sha256(objective))
            run.set_attribute("agent.started_at.wall", ts.wall)
            run.set_attribute("agent.started_at.hybrid", str(ts))
            steps: list[Step] = []

            for i in range(self.max_steps):
                step_ts = clock.now()
                with tracer.start_as_current_span("agent.step", kind=SpanKind.INTERNAL) as step:
                    step.set_attribute("agent.step.index", i)
                    step.set_attribute("agent.step.at.hybrid", str(step_ts))

                    t0 = time.perf_counter()
                    completion, pt, ct = self.llm(f"Objective: {objective}\nStep {i}")
                    dur = (time.perf_counter() - t0) * 1000
                    record_llm_io(step, model="gpt-4o-mini", prompt=objective,
                                  completion=completion, prompt_tokens=pt,
                                  completion_tokens=ct, latency_ms=dur)
                    step_latency.record(dur, {"agent.step.kind": "llm"})

                    if completion.strip().startswith("{"):
                        call = json.loads(completion)
                        tool_name, args = call["tool"], call["args"]
                        try:
                            self.tools[tool_name](**args)
                            steps.append(Step("tool", tool_name, True, dur))
                            run.add_event("agent.tool.ok", {"tool": tool_name})
                        except Exception:
                            tool_errors.add(1, {"agent.tool.name": tool_name})
                            steps.append(Step("tool", tool_name, False, dur))
                            run.add_event("agent.tool.error", {"tool": tool_name})
                    else:
                        steps.append(Step("llm", "plan", True, dur))
                        if "complete" in completion.lower():
                            break

            ok = any(s.kind == "llm" and s.ok for s in steps)
            task_success.add(1, {"agent.outcome": "success" if ok else "failure"})
            run.set_attribute("agent.steps.total", len(steps))
            run.set_attribute("agent.outcome", "success" if ok else "failure")

if __name__ == "__main__":
    ObservabilityFirstAgent(
        llm=fake_llm,
        tools={"search": lambda q: f"results for {q}"},
    ).run(task_id="task-001", objective="Find the time and search OTel conventions")

Step 6 — Structured logs keyed by hash

# logging_setup.py
import structlog
from genai_spans import sha256

log = structlog.get_logger()

def logged_llm_call(task_id: str, step: int, prompt: str, completion: str,
                    pt: int, ct: int):
    log.info(
        "agent.llm.response",
        task_id=task_id,
        step=step,
        prompt_sha256=sha256(prompt),
        completion_sha256=sha256(completion),
        prompt_tokens=pt,
        completion_tokens=ct,
    )

Because task_id and the content hashes appear in both logs and traces, you can pivot from a slow-trace alert to the exact log line to the sampled raw payload with one join key.

4. Time, Ordering, and Watermarks

Observability for agents is ultimately an event-time problem wearing a costume. Wall-clock timestamps in a distributed system are advisory; ordering is what you actually need. Three rules:

1. Capture at ingress. Stamp agent.started_at.hybrid the moment the request enters your service, before any model call, retry, or queue wait.
2. Never sort by model-emitted or tool-emitted time. Those are payload fields. A tool returning {"timestamp": "14:32"} is asserting something about the world; your pipeline should record the assertion, not believe it.
3. Use hybrid logical clocks for tie-breaking. The HybridClock in Step 2 guarantees strict monotonicity within a process. Across processes, concatenate (host_id, wall, logical) — or rely on the trace's span parent/child relationships, which are ordering facts independent of clocks.

For streaming or long-running agents, add a watermark: the ingress timestamp of the oldest task still in flight. Dashboards that aggregate by event time should discard anything older than the watermark, which prevents late-arriving retries from silently rewriting your p95 latency after the fact.

5. Tracing Branchy, Non-Deterministic Execution

A single agent run can produce traces with wildly different shapes — two steps one time, eleven the next, tool calls in a different order. Two consequences:

Head sampling is nearly useless. Randomly keeping 5% of traces means you keep 5% of the interesting failures. Use tail-based sampling in the OpenTelemetry Collector, where the decision is made after the trace completes:

# otel-collector-config.yaml (excerpt)
processors:
  tail_sampling:
    decision_wait: 10s
    expected_new_traces_per_sec: 50
    policies:
      - name: errors
        type: status_code
        status_code:
          status_codes: [ERROR]
      - name: slow-runs
        type: latency
        latency:
          threshold_ms: 5000
      - name: expensive
        type: string_attribute
        string_attribute:
          key: agent.outcome
          values: [failure]
      - name: baseline
        type: probabilistic
        probabilistic:
          sampling_percentage: 2

Divergent retries must stay in the same trace. Do not start a new trace on retry. Keep the retry as a sibling span under agent.run and tag it with agent.retry.attempt and agent.retry.reason. When you later ask "why did this task take nine steps?", the answer is a single trace, not nine fragmented ones.

6. Metrics That Survive Non-Determinism

You cannot dashboard on completion text. You can dashboard on the shape and cost of behavior:

That last one deserves a note. Hashing completions gives you a cheap novelty signal: if the fraction of agent.completion.sha256 values never seen before jumps from 3% to 40% after a prompt change or model upgrade, you have detected behavioral drift without any LLM-as-judge in the loop.

7. Continuous Evaluation as a First-Class Signal

The most under-instrumented signal in agent systems is quality. Correctness is not something you can assert with status_code; you have to measure it. Treat evals as spans in the same trace, sampled at a low rate:

# evals.py
from opentelemetry.trace import SpanKind

def run_continuous_eval(tracer, task_id: str, objective: str, completion: str,
                        judge_score: float):
    with tracer.start_as_current_span("agent.eval.llm_judge",
                                      kind=SpanKind.INTERNAL) as span:
        span.set_attribute("agent.task_id", task_id)
        span.set_attribute("agent.eval.kind", "llm_judge")
        span.set_attribute("gen_ai.request.model", "gpt-4o")
        span.set_attribute("agent.eval.score", judge_score)

Link the eval span to the production trace via agent.task_id, and dashboard avg(agent.eval.score) alongside agent.task.success. When the two disagree — high success rate, collapsing eval score — you have found a case where users are too polite to report failure.

8. Alerting and SLOs for Agents

Thresholds on single requests are noise in non-deterministic systems. Alert on burn rate against a task-level SLO:

• SLO: 99% of agent tasks reach agent.outcome=success within 30 seconds over 7 days.
• Fast burn page: 14.4× budget consumption over 1 hour → wake someone up.
• Slow burn ticket: 6× consumption over 6 hours → file an issue.
• Composite pages only: agent.tool.errors up and agent.task.success down on the same tool name. Tool errors alone are expected; correlated degradation is an incident.
• Loop detector: p99(agent.steps.total) > 3 × 7-day median — the single highest-value agent-specific alert.

Avoid alerting on agent.llm.latency_ms in isolation. Provider-side latency is variable and largely outside your control; page on task latency, which is what users feel.

9. Storage Economics: What to Keep, What to Hash

Full fidelity for every agent run is unaffordable. A workable tiering policy:

1. Always keep (100%): span structure, semantic attributes, hashes, token counts, durations, error status.
2. Always keep for failures (100%): full prompt and completion payloads for any trace where agent.outcome=failure or a span has ERROR status.
3. Sample the rest (1–5%): full payloads for successful runs, written to cheap object storage keyed by agent.task_id and content hash.
4. Redact at the collector, not the app: use an OTel Collector transform/redaction processor so PII never leaves your network boundary. Hash-then-redact means you keep joinability without retaining content.

This keeps your trace backend at roughly constant size per task while preserving the ability to answer "show me the exact prompt that produced this failure" months later.

10. Field Checklist

Before you declare an agent observable, confirm every item:

• Ingress hybrid timestamp captured before any model I/O
• No model-emitted or tool-emitted timestamp used for ordering
• gen_ai.* semantic attributes on every LLM span
• Prompts, completions, and tool payloads hashed; full text only in sampled storage
• Tail-based sampling in the Collector; retries stay within the parent trace
• agent.task_id joins traces, logs, and eval spans
• Metrics use bounded enums only — no completion text as labels
• Task-level SLO with burn-rate alerts, plus a step-count loop detector
• PII redaction enforced at the Collector boundary
• A runbook entry: "model says X, monitoring says Y" → compare agent.started_at.hybrid first

The last item is the cultural fix. The instinct during an agent incident is to distrust the model first. Train the team to distrust the clock, the cache, and the context window first — the model is usually faithfully reporting a stale world.

Frequently Asked Questions

Why not just log the entire prompt and completion for every run? Cost, cardinality, and compliance. A single busy agent can generate megabytes of prompt text per minute; promoting that to trace attributes or metric labels will exhaust most backends and can leak PII into systems that were never scoped for it. Hash by default, sample deliberately, and redact at the Collector so the decision is enforced centrally rather than per-service.

Can I use standard distributed tracing without any of these changes? You can, and you will get spans — but they will mislead you. Standard tracing assumes span timing explains behavior; in agent systems the content of steps determines the trajectory, so you need content hashes, hybrid clocks, and tail sampling to reconstruct what actually happened. Tracing is the skeleton; these additions are the nervous system.

How do I handle agents that run asynchronously across queues and hours-long workflows? Propagate the trace context (and the original ingress hybrid timestamp) through your message payload, not just headers, so each worker extends the same trace rather than starting a new one. Aggregate by event time with a watermark based on the oldest in-flight task, and treat each queue hop as an INTERNAL span under the original agent.run so the user-perceived latency remains one trace.

For more on building resilient instrumentation and platform practices, see Tamiz's Insights.