fix(redact,cli): mask credentials in every log line, silence httpx request urls

src/beaver_gateway/cli.py

@@ -24,7 +24,6 @@ import asyncio
 import contextlib
 import functools
 import logging
-import re
 import signal
 from contextlib import AsyncExitStack
 from typing import TYPE_CHECKING, Any
@@ -51,6 +50,8 @@ from beaver_gateway.core.bus import EventBus
 from beaver_gateway.core.conversations import Conversations
 from beaver_gateway.core.envelope import Envelope
 from beaver_gateway.core.gateway_tools import build_tool_server
+from beaver_gateway.core.redact import install as install_redaction
+from beaver_gateway.core.redact import load_secrets as load_secrets_to_mask
 from beaver_gateway.core.registry import AgentRegistry, Gateway, McpRegistry
 from beaver_gateway.core.rotation import Rotation, RotationPolicy
 from beaver_gateway.core.scheduler import Scheduler
@@ -89,6 +90,7 @@ def main() -> None:
     logging.basicConfig(
         level=logging.INFO, format="%(asctime)s %(levelname)s %(name)s: %(message)s"
     )
+    install_redaction()
     _install_sigterm_handler()
     asyncio.run(_async_main(), loop_factory=uvloop.new_event_loop)
 
@@ -124,6 +126,9 @@ async def _async_main() -> None:
     # populates Settings fields, not the process environment.
     # ``override=False``: real env vars (Docker, systemd) win over .env.
     load_dotenv(override=False)
+    # Only now does the process environment hold the credentials the
+    # redactor masks literally (in Docker they arrive via ``env_file``).
+    load_secrets_to_mask()
 
     settings = Settings()  # ty: ignore[missing-argument]
     gateway = config_loader.load(settings.config_path)
@@ -290,30 +295,8 @@ def _plain_postgres_url(url: str) -> str | None:
     return None
 
 
-_TOKEN_IN_QUERY = re.compile(r"(token=)[^&\s\"]+")
-
-
-class ScrubQueryTokens(logging.Filter):
-    """Mask ``?token=…`` in uvicorn access lines.
-
-    Webhook senders that cannot set headers put the secret in the URL, and
-    ``docker logs`` is not a vault.
-    """
-
-    def filter(self, record: logging.LogRecord) -> bool:
-        if isinstance(record.args, tuple):
-            record.args = tuple(
-                _TOKEN_IN_QUERY.sub(r"\1<…>", a) if isinstance(a, str) else a
-                for a in record.args
-            )
-        elif isinstance(record.msg, str):
-            record.msg = _TOKEN_IN_QUERY.sub(r"\1<…>", record.msg)
-        return True
-
-
 async def _serve_root(gateway: Gateway, *, extra: dict[str, ASGIApp]) -> None:
     app = build_root_app(gateway.frontends, extra=extra)
