DEV Community

MrClaw207
MrClaw207

Posted on

Your AI Agent's Logs Are Lying to You: A 4-Field Schema That Actually Works

I shipped a logging schema to my production agent pipeline six months ago. It logged every prompt, every tool call, every response, and every latency. The dashboards looked great. The alerts never fired. Then one Tuesday morning, an agent ran a 14-step task and ended on a confident "Done." It had fabricated three of those steps. My logs had captured every call. They had just hidden the failure.

The problem wasn't volume. It was that I was logging the wrong fields in the wrong shape. After 12 weeks of iterating on what actually surfaces failures, here's the schema that finally caught the fabrication before it shipped.

The Default Logging Trap

Most agent logging looks like this:

# What most teams ship on day one
log.info("agent_step", extra={
    "step_id": uuid4(),
    "agent_name": "research-agent",
    "prompt_tokens": 1247,
    "completion_tokens": 312,
    "latency_ms": 1843,
    "tool_calls": ["search", "fetch_url", "search"],
    "tool_results": [...],  # truncated to 500 chars
    "status": "ok",
})
Enter fullscreen mode Exit fullscreen mode

This looks comprehensive. It is useless for finding failures.

Three things break:

1. status: ok is what the model said, not what happened. The HTTP call may have returned a 401. The tool may have raised an exception. The agent doesn't see that — it sees a return value, and if that value parses as a dict, the agent logs ok.

2. Tool results are truncated. Truncating to 500 chars hides exactly the errors you need to see. Stack traces and validation messages tend to live past the first 500 characters of a JSON response.

3. There's no notion of intent. You know the agent called search, but you don't know what for. When the agent takes a wrong turn 12 steps in, you can't replay the reasoning because you only have the inputs and outputs.

The deeper issue: these logs are structured for cost analysis, not for catching failures. They were designed by people thinking about token spend, not by people trying to debug a fabrication at 11 PM.

The Four-Field Schema That Works

After three rewrites, I landed on a schema with four mandatory fields per step. Every step log now contains:

  1. expected_outcome — what the agent was trying to accomplish
  2. observed_outcome — what actually happened (HTTP status, exception class, parsed value)
  3. verification — whether the agent confirmed the observed outcome matched the expected one
  4. uncertainty_signal — explicit flag if the agent was unsure about the step

Here's what it looks like in Python:

import logging
from dataclasses import dataclass, asdict
from typing import Any

logger = logging.getLogger("agent.step")

@dataclass
class StepLog:
    step_id: str
    agent_name: str
    expected_outcome: str        # What success looks like
    observed_outcome: dict       # What actually happened (full, not truncated)
    verification: dict          # Did we verify? How?
    uncertainty_signal: str      # "none" | "low" | "high"
    tool_name: str | None = None
    latency_ms: int = 0

def log_step(step: StepLog) -> None:
    # Severity is derived from verification + uncertainty
    if not step.observed_outcome.get("success"):
        severity = "ERROR"
    elif step.uncertainty_signal == "high":
        severity = "WARNING"
    else:
        severity = "INFO"

    logger.log(
        getattr(logging, severity),
        "agent_step",
        extra={"step": asdict(step)},
    )
Enter fullscreen mode Exit fullscreen mode

The four fields work because they map to the three failure modes I kept hitting:

  • Silent failure (HTTP 200 but empty body): caught by observed_outcome requiring a success flag
  • Fabrication (agent invents success from a partial result): caught by verification requiring an explicit re-query
  • Confidence drift (model gets less sure over multi-step tasks): caught by uncertainty_signal

Verification Is the Hard One

verification is the field I underestimated. It seemed redundant at first — the agent just calls the tool, the tool returns something, done. But the difference between "called the tool" and "the tool worked" is where every fabrication I've caught has lived.

Concretely, every step that changes state needs a verification re-read. Closing a GitHub issue, sending an email, posting a comment, writing a file — all of these need a second API call to confirm the first one worked:

