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

[chrikrah]

TokenRedactionFilter only inspects record.args for a Starlette Headers or MutableHeaders object, at src/vllm_router/log.py:163.

The session-extraction line formats the headers into the message instead, at src/vllm_router/services/request_service/request.py:610:

logger.debug(f"Debug session extraction - Request headers: {dict(request.headers)}")

record.args is then empty. The filter has nothing to act on, so Authorization and Cookie print in full at DEBUG level for every request through route_general_request.

Measured with the real filter, both forms of the same call:

CURRENT : Debug session extraction - Request headers: {'authorization': 'Bearer super-secret-token', 'host': 'x'}
LAZY    : Debug session extraction - Request headers: {'authorization': 'Bearer ****', 'host': 'x'}

Second change, same class

init_logger attaches TokenRedactionFilter to the stdout handler only, at log.py:207. Each handler owns its filter chain, and the stdout handler also carries MaxLevelFilter(logging.INFO), so nothing redacts a record at WARNING or above.

No call site logs headers at that level today. This closes the hole rather than a live leak, and it costs one line.

Tests

$ uv run pytest src/tests -q
235 passed

$ uv run pre-commit run --files src/vllm_router/log.py src/vllm_router/services/request_service/request.py src/tests/test_log.py src/tests/test_request_header_redaction.py
black....................................................................Passed
isort....................................................................Passed
ruff (legacy alias)......................................................Passed
codespell................................................................Passed

Three new cases. One pins that a pre-formatted dict is not redacted while a lazy argument is, which is the rule the call site has to follow. One reads the call site's own source, so a later edit back to an f-string fails rather than silently reopening this. Two cover the stderr handler.

Revert both production files, keep the tests, and the two files give 3 failed, 24 passed.

Scope

The message reads identically once redaction has run, so no log format changed for anyone whose headers carry nothing sensitive. _SENSITIVE_HEADERS and _redact_value are untouched.

Duplicate search

Eleven open pull requests touch src/vllm_router/services/request_service/request.py: #1095, #1082, #1072, #1067, #1040, #1023, #1020, #1001, #951, #950 and #939. Not one mentions Request headers.

No open pull request touches src/vllm_router/log.py. gh pr list --state all --search "TokenRedactionFilter" returns only #824, the merged change that added the filter.

• Make sure the code changes pass the pre-commit checks.
• Sign-off your commit by using -s when doing git commit
• Try to classify PRs for easy understanding of the type of changes, such as [Bugfix], [Feat], and [CI].

[gemini-code-assist]

Code Review

This pull request improves sensitive token redaction in logs by adding TokenRedactionFilter to the error stream handler and passing request headers as a lazy argument rather than a pre-formatted dictionary. It also adds corresponding unit tests. Feedback highlights two main issues: first, passing request.headers directly introduces inconsistent log formatting depending on whether sensitive headers are present (recommending that TokenRedactionFilter always convert headers to a dictionary); second, using inspect.getsource to assert on implementation details in tests is fragile and should be replaced with a more robust approach like caplog or mocking.

[gemini-code-assist]

Passing request.headers directly as a lazy argument introduces an inconsistency in the log format depending on whether sensitive headers are present.\n\nThis happens because TokenRedactionFilter (in src/vllm_router/log.py) only converts the Headers object to a dict when a sensitive header is found and modified:\n- With sensitive headers: The filter redacts them and replaces the argument with a standard Python dict. The log output formats as a dictionary: {'authorization': 'Bearer ****', 'host': '...'}.\n- Without sensitive headers: The filter does not modify the argument, leaving it as a Starlette Headers object. The log output formats using the Headers __repr__: Headers(headers=[('host', '...')]).\n\nTo ensure consistent log formatting, TokenRedactionFilter should be updated to always convert Headers and MutableHeaders to a dict (or always reconstruct them as Headers / MutableHeaders if type preservation is desired) regardless of whether any sensitive headers were modified.

[gemini-code-assist]

Using inspect.getsource and string matching to assert on the implementation details of route_general_request is highly fragile. This test will fail if:\n1. The log message is formatted with single quotes instead of double quotes.\n2. A code formatter (like black or ruff) wraps the line differently.\n3. The source code is not available (e.g., when running from compiled .pyc files or in certain CI/CD environments).\n\nInstead of inspecting the source code, a more robust approach is to mock the logger or use pytest's caplog fixture to verify that the logged message is actually redacted when route_general_request is executed. If invoking route_general_request is too complex due to dependencies, we can at least make the string matching more flexible (e.g., using regular expressions or AST parsing via the ast module) to avoid failing on simple formatting changes.

[chrikrah]

Both findings are right. One is applied, one is recorded rather than acted on.

The source-matching test. Applied in aff7554. A string match breaks on quote style and on a formatter rewrapping the line, exactly as you say.

A caplog test loses the point, though. Logging with a lazy argument works whatever the call site does, so such a test passes with the production change reverted and pins nothing.

The test now parses the function, finds the logger.debug call whose first argument mentions Request headers, and asserts it has a second argument. That survives reformatting and requoting. Reverting request.py alone still gives 1 failed, 3 passed.

The format inconsistency. Real, and deliberate upstream of this change.

TokenRedactionFilter replaces the Headers object only when it redacted something, so this line reads as a dict with a secret present and as Headers({...}) without one. test_filter_preserves_non_sensitive_headers asserts that today:

assert isinstance(log_record.args[0], Headers)

Always converting would change the filter's contract and that test, which is a separate decision from this one. I added a case pinning the current behaviour and naming the consequence, so whoever revisits it sees both halves.

Happy to make the filter always convert, in its own change, if that is what you want.