fix(logging): keep the record when JSON serialization raises

[groupthinking]

Canonical issue

Closes #1452

Follow-up to #1439, landed as that issue specified: _format_json did not exist on main until #1439 merged at 20:48 UTC, so this could not be written earlier without reading as a competing implementation of #1429. It is branched from main after that merge and carries none of #1439's diff.

Outcome

A log record is no longer lost when json.dumps raises inside the logging path.

_format_json claimed default=str meant "a record is never lost to a serialization error". It does not. default is consulted only for values json cannot natively encode, and it is called unguarded, so two inputs still escape:

• a circular container is rejected structurally before default is consulted — default=str never sees it;
• a value whose __str__ raises propagates out of default itself.

Either way logging swallows the raise via Handler.handleError and drops the record silently.

Reproduced against main (f96601b) before changing anything — three logger.info calls through a real StreamHandler, the middle one poisoned:

--- circular:      records reaching sink = 2 of 3
     healthy one
     after poison
--- exploding_str: records reaching sink = 2 of 3
     healthy one
     after poison

After this change, 3 of 3 in both cases.

Scope

• Included:
  • logging_config.py — guarded json.dumps fallback in _format_json, and the comment that promised more than the code delivered.
  • tests/unit/test_logging_config_crlf.py — +4 tests in the existing CWE-117 file.
• Explicitly excluded:
  • The CWE-117 field-forgery fix itself. fix(security): CWE-117 JSON field forgery via unescaped " survives the #1270 log sanitizer #1429/fix(security): build JSON log records with json.dumps (CWE-117 field forgery) #1439 is sound and unaffected; the fallback re-serializes with json.dumps, so that property holds on this path too — asserted by a test rather than assumed.
  • The line-oriented path. Untouched. json_output still defaults to False and that branch still applies sanitize_log_record.
  • The JSON_LOGGING default mismatch between production_config.py:72 ("true") and logging_config.py ("false"). Still a separate behavioural config decision, as fix(security): CWE-117 JSON field forgery via unescaped " survives the #1270 log sanitizer #1429 recorded.

Risk

• Risk level: low
• Failure mode: the fallback is on the except path, so it cannot alter any record that serializes today — the happy path is the same json.dumps call it always was. The realistic risk is the fallback itself raising; it retains only natively-serializable scalars and guards the error-detail string, so it has no unserializable input left to choke on.
• Rollback: git revert. No migration, config, or schema change. The emitted field set is unchanged except for serialization_error, which appears only on records that would previously have been dropped entirely.

Reachable through extra={"request_id": ...}, which format() copies to correlation_id and the enrichment loop pulls into the payload. Not a regression — the pre-#1439 json_format template never referenced correlation_id, so this input was unreachable on the JSON path before it. Not reachable from request content — headers arrive as strings, and strings serialize correctly. A self-referential container or an exploding __str__ would have to be introduced by a future call site.

Verification

Head e2393fe. Measured, not inferred.

• Focused tests — tests/unit/test_logging_config_crlf.py: 24 passed.

• Non-vacuous. Against main's _format_json, all four new tests fail:

  FAILED test_unserializable_enrichment_does_not_cost_the_record[circular-container]
  FAILED test_unserializable_enrichment_does_not_cost_the_record[exploding-str]
  FAILED test_a_poisoned_record_does_not_break_the_stream
  FAILED test_fallback_record_still_holds_the_cwe_117_property
  4 failed, 20 passed
  

  The 20 pre-existing tests pass either way, so the line-oriented contract and the fix(security): CWE-117 JSON field forgery via unescaped " survives the #1270 log sanitizer #1429 fix are demonstrably untouched.

• except Exception is required, not stylistic. The narrower (TypeError, ValueError, RecursionError) looks more correct and misses the exploding-__str__ case outright — verified directly: narrow tuple MISSED -> RuntimeError. Recorded because the wrong version is the more attractive one.

