mirror of
https://github.com/MODSetter/SurfSense.git
synced 2026-10-19 15:44:27 +00:00
fix(plugins): keep a log record's arguments when redacting it
Redaction formatted every record and dropped its arguments. uvicorn's access log unpacks its five arguments, so on the deployed host every request logged "TypeError: cannot unpack non-iterable NoneType object" in place of its access line. Each argument is now redacted in place, keeping its shape and type, and a template with arguments is left whole so its placeholders still match. A record whose credential shows only once formatted, split across the template and its arguments, still keeps just its redacted text.
This commit is contained in:
parent
7c6ce2cd1a
commit
3c61cab4de
2 changed files with 70 additions and 1 deletions
|
|
@ -8,6 +8,7 @@ logger or handler, the host's or a library's, can write a credential out.
|
|||
|
||||
import logging
|
||||
import re
|
||||
from collections.abc import Mapping
|
||||
from typing import Any
|
||||
|
||||
REDACTED = "***"
|
||||
|
|
@ -57,13 +58,37 @@ def redact_every_record() -> None:
|
|||
|
||||
|
||||
def _redact(record: logging.LogRecord) -> None:
|
||||
# The arguments keep their shape, since a formatter may read them: uvicorn's
|
||||
# access log unpacks its five. Only one that holds a credential is replaced,
|
||||
# and a template with arguments is left whole, so its placeholders still match.
|
||||
if isinstance(record.args, Mapping):
|
||||
record.args = {key: _redacted_value(v) for key, v in record.args.items()}
|
||||
elif isinstance(record.args, tuple) and record.args:
|
||||
record.args = tuple(_redacted_value(arg) for arg in record.args)
|
||||
else:
|
||||
record.msg = _redacted_value(record.msg)
|
||||
try:
|
||||
message = record.getMessage()
|
||||
except Exception:
|
||||
# A message that does not format is the logging module's own error to report.
|
||||
return
|
||||
record.msg, record.args = redacted(message), None
|
||||
# A credential split across the message and its arguments shows only once
|
||||
# formatted; such a record keeps just its redacted text.
|
||||
if redacted(message) != message:
|
||||
record.msg, record.args = redacted(message), None
|
||||
if record.exc_info and not record.exc_text:
|
||||
record.exc_text = redacted(logging.Formatter().formatException(record.exc_info))
|
||||
if record.stack_info:
|
||||
record.stack_info = redacted(record.stack_info)
|
||||
|
||||
|
||||
def _redacted_value(value: Any) -> Any:
|
||||
"""A string redacted; anything else as it is, unless its text holds a credential."""
|
||||
if isinstance(value, str):
|
||||
return redacted(value)
|
||||
try:
|
||||
text = str(value)
|
||||
except Exception:
|
||||
return value
|
||||
clean = redacted(text)
|
||||
return value if clean == text else clean
|
||||
|
|
|
|||
|
|
@ -2,6 +2,7 @@ import logging
|
|||
from collections.abc import Iterator
|
||||
|
||||
import pytest
|
||||
from uvicorn.logging import AccessFormatter
|
||||
|
||||
from host.redacted_logs import redact_every_record, redacted
|
||||
|
||||
|
|
@ -81,6 +82,49 @@ def test_every_record_is_redacted_whoever_formats_it(
|
|||
assert f"tunnel to {HIDDEN} refused" in caplog.text
|
||||
|
||||
|
||||
def test_a_formatter_that_reads_the_arguments_still_formats(
|
||||
record_factory: None, caplog: pytest.LogCaptureFixture
|
||||
) -> None:
|
||||
"""uvicorn's access log unpacks its five arguments: they keep their shape and types."""
|
||||
redact_every_record()
|
||||
logger = logging.getLogger("host.tests.redacted.access")
|
||||
with caplog.at_level(logging.INFO, logger=logger.name):
|
||||
logger.info(
|
||||
'%s - "%s %s HTTP/%s" %d',
|
||||
"10.0.1.7:51234",
|
||||
"POST",
|
||||
"/web-crawl/mcp?key=abc123",
|
||||
"1.1",
|
||||
200,
|
||||
)
|
||||
|
||||
(record,) = caplog.records
|
||||
assert record.args == (
|
||||
"10.0.1.7:51234",
|
||||
"POST",
|
||||
"/web-crawl/mcp?key=***",
|
||||
"1.1",
|
||||
200,
|
||||
)
|
||||
formatted = AccessFormatter("%(request_line)s %(status_code)s").format(record)
|
||||
assert formatted == "POST /web-crawl/mcp?key=*** HTTP/1.1 200 OK"
|
||||
|
||||
|
||||
def test_a_credential_split_across_message_and_arguments_is_hidden(
|
||||
record_factory: None, caplog: pytest.LogCaptureFixture
|
||||
) -> None:
|
||||
redact_every_record()
|
||||
logger = logging.getLogger("host.tests.redacted.split")
|
||||
with caplog.at_level(logging.WARNING, logger=logger.name):
|
||||
logger.warning("proxy http://%s:%s@%s failed", "user-1", "s3cret", "gw:823")
|
||||
logger.warning("open failed: %s", ConnectionError(f"tunnel to {PROXY} refused"))
|
||||
|
||||
assert [record.getMessage() for record in caplog.records] == [
|
||||
"proxy http://***@gw:823 failed",
|
||||
f"open failed: tunnel to {HIDDEN} refused",
|
||||
]
|
||||
|
||||
|
||||
def test_redacting_twice_wraps_the_factory_once(record_factory: None) -> None:
|
||||
redact_every_record()
|
||||
once = logging.getLogRecordFactory()
|
||||
|
|
|
|||
Loading…
Add table
Add a link
Reference in a new issue