Summary
#1491 merged as 8517bf8fb and closed #1452. It fixes the two headline cases, but the fallback it added still loses the record in two other cases, and emits invalid JSON in two more.
Reported because #1452's whole point was that the comment claimed more than the code enforced. The comment on main today says the fallback means "a bad enrichment costs its own value rather than the whole record". Measured against main, that is still not true.
Not a vulnerability, and not reachable from request content — an attacker-supplied header is a string, and strings serialize correctly. Same reachability as #1452: extra={"request_id": ...} → correlation_id.
Reproduction
Against main @ 8517bf8fb. Three logger.info calls through a real StreamHandler, the middle one poisoned:
| Input |
Result on main |
| circular container |
3 of 3 — fixed by #1491 |
value whose __str__ raises |
3 of 3 — fixed by #1491 |
value with a forged __class__ |
2 of 3 — record lost |
value whose __str__ raises an exception that itself raises |
2 of 3 — record lost |
inf |
3 of 3, but not valid JSON (Infinity) |
nan |
3 of 3, but not valid JSON (NaN) |
1. Forged __class__ — the filter disagrees with the encoder
class ForgedClassStr:
@property
def __class__(self): return str
def __str__(self): raise RuntimeError("boom")
isinstance consults value.__class__, which this forges; json dispatches on the real runtime type. So the value passes the isinstance filter, reaches the fallback's own json.dumps — which on main carries default=str, so str() is called and raises — and the record is gone.
Two independent problems in one line: the filter is forgeable, and the fallback dump has default=str. Either alone would be enough. main:
safe = {k: v for k, v in payload.items()
if isinstance(v, (str, int, float, bool, type(None)))}
safe["serialization_error"] = f"{type(exc).__name__}: {exc}"
return json.dumps(safe, ensure_ascii=True, default=str)
Fix: type(value) in {str, int, float, bool, type(None)}, and drop default= from the fallback dump — nothing may reach default on that path, because reaching it is what reinstates the raising-__str__ hole.
2. The error reporter is unguarded
safe["serialization_error"] = f"{type(exc).__name__}: {exc}"
{exc} calls the caught exception's own __str__. That exception can originate in a call site's __str__, so it can be an instance of a class whose __str__ also raises — and this raise happens inside the except block, where nothing catches it. The record is lost, by the code added to save it.
class ExplodingError(Exception):
def __str__(self): raise RuntimeError("the error's own __str__ exploded")
class NestedExplodingStr:
def __str__(self): raise ExplodingError()
Fix:
try:
detail = f"{type(exc).__name__}: {exc}"
except Exception: # noqa: BLE001 - the type name alone still identifies it
detail = type(exc).__name__
Worth noting: all four of the other implementations of #1452 (#1471, #1472, #1477, #1488) had this guard. #1491 is the only one without it, and #1472 shipped a test (test_exception_whose_str_also_raises_does_not_lose_the_record) that fails on main today.
3. Non-finite floats produce invalid JSON
json.dumps renders inf/nan as the JavaScript literals Infinity/NaN, which are not valid JSON. It does not raise, so the record is emitted looking healthy and a strict downstream parser rejects it — the same loss as dropping it, moved to the consumer where it is harder to see. json.loads accepts those literals by default, which is why no test here catches it; asserting this needs parse_constant= raising.
Fix: allow_nan=False on both dumps, plus a math.isfinite check in the scalar filter so the fallback does not re-emit them.
Acceptance criteria
- A forged-
__class__ value is emitted, not dropped, with level authoritative.
- An exception whose own
__str__ raises is emitted, not dropped.
inf / -inf / nan in an enrichment produce a record that parses under a strict JSON parser.
- Regression tests for all three, each failing on
8517bf8fb.
- The
_format_json comment states the guarantee the code actually provides — and scopes it to serialization, since record.getMessage() on mismatched %-args still loses the record upstream of the guard (pre-existing, shared with the line-oriented path, out of scope).
Provenance
Findings 1 and 2 are #1471's and #1472's, from the four-way collision on #1452 — four sessions implemented that issue inside six minutes with no visibility of each other (comparison). Finding 3 is from a red-team pass on #1477.
#1491 was a fifth implementation and merged; the triage that selected it could not see the cross-PR analysis, which was posted minutes earlier on the other four. The mechanical result is that the merged version is the only one lacking the reporter guard. Filing rather than re-opening anything: #1477 was closed as superseded and stays closed, and no competing PR should be opened against #1452, which is correctly closed. This is a follow-up against what is on main now.
I have deliberately not opened a PR for this — the last round produced five for one issue, and a sixth without triage input would repeat exactly that. Happy to implement it on request; the patch is small and the three fixes are independent.
Summary
#1491 merged as
8517bf8fband closed #1452. It fixes the two headline cases, but the fallback it added still loses the record in two other cases, and emits invalid JSON in two more.Reported because #1452's whole point was that the comment claimed more than the code enforced. The comment on
maintoday says the fallback means "a bad enrichment costs its own value rather than the whole record". Measured againstmain, that is still not true.Not a vulnerability, and not reachable from request content — an attacker-supplied header is a string, and strings serialize correctly. Same reachability as #1452:
extra={"request_id": ...}→correlation_id.Reproduction
Against
main@8517bf8fb. Threelogger.infocalls through a realStreamHandler, the middle one poisoned:main__str__raises__class____str__raises an exception that itself raisesinfInfinity)nanNaN)1. Forged
__class__— the filter disagrees with the encoderisinstanceconsultsvalue.__class__, which this forges;jsondispatches on the real runtime type. So the value passes theisinstancefilter, reaches the fallback's ownjson.dumps— which onmaincarriesdefault=str, sostr()is called and raises — and the record is gone.Two independent problems in one line: the filter is forgeable, and the fallback dump has
default=str. Either alone would be enough.main:Fix:
type(value) in {str, int, float, bool, type(None)}, and dropdefault=from the fallback dump — nothing may reachdefaulton that path, because reaching it is what reinstates the raising-__str__hole.2. The error reporter is unguarded
{exc}calls the caught exception's own__str__. That exception can originate in a call site's__str__, so it can be an instance of a class whose__str__also raises — and this raise happens inside theexceptblock, where nothing catches it. The record is lost, by the code added to save it.Fix:
Worth noting: all four of the other implementations of #1452 (#1471, #1472, #1477, #1488) had this guard. #1491 is the only one without it, and #1472 shipped a test (
test_exception_whose_str_also_raises_does_not_lose_the_record) that fails onmaintoday.3. Non-finite floats produce invalid JSON
json.dumpsrendersinf/nanas the JavaScript literalsInfinity/NaN, which are not valid JSON. It does not raise, so the record is emitted looking healthy and a strict downstream parser rejects it — the same loss as dropping it, moved to the consumer where it is harder to see.json.loadsaccepts those literals by default, which is why no test here catches it; asserting this needsparse_constant=raising.Fix:
allow_nan=Falseon both dumps, plus amath.isfinitecheck in the scalar filter so the fallback does not re-emit them.Acceptance criteria
__class__value is emitted, not dropped, withlevelauthoritative.__str__raises is emitted, not dropped.inf/-inf/nanin an enrichment produce a record that parses under a strict JSON parser.8517bf8fb._format_jsoncomment states the guarantee the code actually provides — and scopes it to serialization, sincerecord.getMessage()on mismatched%-args still loses the record upstream of the guard (pre-existing, shared with the line-oriented path, out of scope).Provenance
Findings 1 and 2 are #1471's and #1472's, from the four-way collision on #1452 — four sessions implemented that issue inside six minutes with no visibility of each other (comparison). Finding 3 is from a red-team pass on #1477.
#1491 was a fifth implementation and merged; the triage that selected it could not see the cross-PR analysis, which was posted minutes earlier on the other four. The mechanical result is that the merged version is the only one lacking the reporter guard. Filing rather than re-opening anything: #1477 was closed as superseded and stays closed, and no competing PR should be opened against #1452, which is correctly closed. This is a follow-up against what is on
mainnow.I have deliberately not opened a PR for this — the last round produced five for one issue, and a sixth without triage input would repeat exactly that. Happy to implement it on request; the patch is small and the three fixes are independent.