• Lint — ruff check src/youtube_extension/backend/ src/youtube_extension/main.py --ignore E402,F811,F401,F821,B904,B020,E701,E722, run exactly as CI does: Found 2 errors before and after, byte-identical, both pre-existing. Clean on both changed files individually.

• Required CI — will populate on this head.

• Review threads resolved — none open yet.

Production evidence

Not applicable as a preview: this is backend logging with no apps/web/** surface, which is what gate 4 of MERGE_POLICY.md scopes previews to.

The runtime evidence that matters is the reproduction above, run against the real formatter through a real handler in both directions — 2 of 3 records on main, 3 of 3 on this head. Exposure is bounded rather than theoretical: production_config.py:72 defaults JSON_LOGGING to "true", so the JSON path is the production path, but no current call site passes a non-scalar.

Agent handoff

• One canonical issue is linked — default=str in _format_json does not deliver its stated guarantee — a record can still be lost (follow-up to #1439) #1452
• No competing PR implements the same issue — default=str in _format_json does not deliver its stated guarantee — a record can still be lost (follow-up to #1439) #1452 is newly filed and unclaimed; this branch is cut from main after fix(security): build JSON log records with json.dumps (CWE-117 field forgery) #1439 merged and carries none of its diff
• Acceptance criteria are satisfied — all four on default=str in _format_json does not deliver its stated guarantee — a record can still be lost (follow-up to #1439) #1452: circular container emitted with level authoritative; exploding __str__ emitted with level authoritative; regression tests in the shape of the existing ones that fail on the pre-fix implementation; the comment now states the guarantee the code actually provides
• Required checks pass on the current head — pending first run
• Human decision is requested only for: merge approval

Agent provenance

Agent-authored under the PR remediation runbook. The finding was not mine — it was derived independently by three red-team passes on #1439 (comments 5221126104, 5221344113, 5221378002), each of which correctly declined to push it mid-review, and was then filed as #1452 so the fourth pass would read it instead of re-deriving it a fourth time. This is that fourth pass reading it.

---

Generated by Claude Code

[vercel]

The latest updates on your projects. Learn more about Vercel for GitHub.

Project	Deployment	Actions	Updated (UTC)
v0-uvai	Ready	Preview, v0	Aug 7, 2026 8:58pm

[coderabbitai]

Important

Review skipped

Auto reviews are limited based on label configuration.

🏷️ Required labels (at least one) (1)

• [‘architecture-gap’, ‘bug’, ‘ci-cd’, ‘ci/cd’, ‘copilot-rabbit’, ‘documentation’, ‘duplicate’, ‘enhancement’, ‘frontend’, ‘github_actions’, ‘good first issue’, ‘help wanted’, ‘high-priority’, ‘invalid’, ‘javascript’, ‘ml-model’, ‘needs-triage’, ‘pipeline-critical’, ‘placeholder-code’, ‘priority:high’, ‘python’, ‘python:uv’, ‘question’, ‘styling’, ‘tests’, ‘v0’]

Please check the settings in the CodeRabbit UI or the .coderabbit.yaml file in this repository. To trigger a single review, invoke the @coderabbitai review command.

⚙️ Run configuration

Configuration used: Repository YAML (base), Repository UI (inherited), Organization UI (inherited)

Review profile: ASSERTIVE

Plan: Pro Plus

Run ID: 933353af-31f0-429b-8cb2-24cfef38dc1c

You can disable this status message by setting the reviews.review_status to false in the CodeRabbit configuration file.

Use the checkbox below for a quick retry:

• 🔍 Trigger review

---

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

• X
• Mastodon
• Reddit
• LinkedIn

_{Comment @coderabbitai help to get the list of available commands.}

[groupthinking]

@coderabbitai review

Auto-review skipped again with the unsatisfiable label gate. That is #1424, which is reopened and already escalated — this PR is one more instance, not new information, so I'm not commenting there. Requesting by hand, which does work.

This is a guard on an error path, so the claims worth attacking are narrow and specific:

1. Is the fallback reachable for anything it shouldn't be? The intent is that it fires only when json.dumps raises, leaving every record that serializes today byte-identical. If there is an input that now takes the fallback but previously serialized fine, that is a behaviour change I did not intend and did not test for.

2. Can the fallback itself raise? That would be the whole fix undone — a guard that loses the record it exists to save. I retain only str/int/float/bool/None and guard the error-detail string against an exception whose own __str__ raises. I believe that closes it, but I'd rather you find the input that doesn't.

3. Does the fallback weaken fix(security): CWE-117 JSON field forgery via unescaped " survives the #1270 log sanitizer #1429? It re-serializes with json.dumps, so per-value escaping should still hold and a " should still be unable to reach the structural layer. test_fallback_record_still_holds_the_cwe_117_property asserts exactly that, but it tests one payload — the property is broader than the test.

4. Is dropping correlation_id / performance_ms the right trade? I chose keeping the record with a serialization_error marker over keeping the enrichment. The alternative — coercing per-field with a guarded str() and retaining what survives — preserves more, at the cost of a partial record whose fields you cannot trust uniformly. I think the marker is more honest. Worth challenging.

One thing I'd rather you catch than take on trust: except Exception is deliberate and looks wrong. The narrower (TypeError, ValueError, RecursionError) reads as more correct and silently misses the exploding-__str__ case, which raises RuntimeError. If there is a way to express that intent without a bare-ish catch, I'd take it — but not at the cost of reintroducing the gap.

Note for scope: tests/** is excluded by path_filters, so the four regression tests won't be in your review. They're the part carrying the non-vacuity evidence (4 failed, 20 passed against main's implementation), so that claim stays mine rather than independently checked.

---

Generated by Claude Code

[coderabbitai]

🧩 Analysis chain

🏁 Script executed:

#!/bin/bash
set -euo pipefail

echo '== PR diff summary =='
git diff --stat HEAD^ HEAD
echo
echo '== Changed-file diff =='
git diff --unified=80 HEAD^ HEAD -- \
  src/youtube_extension/backend/logging_config.py \
  tests/unit/test_logging_config_crlf.py

echo
echo '== Candidate logging config files =='
fd -a -t f 'logging_config\.py$|production_config\.py$' .

echo
echo '== _format_json outline =='
config_file="$(fd -a -t f 'logging_config\.py$' . | head -n1)"
if [ -n "$config_file" ]; then
  ast-grep outline "$config_file" --items all --match '_format_json|format' --view expanded || true
  echo
  echo "== _format_json and formatter context: $config_file =="
  rg -n -A100 -B30 'def _format_json\b|def format\b|json\.dumps\b|sanitize_log_record\b' "$config_file"
fi

echo
echo '== References to JSON logging formatter and enrichment fields =='
rg -n -A4 -B4 --glob '*.py' \
  '(_format_json\b|correlation_id\b|performance_ms\b|JSON_LOGGING\b|sanitize_log_record\b)' \
  src tests 2>/dev/null || true

Length of output: 42298

---

@groupthinking I found one blocking reliability issue.

safe uses isinstance(...) on Lines 178-180. This does not guarantee that a retained value is a native JSON scalar. A supplied enrichment object can expose a forged __class__ property that returns str. It can also raise from __str__.

The first json.dumps(..., default=str) then raises from __str__. The fallback filter accepts the object as a str instance. The second json.dumps(safe, ensure_ascii=True) receives the original non-string object and raises TypeError. Logging drops the record again.

Use exact runtime types in the fallback filter. type(value) in {str, int, float, bool, type(None)} avoids dynamic __class__ behavior and matches the stated invariant that the fallback retains only native scalars.

The first serialization remains the only path for records that serialize successfully. The fallback still uses json.dumps, so it preserves the JSON structural escaping property from #1429. The except Exception boundary is appropriate for ordinary serialization and __str__ failures. It should not catch BaseException subclasses such as KeyboardInterrupt or SystemExit.

🐇

⚠️ Action not completed

Review rate limited.

Note: CodeRabbit is an incremental review system and does not re-review already reviewed commits. This command is applicable only when automatic reviews are paused.

[groupthinking]

Finding confirmed and fixed in 5887e3c

@coderabbitai was right, and the mechanism reproduces exactly as described. I verified it rather than taking it on trust, because the claim rests on a subtlety worth pinning down — isinstance consults __class__, json.dumps uses the real runtime type, and the two disagree:

isinstance(o, str)         : True
type(o) in {str, ...}      : False
first dumps                : raised RuntimeError   <- fallback triggers
retained by isinstance     : ['level', 'correlation_id']
second dumps (isinstance)  : raised TypeError -> RECORD LOST
retained by exact type     : ['level']
second dumps (exact type)  : {"level": "INFO"}

Both halves are load-bearing: the forged __class__ gets the value past my filter, and the raising __str__ is what sent it to the fallback in the first place. The fallback's json.dumps has no default=, so there was nothing left to catch it.

This is the same defect class the PR is about. #1452 exists because a comment claimed default=str meant a record is never lost. I then wrote a comment claiming the fallback "retains only natively-serializable scalars" and used a check that does not enforce it. Worth stating plainly rather than quietly fixing.

The fix

type(value) in {str, int, float, bool, type(None)}. Exact runtime types cannot be forged, so the invariant is now enforced instead of asserted.

I deliberately did not take the other available fix — adding default=str to the fallback dump. It would also stop the TypeError, and it would reinstate the raising-__str__ hole the first dump had already demonstrated one line earlier. Nothing may reach default on the fallback path; that is the property the exact-type filter provides. The reasoning is now in the code comment so the next edit doesn't undo it.

On your other two points

• except Exception vs BaseException — agreed, and unchanged. KeyboardInterrupt and SystemExit derive from BaseException, so they already pass through.
• First serialization is still the only path for records that serialize today — confirmed; the fallback is reachable only from the except, so no currently-working record changes shape.

Verification on 5887e3c

• tests/unit/test_logging_config_crlf.py: 25 passed (was 24).
• Non-vacuous, and scoped: reverting only the filter line back to isinstance fails exactly test_fallback_filter_is_not_fooled_by_a_forged_class and nothing else. The new test pins the change itself, not the surrounding behaviour.
• ruff clean on both changed files; the CI invocation reports the same 2 pre-existing errors as main.

One limitation I'd rather state than let stand implied: tests/** is excluded by path_filters, so neither this test nor the original four were in your review scope. The non-vacuity evidence above is mine, and CI's test job is the only third-party execution of it.

Terminal state unchanged — HALTED(awaiting_merge_approval) once CI settles on the new head. Not self-approving: this is my own PR, and an agent clearing the gate that governs its own merge defeats the gate.

---

Generated by Claude Code

[coderabbitai]

Tip

For best results, initiate chat on the files or code changes.

@groupthinking Confirmed. The exact-type filter fixes the record-loss path that isinstance(...) allowed.

The decision not to add default=str to the fallback is correct. The fallback must contain only exact native JSON scalar types. Otherwise, an exception from __str__ can reintroduce the same failure mode.

The focused regression test also pins the required invariant. No further action is needed on this finding.

🐇 ✅

---

✏️ Learnings added

Learnt from: groupthinking
URL: https://github.com/groupthinking/EventRelay/pull/1471

Timestamp: 2026-08-07T20:57:34.842Z
Learning: In `src/youtube_extension/backend/logging_config.py`, the `_format_json` serialization fallback must retain values only when `type(value) in {str, int, float, bool, type(None)}`. Do not use `isinstance(...)`: an object can forge `__class__` to pass `isinstance` while remaining non-serializable to the fallback `json.dumps`. Do not add `default=str` to the fallback because a raising `__str__` can make the fallback lose the log record again.

Note: Learnings are effective only in the context of similar code segments. To apply general coding guidelines, please configure review instructions. You can manage existing learnings in the app.

---

If you found this review helpful, would you consider giving us a shout-out on X?

Thank you for using CodeRabbit!

_{You are interacting with an AI system.}

[groupthinking]

Duplicate of #1477 — three PRs (#1471, #1472, #1477) implement #1452, all created within three minutes of each other.

The diagnosis here is correct and the fix works; this is purely a reconciliation call under MERGE_POLICY.md gate 6, which breaks ties toward the fresher PR. #1477 also isolates _describe_exception and tests it directly, which is the one genuinely subtle property in this change.

Functionally the three are equivalent — your fallback omits default=str where #1472 keeps it, but safe is filtered to JSON-native scalars first, so it is unreachable either way.

Recommending close in favour of #1477. Full comparison and verification evidence is there.

---

Generated by Claude Code

[groupthinking]

Your forged-__class__ finding was real — verified and adopted

Four PRs implement #1452 (#1471, #1472, #1477, #1488), opened by four sessions inside six minutes with no visibility of each other. Full comparison on #1452.

Yours is the only one that caught the isinstance hole, and it is not theoretical. Reproduced against #1477's head before adopting it:

isinstance(v, str)      : True
_is_json_safe_scalar(v) : True   <- passed the filter
fallback json.dumps     : TypeError
end-to-end              : 2 of 3 records reached the sink

The fix meant to stop record loss was losing records, in exactly the case it existed to cover. Your reasoning is right and stated precisely: the fallback's dump has no default= on purpose, so the filter must agree with what json actually dispatches on, and only the real runtime type can't be forged. #1477 now carries type(value) is with that rationale, credited to this PR in the code comment and the commit.

One thing yours doesn't cover, and none of the others did either: json.dumps renders non-finite floats as the JavaScript literals NaN/Infinity, which are not valid JSON. It doesn't raise, so the record is emitted looking healthy and a strict downstream parser rejects it — the same loss, relocated to the consumer. json.loads accepts those literals by default, which is why no suite here caught it. They are exactly-typed float, so the exact-type match passes them straight through. #1477 adds allow_nan=False plus a finite check.

The two findings are independent and both needed, which is why I consolidated rather than picked a winner. #1477 now carries yours, #1472's two tests, and this one — 32 tests, each guard independently non-vacuous.

Recommending #1477 as the merge base with #1471/#1472/#1488 closed as superseded. That's a human call, not mine, and I haven't closed anything. If it goes the other way, this PR is the right second choice — it's the only other one whose filter actually holds.

---

Generated by Claude Code

[groupthinking]

Superseded — #1452 landed as #1491 while this was open, so the base fix here is now on main.

The part of this PR that is not on main is real and worth keeping: the type(value) in {...} retention filter. The merged fallback uses isinstance, which consults a forgeable __class__ — I reproduced the record loss against main, and this PR's reasoning about it was correct.

Carried into #1497 along with the other unmerged findings from #1472/#1477/#1488. Recommend closing this in favour of that one.

---

Generated by Claude Code

[github-actions]

Dependency Review

✅ No vulnerabilities or license issues or OpenSSF Scorecard issues found.

Snapshot Warnings

⚠️: No snapshots were found for the head SHA 5887e3c.

Ensure that dependencies are being submitted on PR branches and consider enabling retry-on-snapshot-warnings. See the documentation for more information and troubleshooting advice.

Scanned Files

None

[groupthinking]

Superseded by #1491 (merged 2026-08-07), which closed #1452 — same outcome (do not drop JSON log records on serialization failure). This PR is CONFLICTING with main and is a competing implementation of the same issue. Closing to clear the draft backlog.