-    logging.getLogger("uvicorn.access").addFilter(ScrubQueryTokens())
     config = uvicorn.Config(app, host=gateway.host, port=gateway.port, log_level="info")
     _log.info(
         "gateway on http://%s:%d - %s",

src/beaver_gateway/core/redact.py

@@ -0,0 +1,178 @@
+"""Keep credentials out of the process log.
+
+``docker logs`` is not a vault: the stack's stdout lands in an unrotated
+json file on the host, and the model itself can page through it (the
+komodo tool has ``logs`` / ``search_logs``). Nobody has to write a
+careless log call for a secret to end up there — two habits do it on
+their own:
+
+* ``httpx`` logs ``HTTP Request: POST <full url>`` at ``INFO``, so every
+  request to an upstream that keeps its credential *in* the URL prints
+  the credential once per call;
+* a transport error carries that same URL through the traceback, which
+  ``_log.exception`` writes out in full.
+
+Two of our upstreams are exactly that shape: a Google Calendar
+``.../private-<token>/basic.ics`` feed and a USOS ``?key=<token>`` ical
+feed, both handed to the calendar MCP as query parameters.
+
+So: silence the HTTP clients' per-request chatter (nothing here reads
+it), and run one redaction pass over every formatted record as a second
+line of defence. Redaction knows two things — patterns for credentials
+that live in URLs and headers, and the literal values of the
+secret-looking environment variables this process was started with.
+"""
+
+from __future__ import annotations
+
+import logging
+import os
+import re
+from typing import TYPE_CHECKING
+from urllib.parse import quote, unquote
+
+if TYPE_CHECKING:
+    from collections.abc import Mapping
+
+MASK = "<…>"
+
+# Loggers that print request URLs at INFO. We keep their warnings.
+CHATTY: tuple[str, ...] = ("httpx", "httpcore", "aiohttp.client", "urllib3")
+
+# Loggers that bring their own handlers (uvicorn re-runs ``dictConfig``
+# when a server starts), so wrapping the root formatter misses them.
+# ``dictConfig`` drops a logger's handlers but keeps its filters.
+OWN_HANDLERS: tuple[str, ...] = ("uvicorn", "uvicorn.access", "uvicorn.error")
+
+# Env vars whose *value* is a credential — matched as a substring of the
+# name, so ``FIREFLY_PAT`` and ``T3_MAC_TOKEN`` both qualify.
+_SECRET_NAME = re.compile(
+    r"TOKEN|SECRET|KEY|PASSWORD|PASS\b|PAT\b|BEARER|CREDENTIAL|MCPS", re.IGNORECASE
+)
+_MIN_SECRET = 8
+
+# A query parameter may sit behind a plain ``?``/``&`` or behind their
+# percent-encoded twins when a whole URL is nested in another one.
+_LEFT = r"(?:(?<![A-Za-z0-9])|(?<=%26)|(?<=%3F))"
+# ...and runs until the next separator, encoded ``&`` included.
+_VALUE = r"(?:(?!%26)[^&\s\"'<>,;)\]}])+"
+
+_RULES: tuple[tuple[re.Pattern[str], str], ...] = (
+    # Google Calendar's secret path segment; the ``/basic.ics`` after it
+    # survives, encoded or not, so the line still says what it fetched.
+    (
+        re.compile(r"(private-)(?:(?!%2F)[A-Za-z0-9_%-]){8,}", re.IGNORECASE),
+        r"\1" + MASK,
+    ),
+    # ``key=…``, ``api_key=…``, ``token=…``, … in a query string.
+    (
+        re.compile(
+            _LEFT
+            + r"(api[-_]?key|access[-_]?token|auth[-_]?token"
+            + r"|token|key|secret|password|passwd|pat|signature|sig)"
+            + r"(=|%3D)"
+            + _VALUE,
+            re.IGNORECASE,
+        ),
+        r"\1\2" + MASK,
+    ),
+    # ``Authorization: Bearer …`` in a header dump; scheme goes too.
+    (
+        re.compile(
+            r"(authorization[\"']?\s*[:=]\s*[\"']?)(?:\S+\s+)?\S+", re.IGNORECASE
+        ),
+        r"\1" + MASK,
+    ),
+    # A bare ``Bearer <token>`` anywhere else.
+    (re.compile(r"\b(bearer)\s+[A-Za-z0-9._~+/=-]{8,}", re.IGNORECASE), r"\1 " + MASK),
+)
+
+_ENV_SECRETS: list[str] = []
+"""Literal secret values to mask, longest first. Filled by :func:`install`."""
+
+
+def env_secrets(env: Mapping[str, str]) -> list[str]:
+    """Literal values worth masking, longest first.
+
+    Each secret-looking variable contributes its value plus the
+    percent-encoded and percent-decoded spellings of it, because a
+    credential that travels inside another URL is logged encoded.
+    """
+    found: set[str] = set()
+    for name, value in env.items():
+        if not _SECRET_NAME.search(name):
+            continue
+        for form in (value, quote(value, safe=""), unquote(value)):
+            if len(form.strip()) >= _MIN_SECRET:
+                found.add(form.strip())
+    ordered = list(found)
+    ordered.sort(key=len, reverse=True)
+    return ordered
+
+
+def redact(text: str) -> str:
+    """Mask every credential we can recognise in ``text``."""
+    for value in _ENV_SECRETS:
+        if value in text:
+            text = text.replace(value, MASK)
+    for pattern, repl in _RULES:
+        text = pattern.sub(repl, text)
+    return text
+
+
+class RedactingFormatter(logging.Formatter):
+    """Wrap another formatter and redact whatever it produced.
+
+    Formatting first is the point: it catches the message, its ``%``
+    arguments and the traceback of an ``exception()`` call in one pass,
+    which a record-level filter cannot do.
+    """
+
+    def __init__(self, inner: logging.Formatter | None = None) -> None:
+        super().__init__()
+        self._inner = inner if inner is not None else logging.Formatter()
+
+    def format(self, record: logging.LogRecord) -> str:
+        return redact(self._inner.format(record))
+
+
+class RedactFilter(logging.Filter):
+    """Redact at record level, for loggers whose handlers aren't ours.
+
+    Interpolates first and replaces the record with the result, because
+    a secret is often split across the template and its arguments
+    (``"key=%s", token``) and neither half looks like a credential on
+    its own. The arguments are dropped only when something was actually
+    masked, so untouched records stay structured.
+    """
+
+    def filter(self, record: logging.LogRecord) -> bool:
+        try:
+            message = record.getMessage()
+        except (TypeError, ValueError):  # a broken template is not ours to fix
+            return True
+        masked = redact(message)
+        if masked != message:
+            record.msg = masked
+            record.args = ()
+        return True
+
+
+def load_secrets(env: Mapping[str, str] | None = None) -> None:
+    """(Re)read the literal values to mask.
+
+    Called once at startup and again after ``.env`` is loaded, because
+    in dev the process environment only fills up at that point.
+    """
+    _ENV_SECRETS[:] = env_secrets(os.environ if env is None else env)
+
+
+def install(env: Mapping[str, str] | None = None) -> None:
+    """Wire redaction into the root logger. Call right after ``basicConfig``."""
+    load_secrets(env)
+    for handler in logging.getLogger().handlers:
+        handler.setFormatter(RedactingFormatter(handler.formatter))
+    for name in CHATTY:
+        logging.getLogger(name).setLevel(logging.WARNING)
+    for name in OWN_HANDLERS:
+        logging.getLogger(name).addFilter(RedactFilter())