← Our FailuresA failure recorder that re-entered itself wrote 249 rows per call and poisoned the green baseline for 28h
advanced6 min read · updated 2026-06-20
Market & numbers — every figure sourced
rows_written_per_call249 rowsest: Observed write amplification from the live incident: one logical failures.record() call produced 249 physical rows before the guard landed.
baseline_poisoned_duration28 hoursest: Measured wall-clock window during which the self-improvement loop's quality gate stayed red and merged nothing, from incident timeline.
amplification_factor249 xest: rows_written_per_call divided by the intended 1 row per call (249 / 1).
A failure recorder that re-entered itself wrote 249 rows per call and poisoned the green baseline for 28h
The cruelest bugs live inside the machinery you built to catch bugs. We had a `failures.record()` helper whose only job was to write one row when something went wrong. It wrote 249 rows per call instead, and because those rows fed the baseline that gated our self-improvement loop, the loop went red and merged nothing for 28 hours. Nothing else was broken. The detector ate the system.
What we tried
The design looked innocent. `failures.record(err)` appended one row to a table, then notified a few sinks so a human could see the failure (one of them mirrored the message to a chat channel). The intent was: one failure in, one row out, one ping out.
The trap is that the notify path could itself fail — a flaky network call to the chat mirror — and the obvious, well-meaning thing to do when notification fails is... record the failure. So `record()` called the mirror, the mirror raised, and the error handler called `record()` again. Same thread, same call still on the stack, before the first one finished. That is the textbook definition of a non-reentrant routine being re-entered: a function interrupted and resumed before it finishes, re-entering its own shared state (reentrancy).
What broke
It wasn't a clean infinite loop that crashed loudly. It was bounded enough to survive and amplify quietly:
- Each top-level `record()` fanned out into nested `record()` calls (notify-fails-so-record-the-notify-failure), and each of those fanned out again. One logical failure detonated into 249 physical rows.
- Those rows fed the quality-gate baseline. A green baseline is "few recent failures." 249x write amplification made every window look catastrophic, so the gate stayed red.
- The self-coding loop refuses to merge against a red baseline (correct behavior). So it merged nothing for 28 hours. The loop wasn't dead — it was being lied to by its own instruments.
This is the same failure family the standard tooling warns about. Python's `logging` is thread-safe but explicitly not reentrant inside a handler — calling logging APIs from within `emit()` can deadlock or recurse (not-reentrant). Loguru says it plainly: use the logger inside a sink and you "logically result in an infinite recursive loop," which is why it ships a reentrancy guard that raises rather than spins (reentrancy-guard). PostgreSQL hit the identical shape in memory-context logging and fixed it the identical way: a guard that detects "already in progress" and returns immediately (guard-pattern). When the Python core team debated unbounded recursion in logging handlers, the consensus mechanism was the same: a per-thread "we're already inside" flag (thread-flag).
The fix
A thread-local re-entrancy guard. Cheap, correct, and exactly what the references converge on.
```python
import threading
_in_record = threading.local()
def record(err):
Already recording on THIS thread? Don't recurse — drop the nested call.
if getattr(_in_record, "active", False):
return
_in_record.active = True
try:
_write_row(err) # the one row we actually want
_notify_sinks(err) # if a sink raises, the re-entry is a no-op
finally:
_in_record.active = False # finally is non-negotiable
```
Why each piece matters:
- Thread-local, not a global flag. A plain module-level boolean would make thread A's in-progress record block thread B's legitimate record. `threading.local()` scopes the guard to the calling thread, so concurrent failures on other threads still get recorded. The guard suppresses recursion, not concurrency.
- Drop, don't raise. Inside an error-recording path you can't afford the guard itself to throw — that just becomes a new failure to record. The nested call returns silently. The first call still completes and still writes its one row.
- `try/finally` is load-bearing. If `_notify_sinks` raises and you don't reset the flag, that thread is now permanently "recording" and will silently swallow every future failure. Quiet blindness is arguably worse than the cascade. Reset in `finally`, always.
- A reentrant lock is the wrong tool here. `threading.RLock` lets the same thread re-acquire and tracks a recursion level (rlock) — it prevents the deadlock but still lets the body run again, so you'd get the 249 rows without hanging. The goal is to NOT do the work twice, so you want a guard that short-circuits, not a lock that re-admits.
After the guard landed: one failure in, one row out. Baseline went green, the loop started compounding again, and the 28-hour gap closed.
Apply it
- Any writer that can call back into itself needs a re-entrant guard. Audit error recorders, logging sinks, metrics emitters, audit/event hooks, ORM `save` signals, cache-on-miss-that-writes-the-cache, and retry wrappers. Ask: "if the work inside this fails, does my failure handler call this same function?" If yes, you have a latent cascade.
- Failure-handling code must be reentrant or guarded — never let it call non-reentrant routines unprotected. That is literally rule 3 of reentrancy (rule-3). A logger inside a logger, a recorder inside a recorder — same trap every time.
- Treat your detectors' outputs as poisonable inputs. Our gate did exactly what it was told; the data was corrupt. Add a sanity bound: if a single logical event produces an absurd row count (e.g. >5 rows from one `record()`), alert on the amplification ratio, not just the absolute count. The signal "one cause, hundreds of rows" is the cascade signature.
- Make the guard fail safe in both directions. Re-entry must be a no-op (don't crash the original call), and the flag must reset in `finally` (don't go permanently deaf). Test both: one test that asserts a nested call writes zero extra rows, one that asserts a sink raising still leaves the next independent call able to record.
- When in doubt, copy the canon. Loguru, CPython, and Postgres all landed on "per-thread in-progress flag, short-circuit on re-entry." If three battle-tested codebases independently reached for the same guard, reach for it before inventing something cleverer.