Skip to content

default=str in _format_json does not deliver its stated guarantee — a record can still be lost (follow-up to #1439) #1452

Description

@groupthinking

Summary

On PR #1439 (fix(security): build JSON log records with json.dumps), the _format_json return carries this comment:

# `default=str` keeps a non-serializable `extra` value from raising
# inside the logging path, where an exception would be swallowed and
# the record lost entirely.
return json.dumps(payload, ensure_ascii=True, default=str)

The PR body repeats it: "a non-serializable extra value raising inside the logging path, is handled with default=str so a record is never lost to a serialization error."

Both statements are false in two cases. default is consulted only for values json cannot natively encode, and it is called unguarded.

Reproduction

Verified against claude/clever-heisenberg-s5uqf5 @ 4d891f9.

1. Circular container — default is never consulted at all.

called = []
def d(o):
    called.append(type(o).__name__); return str(o)

circ = {}; circ['self'] = circ
json.dumps({'level': 'INFO', 'correlation_id': circ}, default=d)
ValueError: Circular reference detected | default consulted: []

json.dumps detects the cycle structurally and rejects it before reaching default.

2. A value whose __str__ raises — default is consulted, and the exception propagates out of it.

class Boom:
    def __str__(self): raise RuntimeError('str() exploded')

json.dumps({'level': 'INFO', 'correlation_id': Boom()}, default=str)
RuntimeError: str() exploded

The record is genuinely lost, which is the specific outcome the comment says is prevented. Three logger.info calls through a real StreamHandler, the middle one poisoned:

records reaching sink: 2 of 3
   {"level": "INFO", "message": "healthy one"}
   {"level": "INFO", "message": "after poison"}

logging swallows the raise via Handler.handleError and drops the record.

Reachability

Not a regression, and not reachable from request content.

  • The pre-fix(security): build JSON log records with json.dumps (CWE-117 field forgery) #1439 json_format template referenced only timestamp/service/version/level/logger/message/module/line/function. It never referenced correlation_id or performance_ms, so this input was unreachable on the JSON path before that PR. Reading those two fields in the enrichment loop is what makes it reachable.
  • Every live call site passes a scalar: correlation_id comes from record.request_id and from header values in middleware/metrics.py, both strings; the extra={...} sites in shared/run_validation.py, services/ai/speech_to_text_service.py and services/workflows/transcript_action_workflow.py pass str/int.
  • An attacker-supplied header is a string, and strings are escaped correctly. A self-referential container or an exploding __str__ would have to be introduced by a future call site.

Severity: low. The CWE-117 field-forgery fix that #1429/#1439 is about is sound and unaffected — this is a robustness gap plus an inaccurate claim, not a vulnerability.

Why this is filed rather than fixed in place

Three separate red-team passes on #1439 (comments 5221126104, 5221344113, 5221378002) each independently derived this finding and each declined to push it — reasonably, since folding a commit in would reset that PR's green CI, and a branch carrying #1439's diff would read as a competing implementation of #1429 that PR Governance rejects by construction.

The result is that the finding has been re-derived three times and tracked zero times. That is the same waste #1398 records for #1171. This issue exists so the fourth pass reads it instead of re-deriving it.

Suggested fix

Either make the claim true, or narrow it. If fixing:

-        return json.dumps(payload, ensure_ascii=True, default=str)
+        try:
+            return json.dumps(payload, ensure_ascii=True, default=str)
+        except Exception as exc:  # noqa: BLE001 - never lose a record
+            # `default=str` is not sufficient alone: a circular container raises
+            # before `default` is consulted, and a value whose __str__ raises
+            # propagates out of `default` itself. Drop the optional enrichments
+            # and keep the record.
+            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)

except Exception deliberately, not a narrow tuple — (TypeError, ValueError, RecursionError) looks more correct but the exploding-__str__ case walks straight through it.

Acceptance criteria

  1. A record with a circular container in correlation_id/performance_ms is still emitted, with level authoritative.
  2. A record with a value whose __str__ raises is still emitted, with level authoritative.
  3. A regression test in the shape of the existing ones in tests/unit/test_logging_config_crlf.py covers both, and fails on the pre-fix implementation.
  4. The _format_json comment and fix(security): build JSON log records with json.dumps (CWE-117 field forgery) #1439's Risk section state the guarantee the code actually provides.

Sequencing

_format_json does not exist on main — it arrives with #1439. This is a follow-up to be landed after #1439 merges, or folded into #1439 before merge if the reviewer prefers to close it there. It should not be implemented as a competing PR against #1429.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions