[Bugfix][Router] Log request headers as a lazy argument so they can be redacted

src/tests/test_log.py

@@ -333,3 +333,48 @@ def test_init_logger_respects_json_format(self):
         logger = log.init_logger("test.init_json")
         for handler in logger.handlers:
             assert isinstance(handler.formatter, log.JsonFormatter)
+
+
+class TestErrorStreamRedaction:
+    """The stderr handler carries its own filter chain."""
+
+    def test_error_stream_handler_carries_the_redaction_filter(self):
+        logger = log.init_logger("test-error-stream-redaction")
+
+        error_handlers = [
+            h
+            for h in logger.handlers
+            if isinstance(h, logging.StreamHandler) and h.level == logging.WARNING
+        ]
+        assert error_handlers, "expected a WARNING-level stream handler"
+
+        for handler in error_handlers:
+            assert any(
+                isinstance(f, log.TokenRedactionFilter) for f in handler.filters
+            ), "the WARNING handler must redact, since the stdout chain never runs for it"
+
+    def test_error_stream_handler_redacts_a_warning_record(self):
+        logger = log.init_logger("test-error-stream-redaction-applied")
+        handler = next(
+            h
+            for h in logger.handlers
+            if isinstance(h, logging.StreamHandler) and h.level == logging.WARNING
+        )
+        redaction = next(
+            f for f in handler.filters if isinstance(f, log.TokenRedactionFilter)
+        )
+
+        record = logging.LogRecord(
+            name="test",
+            level=logging.WARNING,
+            pathname="test.py",
+            lineno=1,
+            msg="Upstream rejected the request, headers: %s",
+            args=(Headers({"authorization": "Bearer super-secret-token"}),),
+            exc_info=None,
+        )
+
+        redaction.filter(record)
+
+        assert "super-secret-token" not in record.getMessage()
+        assert "Bearer ****" in record.getMessage()

src/tests/test_request_header_redaction.py

@@ -0,0 +1,135 @@
+"""The session-extraction debug line must not defeat TokenRedactionFilter.
+
+TokenRedactionFilter only inspects ``record.args`` for a Starlette ``Headers``
+object, so a call site that formats the headers into the message string leaves
+nothing for it to redact.
+"""
+
+import logging
+
+from starlette.datastructures import Headers
+
+from vllm_router import log
+
+
+def _record(msg, args):
+    return logging.LogRecord(
+        name="test",
+        level=logging.DEBUG,
+        pathname="test.py",
+        lineno=1,
+        msg=msg,
+        args=args,
+        exc_info=None,
+    )
+
+
+def test_formatted_headers_are_not_redacted_but_a_lazy_arg_is():
+    redaction = log.TokenRedactionFilter()
+    headers = Headers(
+        {"authorization": "Bearer super-secret-token", "host": "example.invalid"}
+    )
+
+    formatted = _record(f"Request headers: {dict(headers)}", None)
+    redaction.filter(formatted)
+    assert "super-secret-token" in formatted.getMessage(), (
+        "a pre-formatted dict carries nothing in record.args, so the filter has "
+        "nothing to act on; this is what the call site must avoid"
+    )
+
+    lazy = _record("Request headers: %s", (headers,))
+    redaction.filter(lazy)
+    assert "super-secret-token" not in lazy.getMessage()
+    assert "Bearer ****" in lazy.getMessage()
+
+
+def test_the_filter_leaves_headers_alone_when_nothing_is_sensitive():
+    """Documented behaviour, pinned by test_filter_preserves_non_sensitive_headers.
+
+    The consequence for this call site is that the line reads as a dict when a
+    secret is present and as Headers({...}) when it is not. That is a format
+    difference rather than a leak, and changing it would change the filter's
+    own contract.
+    """
+    redaction = log.TokenRedactionFilter()
+
+    plain = _record("Request headers: %s", (Headers({"host": "x"}),))
+    redaction.filter(plain)
+    assert "Headers({'host': 'x'})" in plain.getMessage()
+
+    secret = _record(
+        "Request headers: %s", (Headers({"authorization": "Bearer s3cret"}),)
+    )
+    redaction.filter(secret)
+    assert secret.getMessage() == "Request headers: {'authorization': 'Bearer ****'}"
+
+
+def test_the_call_site_passes_headers_as_a_lazy_argument():
+    """Read the call site as a syntax tree, not as text.
+
+    A string match on the source breaks on quote style or on a formatter
+    rewrapping the line. The AST answers the only question that matters: does
+    the ``logger.debug`` call for this message carry a second argument, or is
+    everything baked into the first one?
+    """
+    import ast
+    import inspect
+
+    from vllm_router.services.request_service import request as request_module
+
+    tree = ast.parse(inspect.getsource(request_module.route_general_request))
+
+    calls = [
+        node
+        for node in ast.walk(tree)
+        if isinstance(node, ast.Call)
+        and isinstance(node.func, ast.Attribute)
+        and node.func.attr == "debug"
+        and node.args
+        and isinstance(node.args[0], ast.Constant)
+        and isinstance(node.args[0].value, str)
+        and "Request headers" in node.args[0].value
+    ]
+
+    assert len(calls) == 1, "expected exactly one headers debug call"
+    call = calls[0]
+
+    assert len(call.args) >= 2, (
+        "the headers must be a separate argument; TokenRedactionFilter only "
+        "inspects record.args, so anything formatted into the message survives"
+    )
+    assert "%s" in call.args[0].value
+
+
+def test_the_call_site_logs_headers_as_a_lazy_argument():
+    """Capture on the module's own logger, which does not propagate to root."""
+    from vllm_router.services.request_service import request as request_module
+
+    captured: list[logging.LogRecord] = []
+
+    class _Capture(logging.Handler):
+        def emit(self, record: logging.LogRecord) -> None:
+            captured.append(record)
+
+    handler = _Capture(level=logging.DEBUG)
+    logger = request_module.logger
+    previous_level = logger.level
+    logger.addHandler(handler)
+    logger.setLevel(logging.DEBUG)
+    try:
+        logger.debug(
+            "Debug session extraction - Request headers: %s",
+            Headers({"authorization": "Bearer super-secret-token"}),
+        )
+    finally:
+        logger.removeHandler(handler)
+        logger.setLevel(previous_level)
+
+    record = next(
+        r for r in captured if "Debug session extraction - Request headers" in r.msg
+    )
+    assert record.args, "the headers must arrive as a lazy argument"
+
+    log.TokenRedactionFilter().filter(record)
+    assert "super-secret-token" not in record.getMessage()
+    assert "Bearer ****" in record.getMessage()

src/vllm_router/log.py

@@ -210,6 +210,10 @@ def init_logger(name: str, log_level=None) -> Logger:
     error_stream = logging.StreamHandler()
     error_stream.setLevel(logging.WARNING)
     error_stream.setFormatter(formatter)
+    # Each handler owns its filter chain, so the stdout handler's
+    # TokenRedactionFilter never runs for a WARNING or above. Without this,
+    # a warning that logs headers would print them in cleartext.
+    error_stream.addFilter(TokenRedactionFilter())
     logger.addHandler(error_stream)
     logger.propagate = False
 

src/vllm_router/services/request_service/request.py

@@ -607,7 +607,10 @@ async def route_general_request(
         f"Debug session extraction - Router type: {type(request.app.state.router).__name__}"
     )
     logger.debug(f"Debug session extraction - Session key config: {session_key}")
-    logger.debug(f"Debug session extraction - Request headers: {dict(request.headers)}")
+    # Pass the Headers object as a lazy argument rather than a formatted dict,
+    # so TokenRedactionFilter can find it in record.args and redact
+    # Authorization and Cookie before this line is emitted.
+    logger.debug("Debug session extraction - Request headers: %s", request.headers)
     logger.debug(f"Debug session extraction - Extracted session ID: {session_id}")
 
     logger.info(