From b393c8fc4df7690540bc7b2decce6019337cf52d Mon Sep 17 00:00:00 2001 From: Claude Date: Sun, 2 Aug 2026 19:30:03 +0000 Subject: [PATCH 1/2] fix(security): neutralize CR/LF in rendered log records (CWE-117) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit StructuredFormatter only prepended an "Exception Details:" header and never stripped line separators, so any exc_info=True / logger.exception(...) sink — and structured `extra` fields the format references — could forge, corrupt, or split downstream log lines with attacker-controlled separators, even where the message itself was sanitized inline. This central fix escapes every str.splitlines() boundary (LF, CR, VT, FF, FS, GS, RS, NEL, LS, PS) plus ESC in the FINAL rendered record, covering every sink at once without touching call sites. Escapes are emitted as JSON-valid \uXXXX sequences so JSON logging (enable_json_logging=True) stays parseable, and backslash is escaped first so the transform is unambiguous and reversible. Adds tests/unit/test_logging_config_crlf.py asserting against rendered handler output (message, exc_info traceback, logger.exception, extra fields), JSON-log parseability, reversibility, and full splitlines-boundary coverage. Co-Authored-By: Claude Opus 4.8 (1M context) Claude-Session: https://claude.ai/code/session_01AFJ9na5UBaskoD4eAe1fhq --- .../backend/config/logging_config.py | 49 ++++- tests/unit/test_logging_config_crlf.py | 167 ++++++++++++++++++ 2 files changed, 215 insertions(+), 1 deletion(-) create mode 100644 tests/unit/test_logging_config_crlf.py diff --git a/src/youtube_extension/backend/config/logging_config.py b/src/youtube_extension/backend/config/logging_config.py index 98f28489e..3d061dd92 100644 --- a/src/youtube_extension/backend/config/logging_config.py +++ b/src/youtube_extension/backend/config/logging_config.py @@ -14,6 +14,49 @@ from datetime import datetime from pathlib import Path +# Characters that can be abused to forge or corrupt log records (CWE-117 log +# injection). Any of these in dynamic content — a log message, an ``exc_info`` +# traceback, ``str(exc)``, or a structured ``extra`` field — could otherwise +# inject what looks like an independent log line, or (for JSON logs) break the +# record so downstream parsers drop or corrupt it. +# +# The set is the union of every separator ``str.splitlines()`` recognizes as a +# line boundary (LF, CR, VT, FF, FS, GS, RS, NEL, LS, PS) plus ESC (terminal +# control sequences). Each is escaped to a JSON-valid ``\uXXXX`` sequence — not +# a Python ``\v``/``\x1b`` shorthand — so the neutralized record stays valid +# JSON when ``enable_json_logging`` is on, while remaining a single physical +# line for line-oriented sinks. +# +# Backslash is escaped FIRST (see ``sanitize_log_record``) so the encoding is +# unambiguous and reversible: a real newline becomes a backslash-u-000a escape, +# while a literal backslash in the source is doubled, so the two never collide +# and the original text can be recovered by reversing the table. +_UNSAFE_LOG_CHARS = { + ord("\\"): "\\\\", + ord("\n"): "\\u000a", + ord("\r"): "\\u000d", + ord("\v"): "\\u000b", # VT / 0x0B + ord("\f"): "\\u000c", # FF / 0x0C + ord("\x1b"): "\\u001b", # ESC — terminal control / escape sequences + ord("\x1c"): "\\u001c", # FS — file separator + ord("\x1d"): "\\u001d", # GS — group separator + ord("\x1e"): "\\u001e", # RS — record separator + 0x85: "\\u0085", # NEL — Unicode next line + 0x2028: "\\u2028", # LINE SEPARATOR + 0x2029: "\\u2029", # PARAGRAPH SEPARATOR +} + + +def sanitize_log_record(rendered: str) -> str: + """Neutralize line/record separators in a fully-rendered log record. + + Escapes CR/LF (and every other line separator, plus ESC) to JSON-valid + ``\\uXXXX`` sequences so attacker-controlled content cannot forge, corrupt, + or split downstream log lines — including JSON logs (CWE-117). Backslash is + escaped first, so the transform is unambiguous and reversible. + """ + return rendered.translate(_UNSAFE_LOG_CHARS) + class StructuredFormatter(logging.Formatter): """ @@ -39,7 +82,11 @@ def format(self, record: logging.LogRecord) -> str: # Format the base message formatted_message = super().format(record) - return formatted_message + # CWE-117: neutralize line/record separators in the FINAL rendered + # record so message text, exc_info tracebacks, and any structured + # `extra` fields cannot forge, corrupt, or split downstream log lines + # even when inline sanitization was not applied at the call site. + return sanitize_log_record(formatted_message) def formatException(self, ei) -> str: """Format exception with enhanced stack trace""" diff --git a/tests/unit/test_logging_config_crlf.py b/tests/unit/test_logging_config_crlf.py new file mode 100644 index 000000000..0dc17d72c --- /dev/null +++ b/tests/unit/test_logging_config_crlf.py @@ -0,0 +1,167 @@ +"""CWE-117 regression tests for StructuredFormatter log-injection hardening. + +These assert against the *rendered* handler output (not the return value of an +inline sanitizer), because the vulnerability lived in the paths that inline +sanitization does not cover: `logger.error(..., exc_info=True)`, +`logger.exception(...)`, and structured `extra` fields whose text is appended +to the record by the formatter/framework rather than the message string. +""" + +from __future__ import annotations + +import io +import json +import logging +import sys +from pathlib import Path + +import pytest + +sys.path.insert(0, str(Path(__file__).resolve().parents[2] / "src")) + +from youtube_extension.backend.config.logging_config import ( # noqa: E402 + _UNSAFE_LOG_CHARS, + StructuredFormatter, + sanitize_log_record, +) + +pytestmark = [pytest.mark.unit, pytest.mark.security] + +# A format that mirrors a realistic record: a level/message prefix an attacker +# would try to forge a second, fake copy of. +_FMT = "%(levelname)s - %(message)s" + +# The JSON format used by the module in production (`enable_json_logging=True`). +_JSON_FMT = '{"level": "%(levelname)s", "message": "%(message)s", "logger": "%(name)s"}' + + +def _make_logger(name: str, fmt: str = _FMT) -> tuple[logging.Logger, io.StringIO]: + buf = io.StringIO() + handler = logging.StreamHandler(buf) + handler.setFormatter(StructuredFormatter(fmt)) + logger = logging.getLogger(name) + logger.handlers[:] = [handler] + logger.setLevel(logging.DEBUG) + logger.propagate = False + return logger, buf + + +def _forged_line_present(rendered: str) -> bool: + """A forged line is any line *after* the first that looks like its own record.""" + tail = rendered.split("\n", 1)[1] if "\n" in rendered else "" + return "FORGED ADMIN LINE" in tail + + +def test_message_crlf_cannot_forge_a_new_line(): + logger, buf = _make_logger("crlf-message") + logger.info("user said: %s", "hello\r\nCRITICAL - FORGED ADMIN LINE") + out = buf.getvalue() + + assert "\r" not in out + # Exactly one physical line (plus the trailing newline the handler adds). + assert out.count("\n") == 1 + assert not _forged_line_present(out) + # The payload is preserved, just neutralized to JSON-valid escapes. + assert "\\u000d\\u000aCRITICAL - FORGED ADMIN LINE" in out + + +def test_exc_info_traceback_cannot_forge_log_lines(): + logger, buf = _make_logger("crlf-excinfo") + try: + raise ValueError("boom\r\nCRITICAL - FORGED ADMIN LINE") + except ValueError: + logger.error("Error in chat endpoint", exc_info=True) + out = buf.getvalue() + + assert "\r" not in out + # The entire record — message + multi-line traceback — is one physical line. + assert out.count("\n") == 1 + assert not _forged_line_present(out) + # Traceback content is retained in escaped form (still debuggable). + assert "Exception Details:" in out + assert "ValueError" in out + + +def test_logger_exception_helper_is_also_covered(): + logger, buf = _make_logger("crlf-exception-helper") + try: + raise RuntimeError("nope\nERROR - FORGED ADMIN LINE") + except RuntimeError: + logger.exception("handler failed") + out = buf.getvalue() + + assert out.endswith("\n") # only the handler's trailing newline + assert out.count("\n") == 1 # single physical record — no injected line + assert not _forged_line_present(out) + + +def test_extra_fields_referenced_by_format_are_sanitized(): + logger, buf = _make_logger( + "crlf-extra", "%(levelname)s - %(message)s - url=%(video_url)s" + ) + logger.error( + "bad request", + extra={"video_url": "http://x/\r\nCRITICAL - FORGED ADMIN LINE"}, + ) + out = buf.getvalue() + + assert "\r" not in out + assert out.count("\n") == 1 + assert not _forged_line_present(out) + + +def test_all_splitlines_boundaries_are_escaped(): + # Every character str.splitlines() treats as a line boundary must be + # neutralized, or a downstream reader that uses splitlines() could still be + # tricked into seeing multiple records. + payload = "".join(chr(c) for c in _UNSAFE_LOG_CHARS if c != ord("\\")) + assert len(payload.splitlines()) > 1 # sanity: these really are boundaries + cleaned = sanitize_log_record(payload) + assert cleaned.splitlines() == [cleaned] # collapses to a single line + + +def test_json_logging_output_stays_parseable(): + # With enable_json_logging=True the record is interpolated into a JSON + # string; the escapes must be JSON-valid so an attacker cannot corrupt or + # drop downstream JSON logs. + logger, buf = _make_logger("crlf-json", _JSON_FMT) + nasty = "line1\r\nline2\x1b[31m\x0bvt\x1crs" + logger.info("%s", nasty) + out = buf.getvalue().strip() + + parsed = json.loads(out) # must not raise + assert parsed["level"] == "INFO" + # Round-trips back to the original text: the escapes are lossless. + assert parsed["message"] == nasty + + +def test_encoding_is_reversible(): + # A real separator and a literal backslash-escape of it must not collide. + real_newline = "a\nb" + literal_text = "a\\nb" # the two characters backslash + n + assert sanitize_log_record(real_newline) != sanitize_log_record(literal_text) + # Backslash is doubled, so the mapping can be inverted unambiguously. + assert sanitize_log_record(literal_text) == "a\\\\nb" + assert sanitize_log_record(real_newline) == "a\\u000ab" + + +def test_benign_records_are_unchanged(): + logger, buf = _make_logger("crlf-benign") + logger.info("all good %s", "video-123") + out = buf.getvalue() + assert out == "INFO - all good video-123\n" + + +def test_sanitize_log_record_escapes_each_separator_to_json_unicode(): + # Build the input from the table itself so no raw separator is typed by hand + # (which is easy to get wrong for U+2028 / U+2029). + specials = {c: repl for c, repl in _UNSAFE_LOG_CHARS.items() if c != ord("\\")} + raw = "".join(chr(c) for c in specials) + cleaned = sanitize_log_record(raw) + + assert cleaned == "".join(specials[c] for c in specials) + for c in specials: + assert chr(c) not in cleaned # nothing raw remains + # The escaped blob is a JSON-valid string body that decodes losslessly back + # to the original characters (raw has no backslash, so no ambiguity). + assert json.loads(f'"{cleaned}"') == raw From a63014292e35d83231ba8dc5ea396883825575cd Mon Sep 17 00:00:00 2001 From: Claude Date: Fri, 7 Aug 2026 18:02:34 +0000 Subject: [PATCH 2/2] fix(ci): stop the canonical-evidence gate failing Dependabot by construction MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `Canonical issue and evidence` requires five prose sections and exactly one `Closes #` reference in the PR body. Dependabot composes its body from a fixed template and can emit none of them, so the gate named an action the author could not take and failed permanently. PR #1171 is the live proof: it is the only non-draft Dependabot PR open, and its governance run fails with exactly the five-section error. The other three (#1000, #1173, #1176) are drafts and take the existing draft escape; each goes permanently red the moment it is marked ready for review. The sibling truth gate in pr-checks.yml already carried `login !== 'dependabot[bot]'`, and justified deferring by asserting that the canonical requirement is one "an author can actually meet". That was false for Dependabot, so the exemption relocated the constraint instead of removing it. Both halves are fixed here: pr-governance.yml gains the matching escape, and the stale rationale comment is corrected. The escape reports `neutral`, not `success` — the contract is not applicable, not satisfied. Reporting it satisfied would be the same false signal this check exists to catch. Dependency PRs stay gated by dependency-review, npm-audit, trivy, build and test; only the PR-body prose contract is waived. Tests execute the real script under Node against synthetic payloads rather than matching strings in its source. Verified non-vacuous: the Dependabot case fails against the pre-fix workflow and passes after, with the other 13 unchanged. Human authors and other bots posting an identical template-less body still fail, so the exemption is keyed on author rather than body shape. Closes #1419 Co-Authored-By: Claude Opus 5 Claude-Session: https://claude.ai/code/session_01GGBZnk7MiKZR83NFb3QoWQ --- .github/workflows/pr-checks.yml | 22 ++- .github/workflows/pr-governance.yml | 27 +++ tests/unit/test_pr_governance_workflow.py | 194 ++++++++++++++++++++++ 3 files changed, 239 insertions(+), 4 deletions(-) diff --git a/.github/workflows/pr-checks.yml b/.github/workflows/pr-checks.yml index 8f5dec4fe..7cbfb2724 100644 --- a/.github/workflows/pr-checks.yml +++ b/.github/workflows/pr-checks.yml @@ -719,8 +719,15 @@ jobs: // hatch: a pull request that links a dispatched issue is still // fully gated, and requiring a pull request to bind to a focused // issue at all is separately owned by `Canonical issue and - // evidence`, which states a requirement an author can actually - // meet. + // evidence`. + // + // That hand-off holds for human and agent authors, who can write + // the contract. It did not hold for `dependabot[bot]`, whose body + // is template-generated: deferring here sent it to a sibling gate + // it could not clear either, which relocated the constraint + // rather than removing it. `pr-governance.yml` now reports + // `not_applicable` for the same author set, so the deferral + // resolves. See #1419. return login !== 'dependabot[bot]' && (issueDispatch || (pullProvenance && Boolean(selectedIssue))); } @@ -2045,8 +2052,15 @@ jobs: // hatch: a pull request that links a dispatched issue is still // fully gated, and requiring a pull request to bind to a focused // issue at all is separately owned by `Canonical issue and - // evidence`, which states a requirement an author can actually - // meet. + // evidence`. + // + // That hand-off holds for human and agent authors, who can write + // the contract. It did not hold for `dependabot[bot]`, whose body + // is template-generated: deferring here sent it to a sibling gate + // it could not clear either, which relocated the constraint + // rather than removing it. `pr-governance.yml` now reports + // `not_applicable` for the same author set, so the deferral + // resolves. See #1419. return login !== 'dependabot[bot]' && (issueDispatch || (pullProvenance && Boolean(selectedIssue))); } diff --git a/.github/workflows/pr-governance.yml b/.github/workflows/pr-governance.yml index e368adeb4..7cce19487 100644 --- a/.github/workflows/pr-governance.yml +++ b/.github/workflows/pr-governance.yml @@ -55,6 +55,33 @@ jobs: return; } + // Dependabot composes its body from a fixed template (release + // notes, changelog, commit list). It cannot emit the five required + // headings or a `Closes #` reference, so the contract below + // is not a bar it fails -- it is one it has no way to clear. The + // sibling truth gate already defers for the same reason + // (`pr-checks.yml`, `login !== 'dependabot[bot]'`); this keeps the + // two consistent instead of relocating the constraint. + // + // `neutral`, not `success`: the contract is not applicable here, + // and reporting it as satisfied would be the same false signal this + // check exists to catch. Dependency PRs remain gated by + // `dependency-review`, `npm-audit`, `trivy`, `build` and `test`. + const AUTOMATED_DEPENDENCY_AUTHORS = new Set([ + "dependabot[bot]" + ]); + const prAuthor = (pr.user && pr.user.login) || ""; + if (AUTOMATED_DEPENDENCY_AUTHORS.has(prAuthor)) { + await publish( + "neutral", + "Governance not applicable to automated dependency PR", + `PR #${pr.number} is authored by ${prAuthor}, which cannot ` + + `author a canonical delivery contract. The Check is bound to ` + + `exact head ${pr.head.sha}.` + ); + return; + } + const body = pr.body || ""; function getSectionContent(text, heading) { diff --git a/tests/unit/test_pr_governance_workflow.py b/tests/unit/test_pr_governance_workflow.py index 216561e8c..a705ea37e 100644 --- a/tests/unit/test_pr_governance_workflow.py +++ b/tests/unit/test_pr_governance_workflow.py @@ -1,7 +1,12 @@ from __future__ import annotations +import json +import shutil +import subprocess +import textwrap from pathlib import Path +import pytest import yaml WORKFLOW_PATH = Path(__file__).resolve().parents[2] / ".github/workflows/pr-governance.yml" @@ -97,3 +102,192 @@ def test_governance_workflow_checks_issue_before_competitors() -> None: assert script.index("github.rest.issues.get") < script.index( "github.rest.pulls.list" ) + + +# -------------------------------------------------------------------------- +# Behavioural tests (#1419). +# +# The assertions above match strings in the script source, so they stay green +# even if the logic inverts. These run the real script under Node against +# synthetic payloads and assert on the conclusion it publishes. +# -------------------------------------------------------------------------- + +CONTRACT_BODY = """## Canonical issue + +Closes #1419 + +## Outcome + +Real outcome text. + +## Risk + +- Risk level: low +- Failure mode: none observed +- Rollback: git revert + +## Verification + +Ran the focused suite. + +## Production evidence + +Not applicable - workflow-only change. +""" + +# Shape of a real Dependabot body: release notes and a commit list, none of +# the five required headings, no closing reference. Dependabot composes this +# from a fixed template and cannot be made to emit the contract. +DEPENDABOT_BODY = """Bumps [github/gh-aw-actions/setup](https://github.com/github/gh-aw-actions) from 0.82.14 to 0.84.2. + +Release notes +

