log-driven-debugging
verified2e0e052a-a96d-4188-b49b-aef9eba4543d
Use when a bug requires instrumenting code to find it — the log-and-narrow loop: log entry/exit with key vars, tighten the window, repeat, then remove the logs.
Metadata
Skill file
# Log-Driven Debugging
**Use when** you can reproduce a bug but can't see where it goes wrong, and need to instrument the code to follow the data flow. This is the log-and-narrow loop.
## The Log-and-Narrow Loop
```text
1. Log at function entry/exit with key vars
2. Run the repro
3. Read the log, find where values diverge from expectation
4. Tighten the window (log deeper into that branch)
5. Repeat until you can see the exact line
6. Fix, then REMOVE the debug logs
```
## What to Log — Not Just "here"
Bad logging logs position. Good logging logs *state*.
```python
# BAD — tells you nothing about the data
logger.debug("got here")
# GOOD — tells you the inputs, decisions, and outputs
logger.debug("process_order: order_id=%s items=%d total=%f",
order_id, len(items), total)
# Log decision branches explicitly
if total > threshold:
logger.debug("Taking DISCOUNT path: total=%f threshold=%f", total, threshold)
apply_discount(order)
else:
logger.debug("Taking STANDARD path: total=%f", total)
```
### The four things worth logging
1. **Inputs** — function arguments, parsed payloads
2. **Decision branches** — which `if`/`else` was taken and why
3. **Exception context** — the values at the moment of failure
4. **External I/O** — the exact SQL query, HTTP request/response
## Structured & Leveled Logging
Use levels so debug lines are removable, and structured fields so they're greppable:
```python
import logging
logging.basicConfig(
format="%(asctime)s %(levelname)s %(name)s %(message)s",
level=logging.DEBUG
)
logger = logging.getLogger("orders.process")
# Leveled by intent
logger.debug("detail for debugging") # remove after fix
logger.info("normal operation") # keep
logger.warning("something unexpected") # keep
logger.error("something failed") # keep
```
## The "Remove After" Discipline
Debug logs are scaffolding, not features. Track them so they don't ship:
```bash
# Mark all debug logs with a unique tag so you can find and remove them
grep -rn "DEBUG_TEMP" src/ # after the fix, delete every hit
# Or use a TODO convention your linter flags
# TODO(debug): remove this log
```
```python
# The discipline: after the fix, your diff should only contain
# (1) the actual fix and (2) removal of the debug logs — nothing else
git diff
```
## Worked Example: Finding a Wrong Calculation
```python
def calculate_shipping(weight_kg, zone, expedited):
base = ZONE_RATES[zone] # <-- suspect
multiplier = 1.5 if expedited else 1.0
return base * weight_kg * multiplier
# Instrument:
def calculate_shipping(weight_kg, zone, expedited):
logger.debug("shipping: weight=%s zone=%s expedited=%s",
weight_kg, zone, expedited)
base = ZONE_RATES[zone]
logger.debug("shipping: base_rate=%s for zone=%s", base, zone)
multiplier = 1.5 if expedited else 1.0
result = base * weight_kg * multiplier
logger.debug("shipping: result=%s", result)
return result
# Run, read log: "base_rate=0 for zone='eu'"
# -> ZONE_RATES missing 'eu' key, returns default 0. Root cause found.
```
## Guardrails
- Log *state*, not *position* — "got here" is useless
- Never commit debug logs to production — use the remove-after discipline
- Don't log secrets: passwords, tokens, PII, credit cards. Redact them.
- Don't log in a hot loop (1000s/sec) — it will bury the signal and slow the system
- One narrowing hypothesis at a time — don't spray logs everywhere and hope
## Pitfalls
| Pitfall | Fix |
|---------|-----|
| Log spam buries the signal | Log only key vars, not whole objects; use `logger.debug` not `print` |
| Leaving debug logs in prod | Grep for your tag before commit; CI lint for `print(` |
| Logging without a hypothesis | Decide what you expect to see BEFORE running |
| `print()` instead of logging | `print` has no level, can't be silenced, mixes with stdout |
| Logging the wrong variable | Log the *input* to the failing computation, not a downstream echo |
## Verify / Checklist
- [ ] Repro runs and produces a readable log
- [ ] Log contains inputs, decision branches, and the point of divergence
- [ ] Root cause identifiable from the log alone
- [ ] Fix applied and verified
- [ ] All debug logs removed (`git diff` shows only the fix)
- [ ] No secrets in any log lineAttached files
No attached files.