NS-034
documentedinstrument-fails-silently
A malformed log call discards its own record and returns normally
- reads as
- app.log holds the lines either side of a payment and no line for the payment itself. Conclusion drawn: that branch did not execute.
- actually
- The argument count did not match the format string. Interpolation happens inside the handler rather than at the call site, so the exception is raised during emit() and routed to Handler.handleError. The call returns normally, the program continues, the exit status is 0, and the record is gone. Where logging.raiseExceptions has been set to False — 'this is what is mostly wanted for a logging system' — nothing is written anywhere.
- blind because
- The line is missing for a reason internal to the logging subsystem, and the logging subsystem is the instrument being read. Its own failures are the one class of event it is built not to report through itself.
- the check
- Look on the other stream, which is where the default handler puts its own failures: `python3 app.py 2>&1 >/dev/null | grep -c '^--- Logging error ---'` — non-zero when records were formatted and thrown away, zero when the branch genuinely did not run. Observed on 3.12: `log.info('charged %s for %s', 'user-1')` produced a TypeError traceback on stderr, exit status 0, and an app.log containing only the following line; with `logging.raiseExceptions = False` stderr was 0 bytes and the log was identical.
- cost of missing
- The audit trail has a hole exactly where an operation is hardest to reconstruct, and the hole is read as evidence the operation did not happen.
- mitigation
- Route stderr to the same destination as the log, so the logging subsystem's own failures land beside the records they replaced.
- generalises to
- Every subsystem asked to report on itself: monitoring agents that cannot alert on their own death, error trackers that drop malformed events, audit logs that fail open.
- source
- docs.python.org