Sourced from setup's releases.

+Commits +
  • fd783ac chore: sync actions from gh-aw@v0.84.2
+""" + +_DRIVER = """ +const fs = require('fs'); +const source = fs.readFileSync(process.argv[2], 'utf8'); +const pr = JSON.parse(process.argv[3]); + +(async () => { + const published = []; + const context = { + payload: { pull_request: pr }, + repo: { owner: 'groupthinking', repo: 'EventRelay' }, + runId: 1, + serverUrl: 'https://github.com', + }; + const core = { setFailed: () => {} }; + const github = { + rest: { + checks: { create: async (args) => { published.push(args); } }, + // Canonical issue resolves to a real, open, non-PR issue. + issues: { get: async () => ({ data: { number: 1419, state: 'open' } }) }, + pulls: { list: 'list' }, + }, + paginate: async () => [], // no competing PRs + }; + const fn = new Function( + 'context', 'core', 'github', + `return (async () => {${source}})();` + ); + await fn(context, core, github); + process.stdout.write(JSON.stringify({ + conclusion: published[0] && published[0].conclusion, + title: published[0] && published[0].output && published[0].output.title, + })); +})(); +""" + + +def _run_gate(tmp_path: Path, pull_request: dict) -> dict: + """Execute the real governance script against a synthetic PR payload.""" + script = _get_script(_load_workflow()) + source_path = tmp_path / "gov_source.js" + source_path.write_text(script) + driver_path = tmp_path / "driver.js" + driver_path.write_text(textwrap.dedent(_DRIVER)) + + result = subprocess.run( + ["node", str(driver_path), str(source_path), json.dumps(pull_request)], + capture_output=True, + text=True, + timeout=60, + check=False, + ) + assert result.returncode == 0, f"driver failed: {result.stderr}" + return json.loads(result.stdout) + + +requires_node = pytest.mark.skipif( + shutil.which("node") is None, reason="node is required to execute the gate" +) + + +@requires_node +def test_gate_is_not_applicable_to_dependabot(tmp_path: Path) -> None: + """Dependabot cannot author the contract, so the gate must not fail it. + + Regression guard for #1419: PR #1171 was permanently red on this check. + """ + verdict = _run_gate( + tmp_path, + { + "number": 1171, + "draft": False, + "user": {"login": "dependabot[bot]"}, + "body": DEPENDABOT_BODY, + "head": {"sha": "bfb1bb7"}, + }, + ) + assert verdict["conclusion"] == "neutral" + # "neutral", not "success": the contract is not applicable, not satisfied. + assert "not applicable" in verdict["title"].lower() + + +@requires_node +def test_gate_still_fails_a_human_with_the_same_body(tmp_path: Path) -> None: + """The exemption is keyed on author, not on body shape. + + Without this, a fix that simply stopped requiring the sections would also + pass test_gate_is_not_applicable_to_dependabot. + """ + verdict = _run_gate( + tmp_path, + { + "number": 9001, + "draft": False, + "user": {"login": "groupthinking"}, + "body": DEPENDABOT_BODY, + "head": {"sha": "deadbee"}, + }, + ) + assert verdict["conclusion"] == "failure" + + +@requires_node +def test_gate_still_fails_other_bots(tmp_path: Path) -> None: + """Only automated dependency authors are exempt, not every bot.""" + verdict = _run_gate( + tmp_path, + { + "number": 9003, + "draft": False, + "user": {"login": "google-labs-jules[bot]"}, + "body": DEPENDABOT_BODY, + "head": {"sha": "abc0001"}, + }, + ) + assert verdict["conclusion"] == "failure" + + +@requires_node +def test_gate_passes_a_complete_contract(tmp_path: Path) -> None: + verdict = _run_gate( + tmp_path, + { + "number": 9002, + "draft": False, + "user": {"login": "groupthinking"}, + "body": CONTRACT_BODY, + "head": {"sha": "cafe123"}, + }, + ) + assert verdict["conclusion"] == "success" + + +@requires_node +def test_gate_tolerates_a_missing_user_object(tmp_path: Path) -> None: + """The author lookup must not throw when `user` is absent.""" + verdict = _run_gate( + tmp_path, + { + "number": 9004, + "draft": False, + "body": CONTRACT_BODY, + "head": {"sha": "f00d111"}, + }, + ) + assert verdict["conclusion"] == "success"