def log_github_close_issue(repo: str, issue_number: int) -> None:
    # 1. Execute
    close_response = github.post(
        f"/repos/{repo}/issues/{issue_number}/close",
        headers={"Authorization": f"Bearer {GITHUB_TOKEN}"},
    )

    # 2. Verify (separate API call)
    verify_response = github.get(
        f"/repos/{repo}/issues/{issue_number}",
        headers={"Authorization": f"Bearer {GITHUB_TOKEN}"},
    )

    # 3. Build the step log with verification embedded
    step = StepLog(
        step_id=str(uuid4()),
        agent_name="issue-closer",
        expected_outcome=f"Issue #{issue_number} state == 'closed'",
        observed_outcome={
            "close_call_status": close_response.status_code,
            "verify_call_status": verify_response.status_code,
            "actual_state": verify_response.json().get("state"),
            "success": (
                close_response.status_code == 200
                and verify_response.json().get("state") == "closed"
            ),
        },
        verification={
            "method": "re-read-via-get",
            "passed": (
                close_response.status_code == 200
                and verify_response.json().get("state") == "closed"
            ),
        },
        uncertainty_signal="none",
    )

    log_step(step)
Enter fullscreen mode Exit fullscreen mode

If verification.passed is False, the log severity is ERROR even if the agent itself reports status: ok. That's how I catch the fabrication: the agent believes it succeeded, but the log fires an alert because the verification field saw the truth.

The Uncertainty Signal

uncertainty_signal is the field I added last, and it's the one that catches the subtlest bugs. It's a string: "none", "low", or "high". The model sets it explicitly after each step.

Most teams try to derive uncertainty from logit values or token probabilities. That doesn't work — those values track next-token confidence, not task-level confidence. An agent can be very sure about which token comes next while being completely wrong about whether the tool returned useful data.

Instead, I prompt the agent to self-report:

SYSTEM_PROMPT = """
After each tool call, append a single line to your reasoning:
UNCERTAINTY: <none|low|high>

Use 'high' when:
- The tool returned an unexpected format
- You had to guess what a field meant
- You are inferring success without explicit confirmation

Use 'low' when:
- The tool returned what you expected but with minor formatting differences

Use 'none' when:
- You received exactly the data structure you asked for
"""
Enter fullscreen mode Exit fullscreen mode

Parsing this line gives the uncertainty_signal. Combined with verification, it produces three alert classes:

  • ERROR: verification failed → block the step, escalate to human
  • WARNING: verification passed but uncertainty high → flag for review, continue
  • INFO: verification passed and uncertainty low → silent

In my pipeline, about 4% of steps fire WARNING. About 0.6% fire ERROR. That 0.6% is where every fabrication has come from. The WARNINGs are where I find bugs in my tool definitions — cases where the tool returns technically-valid data that the agent misinterprets.

What I Learned

Three months in, the four-field schema has done three things the old logs couldn't:

Catching fabrications is automatic now. I no longer discover "the agent said done but didn't do it" the next morning. The verification step fires an ERROR within seconds, the agent's final report gets gated on the ERROR count, and a human gets pinged before anything ships.

Bugs in tool definitions surface faster. When an agent logs uncertainty_signal: high across many calls to the same tool, I know the tool schema or response format needs work. This was a huge blind spot before — I thought the agent was flaky when really the tool was ambiguous.

Token cost became debuggable. Because expected_outcome is structured, I can group steps by intent. Steps that share an expected_outcome but use wildly different token counts usually indicate either a bug or a tool returning data the agent has to re-parse multiple times. The cost team loves this; they used to only see totals.

The schema is not perfect. It still doesn't catch cases where the agent fabricates the verification itself — "yes I checked, the issue is closed" when the verification API was never called. For that, I added a separate layer that runs the verification logic outside the agent loop, in a watchdog process. That's a different article.

If you're starting from scratch with agent logging, don't begin with prompt_tokens and latency. Begin with: what does this step intend to do, what actually happened, did we verify the two match, and how unsure is the model? Those four questions catch almost every production failure I've seen in the last six months. The other fields are nice to have.

Top comments (0)