TL;DR
My AI coding agent wasn't bad at debugging — my logs were bad at being read. Five changes to how my services log (correlation IDs, structured JSON, errors that carry state, honest log levels, and a query command instead of a log file) took its median time-to-root-cause from ~40 minutes of flailing down to under 5. None of these habits are new. What's new is that a machine is now the primary reader of your logs.
The Problem
A checkout endpoint started returning 500s for about 2% of requests. Classic intermittent bug: not reproducible locally, no obvious pattern, and the kind of thing that eats an afternoon.
So I did what I'd been doing all year — handed it to my coding agent with production log access and went to make coffee.
Twenty minutes later it had:
- grepped
erroracross a 2.3 GB log file and found 4,100 matches - picked a
Redis connection resetline that turned out to be unrelated noise from a nightly job - added a retry wrapper around the Redis client
- told me, confidently, that this "should resolve the intermittent 500s"
It didn't. The actual bug was a race between a coupon-validation call and a cart-refresh call, and the evidence was sitting right there in the logs — just spread across four lines that had nothing linking them together.
That's when it clicked. The agent hadn't failed at reasoning. It had failed at evidence gathering, because my logs made evidence gathering nearly impossible. I'd spent years writing logs for a reader who already knew the system: me. Lines like:
[2026-09-04 11:42:07] processing cart
[2026-09-04 11:42:07] validating
[2026-09-04 11:42:08] failed, retrying
I can read that. I know "validating" means the coupon service and "failed, retrying" is the HTTP client's third attempt. An agent reads those lines the way a new hire does — except a new hire asks you a question, and an agent makes a plausible guess and writes code based on it.
The constraint that made this interesting: I couldn't make the agent smarter, but I could completely control what it had to read. So I spent a week rewriting logging across three services with exactly one design goal — a reader with zero prior context should be able to reconstruct one request end-to-end.
How I Solved It
Here's the loop I was optimizing for. The failure mode is always the same: the agent can't narrow, so it guesses.
flowchart TD
A[Bug report] --> B{Can the agent isolate<br/>one failing request?}
B -->|No| C[Grep for 'error']
C --> D[4,100 matches]
D --> E[Picks a plausible line]
E --> F[Fixes the wrong thing]
B -->|Yes| G[Pull full trace by ID]
G --> H[Read ordered, typed events]
H --> I[Compare to a passing request]
I --> J[Root cause]
Everything below is about moving from the left branch to the right branch. Stack: Python 3.13 with structlog, Node.js 22 LTS with pino 9.x, and Claude Code CLI (v2.x line, as of September 2026) as the agent.
Habit 1: One ID that survives the whole request
This is the single highest-leverage change, and it's boring. Generate an ID at the edge, stuff it in a context variable, and attach it to every single log line — including the ones inside your background workers.
# Python 3.13 + structlog
import contextvars, uuid, structlog
request_id_var = contextvars.ContextVar("request_id", default=None)
def bind_request_id(logger, method_name, event_dict):
rid = request_id_var.get()
if rid:
event_dict["request_id"] = rid
return event_dict
structlog.configure(
processors=[
bind_request_id,
structlog.processors.TimeStamper(fmt="iso"),
structlog.processors.JSONRenderer(),
]
)
# FastAPI middleware
@app.middleware("http")
async def attach_request_id(request, call_next):
rid = request.headers.get("x-request-id") or str(uuid.uuid4())
request_id_var.set(rid)
response = await call_next(request)
response.headers["x-request-id"] = rid
return response
The payoff isn't the ID itself — it's that "show me everything about the failing request" becomes a single filter instead of a research project. The first time I gave my agent a codebase with this in place, it stopped grepping for keywords entirely and started pulling traces.
If you adopt exactly one thing from this post, adopt this one. It's about 30 lines per service and it changes what questions are answerable.
Habit 2: Structured JSON, not prose
Prose logs force the agent to write a regex to parse your sentence structure, which it will do badly, and then reason on top of that bad parse. Compounding errors.
# Before — needs a parser, and the parser will be wrong
log.info(f"Coupon {code} rejected for user {uid} after {ms}ms")
# After — needs no parser
log.info("coupon_rejected", coupon=code, user_id=uid, duration_ms=ms, reason="expired")
Two rules that matter more than the format itself:
-
The event name is a stable identifier, not a sentence.
coupon_rejected, not"Coupon was rejected". Stable names make cross-request comparison trivial: countcoupon_rejectedin failing vs. passing traces and the anomaly jumps out. - Values go in fields, never interpolated into the message. The moment a user ID lives inside a string, filtering by user ID becomes substring matching.
Habit 3: Errors that carry state, not just a stack trace
A stack trace tells you where it broke. It almost never tells you why. An agent staring at TypeError: Cannot read properties of undefined (reading 'total') at line 214 will go read line 214 and start theorizing about null checks — when the real story is that an upstream call returned a 204 with an empty body.
// Node.js 22 LTS + pino 9
try {
return await applyCoupon(cart, code);
} catch (err) {
logger.error({
err, // pino serializes stack + message
event: "coupon_apply_failed",
coupon: code,
cart_id: cart.id,
cart_item_count: cart.items.length,
cart_version: cart.version, // the field that actually solved it
upstream_status: err.cause?.status ?? null,
}, "coupon application failed");
throw err;
}
cart_version was the whole ballgame in my race condition. Two requests were mutating the same cart, and the version numbers in the log made it obvious within seconds — to the agent, not to me. I'd been staring at those logs for an hour.
The rule I now apply when writing an error log: what would I need to know to reproduce this without asking anyone? Log that. If the answer is "the state of the object", log the state of the object.
Habit 4: Log levels that mean something
My levels had rotted into decoration. Half of ERROR was retryable noise; real failures were hiding at WARN because someone didn't want to page anybody. An agent takes your levels literally — that's why mine latched onto a Redis connection reset that a human would have skipped on sight.
The definitions I settled on and wrote into the project spec file:
| Level | Meaning | Agent's reading |
|---|---|---|
ERROR |
A user-visible operation failed and will not succeed | Start here |
WARN |
Something degraded but recovered (retry succeeded, fallback used) | Context, not cause |
INFO |
A business event happened (order placed, coupon applied) | Timeline material |
DEBUG |
Internal step detail | Only when tracing one request |
Then I did the unglamorous part: swept the codebase and re-leveled roughly 300 call sites to match. Unsurprisingly, this is exactly the kind of mechanical-but-judgment-heavy sweep an agent is great at — I reviewed the diff in chunks rather than writing it by hand.
Habit 5: Give the agent a query command, not a log file
Pointing an agent at raw logs is how you burn 50k tokens to learn nothing. Pointing it at a command that returns exactly one trace is how you burn 2k tokens and get an answer.
#!/usr/bin/env bash
# logq — trace a single request across services
# usage: logq trace <request_id> [--since 24h]
# logq errors [--since 1h] [--top 20]
case "$1" in
trace)
jq -c --arg rid "$2" 'select(.request_id == $rid)' "$LOG_PATH" \
| jq -s 'sort_by(.timestamp)' ;;
errors)
jq -c 'select(.level == "error")' "$LOG_PATH" \
| jq -r '.event' | sort | uniq -c | sort -rn | head -"${3:-20}" ;;
esac
Then I documented it in CLAUDE.md so the agent reaches for it unprompted:
## Debugging production issues
Never grep the raw log file — it's multi-GB and unstructured at the edges.
1. `logq errors --since 1h` to find which event names are spiking
2. `logq trace <request_id>` to pull one full request timeline
3. Always pull a *passing* trace too and diff the two before theorizing
That last line did more than the script did. "Compare a failing trace to a passing trace" is the single instruction that most reliably stops an agent from pattern-matching on the first scary-looking line it sees.
Lessons Learned
1. Your logs are now a machine-readable API. Version them like one. Once an agent (and a logq script, and a dashboard) depends on the event name coupon_rejected, renaming it is a breaking change. I treat event names with the same care as route paths now.
2. Agents fail at evidence gathering far more than at reasoning. Every "the AI wrote a dumb fix" story I've hit this year traced back to the agent reasoning correctly over bad or partial evidence. Fixing inputs beat every prompt-engineering trick I tried.
3. Optimize for "reconstruct one request", not "search everything". Search-everything is a human affordance — we're good at skimming and discarding. An agent's context window is small and expensive, and irrelevant lines don't just waste tokens, they actively mislead. Narrow beats complete.
4. Tools beat instructions when the task is mechanical. I spent two days writing increasingly elaborate prompt instructions about how to search logs carefully. A 20-line shell script made all of them unnecessary. If you find yourself writing a paragraph explaining how to gather information, you should probably be writing a command instead.
5. This is just good observability, and that's the point. Every habit here is something an SRE would have told you in 2018. The AI angle didn't change the advice — it changed the ROI. Sloppy logs used to cost me an afternoon occasionally. Now they cost me every single automated debugging run, and the improvements compound daily.
What's Next
Two things I'm working on:
-
Sampling
DEBUGin production for a small slice of traffic. Right nowDEBUGis off in prod, which means the richest data disappears exactly when I need it. Head-based sampling at ~1% with forced capture on error looks like the right trade. -
Wiring OpenTelemetry spans into the same query command, so
logq tracereturns logs and timing spans on one timeline. Half of my remaining hard bugs are latency-shaped, and logs alone under-serve those.
I'd also like to stop maintaining logq as a shell script and expose it as a proper tool the agent calls directly — the bash-wrapper stage is clearly temporary.
Wrap-up
If your AI agent keeps "fixing" the wrong thing, before you rewrite your prompts, go read your logs the way it has to: with no prior knowledge, one line at a time, unable to ask a question. It's an uncomfortable exercise and it'll show you exactly what to fix.
Start with correlation IDs. It's an afternoon of work and it's the one that unlocks everything else.
Your turn: what's the one logging change that paid for itself fastest in your codebase? Drop it in the comments — I'm still collecting these. 👇
If this was useful, follow me here on Dev.to — I write about building and living with autonomous coding agents, usually with the embarrassing parts left in. 🚀
Top comments (0)