mirror of
https://github.com/bytedance/deer-flow.git
synced 2026-10-26 21:26:39 +00:00
fix(logging): redact credential-bearing header values in urllib3's header-parse dump (#5752)
* fix(logging): redact credential-bearing header values in urllib3's header-parse dump * fix(logging): bind redacted before the header-dump pass runs * fix(logging): collapse the first field of a header dump, which shares its line with the url argument * fix(logging): collapse every header-dump field, in the message and in the exc_info traceback * test(logging): give the traceback message copy real CRLF The message half of the record built its payload with literal backslash-r text while the exc_info copy used real CRLF, so the two halves rendered the dump in different shapes and the message only exercised the pass through a fragment match instead of the escape the real record produces. * fix(logging): redact obs-fold continuations and Proxy-Authentication-Info A malformed response can fold a header value onto the next line, and this warning exists precisely to dump malformed upstream bytes, so a folded credential cannot be assumed absent: the pass replaced only the matched segment and left the continuation - `CookieSecret; Path=/` - in the log whole. A collapsed field now also swallows the SP/HTAB-prefixed segments that follow it, while a non-sensitive field keeps its own continuation. Proxy-Authentication-Info is the proxy-side twin of Authentication-Info, which was already on the list; nextnonce reaches the payload and was logged verbatim in both the message and the exception copy. * fix(logging): redact a credential folded under an unlisted field, past repr escapes, and behind an empty first segment Addresses the three P1 findings on the header-parse dump pass: - A credential that exists only in an obs-fold continuation is now collapsed. ``_CREDENTIAL_FIELD_RE`` no longer carries the ``^``: the anchor is applied past a segment's fold marker instead, because under RFC 7230 unfolding a bearer token folded under a field this list does not name is still a bearer token. - ``_OBS_FOLD_RE`` now also recognises the repr-escaped ``\t`` spelling. The payload reaches the record through ``!r``, so a real tab is the two characters backslash-t and never matched a literal-class marker. - The continuation walk runs even when the matched value is empty, so ``Set-Cookie:\r\n Secret; Path=/`` collapses instead of leaving the secret in the segment that follows. Evidence: 3 new regression tests, red on the previous head (3 failed / 23 passed) and green on this commit (26 passed) against urllib3 2.7.0; ``ruff check`` and ``ruff format --check`` clean on both files. * test(logging): move the header-parse tests out of the EOF hunk Upstream `22b5b59` appended a redaction test at the end of this file, the same position this branch appends its own block to, so the PR reported a conflict. Relocating this branch's block to the preceding top-level boundary frees the EOF hunk; the three-way merge against current `main` is then clean. Content is unchanged: base->head is a single pure insertion of the same 312 lines (0 deletions, same line multiset as before this commit), and the merge result is byte-identical in aggregate to resolving the conflict by hand. * fix(logging): treat an escaped bare CR as a header-dump line break urllib3's header-parse warning carries the unparsed block through repr(), so its separators are escaped text. The splitter recognised escaped CRLF and escaped LF but not escaped bare CR, which http.client also accepts as a line terminator: a payload separated on bare CR alone stayed in one segment, no field name landed at a segment start, so the credential anchor never fired and the Set-Cookie and signed Location values were logged verbatim in both the message and the repeated exc_text. Add the escaped \r alternative and an end-to-end case driven through the real parse_headers/assert_header_parsing pair on the pinned urllib3 2.7.0. Co-Authored-By: sxh313 <sxh313@users.noreply.github.com> * test(logging): pin the bare-CR header dump on the JSON path too The Gateway runs with logging.enhance.format=json, and JsonTraceFormatter renders the exception itself, so the text-format case alone left the deployed emission unguarded for an escaped bare-CR payload. Record the measured cost of reordering the break alternation, which obs-fold continuations depend on. --------- Co-authored-by: sxh313 <sxh313@users.noreply.github.com>
This commit is contained in:
parent
59aa91d622
commit
3bb9a1c6ba
@ -124,6 +124,83 @@ def _url_pass_consumes_slot(slot: str) -> bool:
|
||||
return match is not None and match.end() == len(slot)
|
||||
|
||||
|
||||
# urllib3's header-parse warning (connection.py:575-581, WARNING, so it clears
|
||||
# the Gateway's INFO root) renders "Failed to parse headers (url=%s): %s". In
|
||||
# the pinned 2.7.0 the second argument stringifies as ``<defects>, unparsed
|
||||
# data: <payload!r>`` (exceptions.py:324) — there is no ``headers_received``.
|
||||
# The raw header block arrives through ``unparsed_data``: assert_header_parsing
|
||||
# sets it to ``headers.get_payload()``, and the email parser routes everything
|
||||
# after the FIRST malformed line into that payload, so the credential fields
|
||||
# that leak are the ones trailing the break — repr-escaped onto ONE physical
|
||||
# line whose logical breaks are the four characters ``\r\n``, not real newlines.
|
||||
# A pattern that ignores that shape cannot hold: with a ``[^\r\n]*`` value class
|
||||
# the first anchorable field swallowed the rest of the message, so exactly one
|
||||
# field ever collapsed while a signed ``Location`` ahead of it stayed whole (its
|
||||
# ``\b`` never fired at all, since the escape's literal ``n`` leaves no word
|
||||
# boundary before ``Location``). So this pass splits the dump on its logical
|
||||
# breaks and anchors one field per segment: every credential-bearing name
|
||||
# collapses, the names stay for operator legibility, a non-sensitive field keeps
|
||||
# its value, and a header-looking line in any other log is untouched, because
|
||||
# the pass runs only on text carrying urllib3's own literals. ``location`` is in
|
||||
# the list because that field value is the same origin-form signed target the
|
||||
# Redirecting and retry passes collapse. The anchor is applied past a segment's
|
||||
# obs-fold marker (see _OBS_FOLD_RE) rather than written into the pattern,
|
||||
# because a folded value is one header value under RFC 7230 unfolding: a bearer
|
||||
# token folded under a field this list does not name is still a bearer token.
|
||||
_CREDENTIAL_FIELD_RE = re.compile(r"(?i)(?P<name>set-cookie2?|cookie|authorization|proxy-authorization|www-authenticate|proxy-authenticate|authentication-info|proxy-authentication-info|location)[ \t]*:[ \t]*(?P<value>.*)$")
|
||||
# The payload's line breaks as they appear in the log: escaped inside a repr,
|
||||
# and real if a future format ever stops quoting the block. The repr's opening
|
||||
# quote is a break too — the dump's first field follows ``unparsed data: `` and
|
||||
# its ``b?`` bytes form on the same segment as the warning's own scaffolding, so
|
||||
# without it that first field would never start a segment and never be anchored.
|
||||
# Every break spelling needs both forms. A bare CR is a separator to
|
||||
# ``parse_headers`` even though RFC 9112 only defines CRLF, so a payload can be
|
||||
# split on ``\r`` alone; in the repr that is the two characters ``\\r``, which
|
||||
# ``\\r\\n`` and ``\\n`` never match. Missing it leaves the whole dump in one
|
||||
# segment, so the leading field name is not at a segment start, no anchor fires,
|
||||
# and every credential in the block is logged verbatim. ``\\r\\n`` must stay
|
||||
# ahead of ``\\r``: alternation is leftmost-first, so leading with ``\\r`` splits
|
||||
# every CRLF escape into two breaks, and the empty segment between them ends an
|
||||
# obs-fold walk early — a credential folded under a ``\r\n`` break plus a
|
||||
# ``\t`` continuation then leaks whole.
|
||||
_DUMP_LOGICAL_BREAK_RE = re.compile(r"(\\r\\n|\\r|\\n|\r\n|\r|\n|unparsed data: b?['\"])")
|
||||
_HEADER_DUMP_PREFIX = "Failed to parse headers (url="
|
||||
# An RFC 5322 obs-fold continuation keeps the field's value on the next line and
|
||||
# is marked by a leading SP/HTAB. This warning exists to dump malformed upstream
|
||||
# bytes, so a folded credential cannot be assumed absent: the rest of a collapsed
|
||||
# field's value — or the whole of it, when the field's first segment is empty —
|
||||
# lives in the segments that follow its break. The marker has two spellings in
|
||||
# the logged copy, because the payload reaches the record through ``!r``: a real
|
||||
# tab is the two characters backslash-t, while a space is never escaped.
|
||||
_OBS_FOLD_RE = re.compile(r"^(?:[ \t]|\\t)+")
|
||||
# HeaderParsingError's own message, so a record's exception text — which repeats
|
||||
# the dump verbatim — is recognised as the same shape rather than as free text.
|
||||
_HEADER_DUMP_MARKER = "unparsed data: "
|
||||
|
||||
|
||||
def _redact_credential_headers(message: str) -> str:
|
||||
parts = _DUMP_LOGICAL_BREAK_RE.split(message)
|
||||
# A capturing split returns [text, break, text, break, ...]; only the
|
||||
# even-indexed segments are header lines.
|
||||
for index in range(0, len(parts), 2):
|
||||
segment = parts[index]
|
||||
fold = _OBS_FOLD_RE.match(segment)
|
||||
lead = fold.group(0) if fold else ""
|
||||
match = _CREDENTIAL_FIELD_RE.match(segment, len(lead))
|
||||
if match is None:
|
||||
continue
|
||||
# An empty value hides nothing on its own line, and rewriting it would
|
||||
# claim a redaction that never happened — but the field is still the one
|
||||
# its continuation belongs to, so the walk below runs either way.
|
||||
if match.group("value"):
|
||||
parts[index] = lead + match.group("name") + ": <redacted>"
|
||||
walk = index + 2
|
||||
while walk < len(parts) and _OBS_FOLD_RE.match(parts[walk]):
|
||||
parts[walk] = "<redacted>"
|
||||
walk += 2
|
||||
return "".join(parts)
|
||||
|
||||
|
||||
# The two scheme-bearing patterns start with a character class, so re.sub
|
||||
# retries the match at every position of a long token — a letter run with no
|
||||
# ``://`` makes each attempt walk to the end of the run, which is quadratic
|
||||
@ -198,6 +275,10 @@ class UrlRedactionFilter(logging.Filter):
|
||||
(``msg`` set to the redacted formatted message, ``args`` cleared) so
|
||||
every downstream handler and formatter — text or JSON — sees the same
|
||||
redacted line, while the method/status/error observability is preserved.
|
||||
Where a record's exception repeats a secret the message pass collapsed
|
||||
(urllib3's header-parse warning logs with ``exc_info=True``), ``exc_text``
|
||||
is produced through the same passes, because a formatter appends that text
|
||||
to the output whatever the format string says.
|
||||
The scheme-bearing patterns are attempted only at ``://``-anchored
|
||||
scheme starts, so filtering a record costs linear time in its message
|
||||
length. A URL is rewritten only when it carries something to hide
|
||||
@ -205,9 +286,7 @@ class UrlRedactionFilter(logging.Filter):
|
||||
records without any URL pass through untouched.
|
||||
"""
|
||||
|
||||
def filter(self, record: logging.LogRecord) -> bool:
|
||||
message = record.getMessage()
|
||||
|
||||
def _redact_message(self, message: str) -> str:
|
||||
def _redact(match: re.Match[str]) -> str:
|
||||
if not (match.group("userinfo") or match.group("rest")):
|
||||
return match.group(0) # bare origin: nothing to redact
|
||||
@ -260,15 +339,43 @@ class UrlRedactionFilter(logging.Filter):
|
||||
# two scheme-bearing passes scan from ``://`` occurrences (see
|
||||
# _scheme_starts) instead of re.sub, so long letter runs in any
|
||||
# record — URL paths or URL-free error bodies — stay linear-time.
|
||||
redacted = _redact_scheme_bearing(_URLLIB3_REQUEST_LINE_RE, _redact_request_line, message)
|
||||
redacted = message
|
||||
# Runs before the URL passes: the absolute-URL rewrite consumes the
|
||||
# ``): `` closer and the repr scaffolding that separate the url
|
||||
# argument from the header dump, which would blur the two together and
|
||||
# leave a value whose only boundary was the consumed closer behind.
|
||||
if message.startswith(_HEADER_DUMP_PREFIX) or _HEADER_DUMP_MARKER in message:
|
||||
# The record's own second argument, not a URL line: the response
|
||||
# header block that urllib3 echoes when it could not parse it. The
|
||||
# marker branch covers the exception text, whose last line repeats
|
||||
# that block outside the warning's prefix.
|
||||
redacted = _redact_credential_headers(redacted)
|
||||
redacted = _redact_scheme_bearing(_URLLIB3_REQUEST_LINE_RE, _redact_request_line, redacted)
|
||||
redacted = _URLLIB3_INCREMENT_RETRY_RE.sub(_redact_increment, redacted)
|
||||
redacted = _URLLIB3_RETRY_TARGET_RE.sub(_redact_retry_target, redacted)
|
||||
redacted = _URLLIB3_RETRYING_RE.sub(_redact_retrying, redacted)
|
||||
redacted = _URLLIB3_REDIRECTING_ORIGIN_RE.sub(_redact_redirecting_origin, redacted)
|
||||
redacted = _redact_scheme_bearing(_URL_REDACT_RE, _redact, redacted)
|
||||
return redacted
|
||||
|
||||
def filter(self, record: logging.LogRecord) -> bool:
|
||||
message = record.getMessage()
|
||||
redacted = self._redact_message(message)
|
||||
if redacted != message:
|
||||
record.msg = redacted
|
||||
record.args = None
|
||||
if record.exc_info and _HEADER_DUMP_MARKER in message:
|
||||
# urllib3 emits the header-parse warning with exc_info=True, and
|
||||
# Formatter.format appends formatException() to any record carrying
|
||||
# one — independently of the format string — so the traceback's last
|
||||
# line is a second whole copy of the dump the message pass just
|
||||
# collapsed. Pre-populating exc_text is what wins, because the
|
||||
# Formatter recomputes it only when unset. The gate reads the
|
||||
# already-formatted message rather than the exception: that warning
|
||||
# interpolates the exception into it, so the marker is the same
|
||||
# signal, and no other error record pays for formatting a traceback
|
||||
# this filter would leave untouched anyway.
|
||||
record.exc_text = self._redact_message(logging.Formatter().formatException(record.exc_info))
|
||||
return True
|
||||
|
||||
|
||||
@ -289,8 +396,9 @@ class UrlRedactionFilter(logging.Filter):
|
||||
# The enumeration of urllib3's URL-bearing lines is closed against the
|
||||
# installed source (2.7.0): every other emitter logs host:port only
|
||||
# (connection establishment/reset) or an absolute URL in one piece
|
||||
# (``connection.py``'s header-parse warning), which the generic absolute-URL
|
||||
# pass rewrites without a dedicated shape. The closure is version-anchored:
|
||||
# (``connection.py``'s header-parse warning, whose second argument is a raw
|
||||
# response header block rather than a URL, and goes through
|
||||
# _redact_credential_headers). The closure is version-anchored:
|
||||
# a urllib3 upgrade can change these format strings and silently reopen it —
|
||||
# re-run the emitter enumeration when bumping the dependency.
|
||||
_REDACTED_LOGGER_NAMES = ("httpx",)
|
||||
@ -347,7 +455,13 @@ class JsonTraceFormatter(logging.Formatter):
|
||||
"message": record.getMessage(),
|
||||
}
|
||||
if record.exc_info:
|
||||
payload["exc_info"] = self.formatException(record.exc_info)
|
||||
# Follow logging.Formatter in caching and reusing exc_text: a filter
|
||||
# that already redacted it (UrlRedactionFilter, for urllib3's
|
||||
# header-parse warning) would otherwise be recomputed here and its
|
||||
# result discarded, re-emitting the exception's own text in full.
|
||||
if not record.exc_text:
|
||||
record.exc_text = self.formatException(record.exc_info)
|
||||
payload["exc_info"] = record.exc_text
|
||||
if record.stack_info:
|
||||
payload["stack_info"] = self.formatStack(record.stack_info)
|
||||
return json.dumps(payload, ensure_ascii=False)
|
||||
|
||||
@ -753,6 +753,347 @@ def test_url_redaction_filter_redirecting_survives_spacey_location() -> None:
|
||||
assert sandbox.getMessage() == "sandbox.mounts entry /srv/knowledge -> /mnt/knowledge ignored: missing"
|
||||
|
||||
|
||||
def _emit_real_header_parse_warning(url: str, raw: bytes, *, json_format: bool = False) -> str:
|
||||
"""Drive urllib3's own header-parse warning end to end and return the log line.
|
||||
|
||||
``http.client.parse_headers`` + ``assert_header_parsing`` build the real
|
||||
``HeaderParsingError``, and the emission copies ``connection.py`` including
|
||||
``exc_info=True``, so the result is what a handler's formatter writes - not
|
||||
just ``record.getMessage()``.
|
||||
"""
|
||||
import http.client
|
||||
import io
|
||||
|
||||
from urllib3.exceptions import HeaderParsingError
|
||||
from urllib3.util.response import assert_header_parsing
|
||||
|
||||
from deerflow.logging_config import UrlRedactionFilter
|
||||
|
||||
headers = http.client.parse_headers(io.BytesIO(raw))
|
||||
root = logging.getLogger()
|
||||
saved_handlers, saved_level = root.handlers[:], root.level
|
||||
stream = io.StringIO()
|
||||
handler = logging.StreamHandler(stream)
|
||||
if json_format:
|
||||
from deerflow.logging_config import JsonTraceFormatter
|
||||
|
||||
handler.setFormatter(JsonTraceFormatter())
|
||||
else:
|
||||
handler.setFormatter(logging.Formatter("%(message)s"))
|
||||
handler.addFilter(UrlRedactionFilter())
|
||||
root.handlers = [handler]
|
||||
root.setLevel(logging.WARNING)
|
||||
try:
|
||||
try:
|
||||
assert_header_parsing(headers)
|
||||
raise AssertionError("expected HeaderParsingError")
|
||||
except (HeaderParsingError, TypeError) as hpe:
|
||||
logging.getLogger("urllib3.connection").warning("Failed to parse headers (url=%s): %s", url, hpe, exc_info=True)
|
||||
return stream.getvalue()
|
||||
finally:
|
||||
root.handlers[:] = saved_handlers
|
||||
root.setLevel(saved_level)
|
||||
|
||||
|
||||
def test_url_redaction_filter_collapses_credentials_in_a_header_parse_dump() -> None:
|
||||
"""urllib3's header-parse warning embeds the raw response header block.
|
||||
|
||||
``connection.py:575-581`` logs ``Failed to parse headers (url=%s): %s`` at
|
||||
WARNING with ``exc_info=True``, and the pinned 2.7.0 ``HeaderParsingError``
|
||||
stringifies as ``"<defects>, unparsed data: <payload!r>"`` - the payload
|
||||
being everything after the FIRST malformed line of the response. Every
|
||||
credential-bearing field therefore sits behind that break, repr-escaped onto
|
||||
one physical line whose breaks are the literal four characters ``\\r\\n``.
|
||||
Field order is the response's choice, so both a leading ``Location`` and a
|
||||
leading ``Set-Cookie`` must collapse, and the emitted traceback must not
|
||||
re-carry the block the message line just lost.
|
||||
"""
|
||||
url = "https://cdn.example.com:443/tenant-42/reports/q1?sig=UrlSecret"
|
||||
secrets = ("SignedPathSecret", "CookieSecret", "TokenSecret", "UrlSecret", "session=", "Bearer ")
|
||||
blocks = (
|
||||
# Location first: the signed origin-form target leads the payload.
|
||||
b"bad line\r\nLocation: /tenant-42/reports/q1?sig=SignedPathSecret\r\nSet-Cookie: session=CookieSecret; Path=/\r\nWWW-Authenticate: Bearer TokenSecret\r\nContent-Type: application/json\r\n\r\n",
|
||||
# Set-Cookie first: the credentials trail it.
|
||||
b"bad line\r\nSet-Cookie: session=CookieSecret; Path=/\r\nWWW-Authenticate: Bearer TokenSecret\r\nLocation: /tenant-42/reports/q1?sig=SignedPathSecret\r\nContent-Type: application/json\r\n\r\n",
|
||||
)
|
||||
|
||||
for raw in blocks:
|
||||
formatted = _emit_real_header_parse_warning(url, raw)
|
||||
for secret in secrets:
|
||||
assert secret not in formatted, secret
|
||||
# Field names, the non-sensitive field and the defect itself stay.
|
||||
assert "Set-Cookie: <redacted>" in formatted
|
||||
assert "WWW-Authenticate: <redacted>" in formatted
|
||||
assert "Location: <redacted>" in formatted
|
||||
assert "Content-Type: application/json" in formatted
|
||||
assert "bad line" in formatted
|
||||
|
||||
|
||||
def test_url_redaction_filter_collapses_credentials_behind_escaped_bare_cr_separators() -> None:
|
||||
"""A payload separated on bare CR alone must collapse too.
|
||||
|
||||
``http.client`` accepts ``\\r`` as a line terminator even though RFC 9112
|
||||
defines only CRLF, so ``parse_headers`` + ``assert_header_parsing`` yield a
|
||||
``HeaderParsingError`` whose payload carries every field after a bare-CR
|
||||
break. That block reaches the record through ``!r``, so its separators are
|
||||
the two characters ``\\r`` rather than the four of ``\\r\\n``: a splitter
|
||||
that knows escaped CRLF and escaped LF but not escaped bare CR keeps the
|
||||
whole dump in one segment. No field name then sits at a segment start, the
|
||||
anchor never fires, and the cookie and the signed ``Location`` are logged
|
||||
verbatim in both the message and the ``exc_text`` that repeats it, and the
|
||||
deployed JSON format renders the same repr, so it must collapse there too.
|
||||
"""
|
||||
url = "https://cdn.example.com:443/tenant-42/reports/q1?sig=UrlSecret"
|
||||
raw = b"bad line\rSet-Cookie: session=BareCRSecret\rLocation: /p?sig=LocationSecret\r\r"
|
||||
|
||||
formatted = _emit_real_header_parse_warning(url, raw)
|
||||
# ``logging.enhance.format=json`` is the Gateway's setting, and its formatter
|
||||
# renders the exception itself rather than the filter's redacted exc_text.
|
||||
for out in (formatted, _emit_real_header_parse_warning(url, raw, json_format=True)):
|
||||
for secret in ("BareCRSecret", "LocationSecret", "session=", "UrlSecret"):
|
||||
assert secret not in out, secret
|
||||
# The names survive for operator legibility, and so does the malformed line.
|
||||
assert "Set-Cookie: <redacted>" in formatted
|
||||
assert "Location: <redacted>" in formatted
|
||||
assert "bad line" in formatted
|
||||
|
||||
|
||||
def test_url_redaction_filter_collapses_folded_continuations_and_proxy_auth_info() -> None:
|
||||
"""A collapsed field's value can continue on the following line, and
|
||||
``Proxy-Authentication-Info`` is the proxy-side twin of a field already on
|
||||
the list.
|
||||
|
||||
RFC 5322 obs-fold marks a continuation with a leading SP/HTAB, and this
|
||||
warning dumps malformed upstream bytes, so folded lines cannot be assumed
|
||||
absent: replacing only the matched segment would log ``Set-Cookie:
|
||||
<redacted>`` followed by the still-plain ``CookieSecret; Path=/``. A
|
||||
non-sensitive field keeps its own continuation, which is what bounds the
|
||||
rewrite to the fields this pass actually collapses.
|
||||
"""
|
||||
url = "https://cdn.example.com:443/tenant-42/reports/q1?sig=UrlSecret"
|
||||
raw = b'bad line\r\nSet-Cookie: session=\r\n CookieSecret; Path=/\r\nProxy-Authentication-Info: nextnonce="ProxySecret"\r\nContent-Type: application/json\r\n\tcharset=utf-8\r\n\r\n'
|
||||
|
||||
formatted = _emit_real_header_parse_warning(url, raw)
|
||||
for secret in ("CookieSecret", "ProxySecret", "session=", "UrlSecret"):
|
||||
assert secret not in formatted, secret
|
||||
assert "Set-Cookie: <redacted>" in formatted
|
||||
assert "Proxy-Authentication-Info: <redacted>" in formatted
|
||||
# The continuation is part of the collapsed field, so it goes too.
|
||||
assert "Set-Cookie: <redacted>\\r\\n<redacted>" in formatted
|
||||
assert "Content-Type: application/json" in formatted
|
||||
assert "charset=utf-8" in formatted
|
||||
|
||||
|
||||
def test_url_redaction_filter_collapses_a_credential_folded_under_an_unlisted_field() -> None:
|
||||
"""A folded credential is still that header's value, whatever field it folds under.
|
||||
|
||||
Under RFC 7230 unfolding ``X-Trace: keep\\r\\n Authorization: Bearer …`` is one
|
||||
header whose value carries the bearer token, so the fold is a credential leak
|
||||
even though the field it attaches to is not on the list. Anchoring the field
|
||||
name only at the segment start let exactly this segment through while the
|
||||
unindented ``Set-Cookie`` right after it collapsed, which is the proof the
|
||||
pass ran rather than that a name matched.
|
||||
"""
|
||||
url = "https://cdn.example.com:443/tenant-42/reports/q1?sig=UrlSecret"
|
||||
raw = b"bad line\r\nX-Trace: keep\r\n Authorization: Bearer FoldSecret\r\nSet-Cookie: session=CookieSecret\r\n\r\n"
|
||||
|
||||
formatted = _emit_real_header_parse_warning(url, raw)
|
||||
for secret in ("FoldSecret", "CookieSecret", "Bearer", "UrlSecret"):
|
||||
assert secret not in formatted, secret
|
||||
# The fold marker and the name stay for operator legibility, and the
|
||||
# non-sensitive field the credential folded under keeps its own value.
|
||||
assert " Authorization: <redacted>" in formatted
|
||||
assert "X-Trace: keep" in formatted
|
||||
assert "Set-Cookie: <redacted>" in formatted
|
||||
|
||||
|
||||
def test_url_redaction_filter_collapses_an_escaped_htab_continuation() -> None:
|
||||
"""A tab continuation reaches the log as ``\\t``, not as a real HTAB.
|
||||
|
||||
``HeaderParsingError`` renders the payload with ``!r``, so the RFC 5322
|
||||
marker in front of a folded value survives into the record as the two
|
||||
characters backslash-t. A fold test that uses a space for the sensitive
|
||||
continuation therefore never asks the walk about that spelling, and a
|
||||
bearer token sitting behind it is logged whole.
|
||||
"""
|
||||
url = "https://cdn.example.com:443/tenant-42/reports/q1?sig=UrlSecret"
|
||||
raw = b"bad line\r\nSet-Cookie: session=AlphaSecret\r\n\tBetaSecret; Path=/\r\nContent-Type: application/json\r\n\tcharset=utf-8\r\n\r\n"
|
||||
|
||||
formatted = _emit_real_header_parse_warning(url, raw)
|
||||
for secret in ("AlphaSecret", "BetaSecret", "session=", "UrlSecret"):
|
||||
assert secret not in formatted, secret
|
||||
assert "Set-Cookie: <redacted>\\r\\n<redacted>" in formatted
|
||||
# The asymmetry holds under the escaped spelling: a continuation that names
|
||||
# no credential field stays, so this pass cannot be replaced by "fold
|
||||
# everything whitespace-led".
|
||||
assert "Content-Type: application/json" in formatted
|
||||
assert "\\tcharset=utf-8" in formatted
|
||||
|
||||
|
||||
def test_url_redaction_filter_collapses_a_credential_entirely_inside_the_fold() -> None:
|
||||
"""An empty first segment does not mean the folded field has no value.
|
||||
|
||||
``Set-Cookie:\\r\\n CookieSecret`` puts the whole value on the continuation.
|
||||
Gating the fold walk on the matched segment having a non-empty value
|
||||
skipped the walk for exactly this shape, so the credential was logged
|
||||
while a same-shaped field with a value collapsed. The field itself stays
|
||||
as written — nothing on that segment was redacted.
|
||||
"""
|
||||
url = "https://cdn.example.com:443/tenant-42/reports/q1?sig=UrlSecret"
|
||||
raw = b"bad line\r\nSet-Cookie:\r\n GammaSecret; Path=/\r\nX-Other: keep\r\n\r\n"
|
||||
|
||||
formatted = _emit_real_header_parse_warning(url, raw)
|
||||
for secret in ("GammaSecret", "UrlSecret"):
|
||||
assert secret not in formatted, secret
|
||||
assert "Set-Cookie:\\r\\n<redacted>" in formatted
|
||||
assert "X-Other: keep" in formatted
|
||||
|
||||
|
||||
def test_url_redaction_filter_collapses_dump_credentials_in_json_logging_too() -> None:
|
||||
"""JSON output must not reopen the leak the text path closes.
|
||||
|
||||
``JsonTraceFormatter`` renders the exception itself rather than going
|
||||
through ``logging.Formatter.format``, so it can discard a filter's redacted
|
||||
``exc_text`` and re-emit the payload; the Gateway runs with
|
||||
``logging.enhance.format=json``, which makes that the deployed path.
|
||||
"""
|
||||
url = "https://cdn.example.com:443/tenant-42/reports/q1?sig=UrlSecret"
|
||||
raw = b"bad line\r\nSet-Cookie: session=CookieSecret; Path=/\r\nLocation: /tenant-42/reports/q1?sig=SignedPathSecret\r\n\r\n"
|
||||
|
||||
formatted = _emit_real_header_parse_warning(url, raw, json_format=True)
|
||||
for secret in ("SignedPathSecret", "CookieSecret", "UrlSecret", "session="):
|
||||
assert secret not in formatted, secret
|
||||
assert "Set-Cookie: <redacted>" in formatted
|
||||
assert "unparsed data:" in formatted # the shape stays diagnosable
|
||||
|
||||
|
||||
def test_url_redaction_filter_collapses_credentials_carried_by_the_traceback() -> None:
|
||||
"""The warning's traceback text is a second copy of the dump.
|
||||
|
||||
``logging.Formatter.format`` appends ``formatException`` to any record that
|
||||
carries ``exc_info``, independently of the format string, and that text ends
|
||||
with the exception's own ``unparsed data: '<payload>'`` line. Redacting the
|
||||
message alone leaves the credentials in the log whole, so the filter
|
||||
pre-populates ``exc_text`` - the Formatter only recomputes it when unset.
|
||||
"""
|
||||
from urllib3.exceptions import HeaderParsingError
|
||||
|
||||
from deerflow.logging_config import UrlRedactionFilter
|
||||
|
||||
payload = "Set-Cookie: session=CookieSecret\r\n"
|
||||
record = logging.LogRecord("urllib3.connection", logging.WARNING, __file__, 1, "Failed to parse headers (url=%s): %s", ("https://cdn.example.com/tenant-42/x?sig=UrlSecret", HeaderParsingError([], payload)), None)
|
||||
record.exc_info = (HeaderParsingError, HeaderParsingError([], "Set-Cookie: session=CookieSecret\r\n"), None)
|
||||
|
||||
assert UrlRedactionFilter().filter(record) is True
|
||||
assert record.exc_text is not None
|
||||
assert "CookieSecret" not in record.getMessage() + record.exc_text
|
||||
assert "Set-Cookie: <redacted>" in record.exc_text
|
||||
assert "unparsed data:" in record.exc_text
|
||||
|
||||
|
||||
def test_url_redaction_filter_does_not_format_exceptions_of_other_records() -> None:
|
||||
"""The traceback pass is gated on urllib3's own literal, like the dump pass.
|
||||
|
||||
Formatting an arbitrary record's exception to scan it would cost every error
|
||||
log a ``linecache`` read for no redaction benefit, so a record that is not
|
||||
urllib3's header-parse warning keeps its ``exc_text`` unset.
|
||||
"""
|
||||
from deerflow.logging_config import UrlRedactionFilter
|
||||
|
||||
record = logging.LogRecord("deerflow.something", logging.ERROR, __file__, 1, "upstream call failed", (), None)
|
||||
try:
|
||||
raise ValueError("boom")
|
||||
except ValueError:
|
||||
import sys
|
||||
|
||||
record.exc_info = sys.exc_info()
|
||||
|
||||
assert UrlRedactionFilter().filter(record) is True
|
||||
assert record.exc_text is None
|
||||
|
||||
|
||||
def test_url_redaction_filter_anchors_every_repr_form_of_the_payload() -> None:
|
||||
"""The dump pass anchors on the payload's own delimiters, not on guesses.
|
||||
|
||||
``HeaderParsingError`` renders ``unparsed_data`` through ``!r``, so the field
|
||||
lines are separated by the four characters ``\\r\\n`` and the first field
|
||||
follows the repr's opening quote - which is ``'``, ``"``, ``b'`` or ``b"``
|
||||
depending on the payload's type and on whether the value holds a quote. Each
|
||||
of those is an anchor this pass must recognise, or the field glued to it
|
||||
stays whole.
|
||||
"""
|
||||
from deerflow.logging_config import UrlRedactionFilter
|
||||
|
||||
cases = [
|
||||
# First field glued to the repr's opening quote.
|
||||
(
|
||||
"""Failed to parse headers (url=https://h/p): [D], unparsed data: 'Set-Cookie: session=CookieSecret\\r\\nContent-Type: text/plain\\r\\n'""",
|
||||
"Set-Cookie: <redacted>",
|
||||
"Content-Type: text/plain",
|
||||
),
|
||||
# The payload holds an apostrophe, so repr switches to double quotes.
|
||||
(
|
||||
'''Failed to parse headers (url=https://h/p): [D], unparsed data: "Set-Cookie: it's-CookieSecret\\r\\n"''',
|
||||
"Set-Cookie: <redacted>",
|
||||
None,
|
||||
),
|
||||
# Bytes payload.
|
||||
(
|
||||
"""Failed to parse headers (url=https://h/p): [D], unparsed data: b'Set-Cookie: session=CookieSecret\\r\\n'""",
|
||||
"Set-Cookie: <redacted>",
|
||||
None,
|
||||
),
|
||||
# A later field carries an absolute URL: its secret is the credential
|
||||
# field's own, and the field collapses before the URL pass could need it.
|
||||
(
|
||||
"""Failed to parse headers (url=https://h/p): [D], unparsed data: 'bad\\r\\nLocation: https://cdn.example/tenant-42/x?sig=SignedPathSecret\\r\\n'""",
|
||||
"Location: <redacted>",
|
||||
None,
|
||||
),
|
||||
# Single-character escape break instead of the CRLF pair.
|
||||
(
|
||||
"""Failed to parse headers (url=https://h/p): [D], unparsed data: 'bad\\nWWW-Authenticate: Bearer TokenSecret\\n'""",
|
||||
"WWW-Authenticate: <redacted>",
|
||||
None,
|
||||
),
|
||||
]
|
||||
secrets = ("CookieSecret", "SignedPathSecret", "TokenSecret")
|
||||
|
||||
for message, collapsed, kept_field in cases:
|
||||
record = logging.LogRecord("urllib3.connection", logging.WARNING, __file__, 1, message, (), None)
|
||||
assert UrlRedactionFilter().filter(record) is True
|
||||
formatted = record.getMessage()
|
||||
for secret in secrets:
|
||||
assert secret not in formatted, (message, secret)
|
||||
assert "unparsed data:" in formatted
|
||||
assert collapsed in formatted, formatted
|
||||
if kept_field:
|
||||
assert kept_field in formatted, formatted
|
||||
|
||||
|
||||
def test_url_redaction_filter_leaves_header_looking_text_outside_the_dump_alone() -> None:
|
||||
"""The dump pass is gated on urllib3's own literal, not on header syntax.
|
||||
|
||||
A ``Set-Cookie:`` shaped line in some other component's log is that
|
||||
component's data, and rewriting it here would silently widen a URL
|
||||
redactor into a general PII filter.
|
||||
"""
|
||||
from deerflow.logging_config import UrlRedactionFilter
|
||||
|
||||
record = logging.LogRecord(
|
||||
"deerflow.something",
|
||||
logging.INFO,
|
||||
__file__,
|
||||
1,
|
||||
"parsed upstream reply: Set-Cookie: session=OtherCookieSecret",
|
||||
(),
|
||||
None,
|
||||
)
|
||||
|
||||
assert UrlRedactionFilter().filter(record) is True
|
||||
assert "OtherCookieSecret" in record.getMessage()
|
||||
|
||||
|
||||
def test_url_redaction_filter_redirecting_covers_all_relative_ref_forms() -> None:
|
||||
"""Round-15 residual: a Redirecting slot stayed verbatim unless it
|
||||
started with "/", but the Location field-value grammar (RFC 3986
|
||||
|
||||
Loading…
x
Reference in New Issue
Block a user