fix(logging): preserve uvicorn color_message args during secret redaction (#37122)

* fix(logging): preserve uvicorn color_message args during secret redaction

SecretRedactionFilter clears record.args after substituting record.msg, but
uvicorn's colorized formatter re-renders the separate color_message extra
field against record.args at emit time. With args cleared, uvicorn prints
the raw "%s://%s:%d" template instead of the actual startup URL whenever
output goes to a TTY (colors on).

* fix(logging): narrow color_message fallback to TypeError

Bare except-Exception-pass on the color_message substitution pushed the
BLE001 and S110 strict-rule budgets over their ceiling. Narrow to the one
exception the %-format can actually raise and give it a real fallback
instead of silently swallowing it.

* refactor(logging): move color_message substitution into a helper

The two record.color_message stores put LIT011 over its ceiling. Building the
value in a pure helper leaves one store, marked rebind-ok since scrubbing a
record in place is the logging.Filter contract.

Also pins the ordering that makes the substitution safe: it has to run before
args are cleared, which puts it before the extra-field loop that redacts the
result, so a secret arriving through record.args is still scrubbed out of
color_message.

litellm/_logging.py

@@ -88,6 +88,24 @@ def redact_secrets(value: str) -> str:
     return _redact_string(value)
 
 
+def _substituted_color_message(record: logging.LogRecord) -> str | None:
+    """Render a record's ``color_message`` against its args, or None if absent.
+
+    uvicorn's colorized formatter re-renders `color_message` against
+    record.args at emit time (see uvicorn.logging.ColourizedFormatter) instead
+    of using the already-formatted record.msg, so it has to be substituted
+    before args are cleared or it is later formatted with no args and prints
+    the raw "%s://%s:%d" placeholders instead of the URL.
+    """
+    color_message: Final = record.__dict__.get("color_message")
+    if not isinstance(color_message, str) or not record.args:
+        return None
+    try:
+        return color_message % record.args
+    except TypeError:
+        return color_message
+
+
 class SecretRedactionFilter(logging.Filter):
     """Scrubs known secret/credential patterns from log records."""
 
@@ -97,6 +115,12 @@ class SecretRedactionFilter(logging.Filter):
         if not _ENABLE_SECRET_REDACTION:
             return True
 
+        # Runs before args are cleared, and before the extra-field loop below
+        # that redacts the substituted result.
+        substituted_color_message: Final = _substituted_color_message(record)
+        if substituted_color_message is not None:
+            record.color_message = substituted_color_message  # rebind-ok: a Filter scrubs records in place
+
         try:
             record.msg = _redact_string(record.getMessage())
             record.args = None

tests/test_litellm/test_secret_redaction.py

@@ -147,6 +147,71 @@ def test_filter_redacts_extra_fields():
     assert record.region == "us-east-1"
 
 
+def test_filter_preserves_uvicorn_color_message_args():
+    """Regression test: uvicorn's startup banner logs a plain message plus a
+    colorized `extra={"color_message": ...}` copy of the same "%s://%s:%d" template,
+    both meant to be filled in from record.args. uvicorn's own ColourizedFormatter
+    re-substitutes color_message against record.args when writing to a TTY, instead
+    of using the already-formatted record.msg.
+
+    Before this fix, the filter cleared record.args after substituting only
+    record.msg, so color_message was rendered with args=None and the raw
+    "%s://%s:%d" placeholders were printed instead of the real host/port.
+    """
+    from uvicorn.logging import DefaultFormatter
+
+    addr_format = "%s://%s:%d"
+    plain_message = f"Uvicorn running on {addr_format} (Press CTRL+C to quit)"
+    color_message = f"Uvicorn running on {addr_format} (Press CTRL+C to quit)"
+
+    logger = logging.getLogger("uvicorn.error")
+    saved_handlers, saved_level = logger.handlers[:], logger.level
+    buf = StringIO()
+    handler = logging.StreamHandler(buf)
+    formatter = DefaultFormatter("%(levelprefix)s %(message)s")
+    formatter.use_colors = True
+    handler.setFormatter(formatter)
+    logger.handlers = [handler]
+    logger.setLevel(logging.INFO)
+    try:
+        logger.info(
+            plain_message,
+            "http",
+            "0.0.0.0",
+            4000,
+            extra={"color_message": color_message},
+        )
+        output = buf.getvalue()
+    finally:
+        logger.handlers = saved_handlers
+        logger.setLevel(saved_level)
+
+    assert "%s" not in output and "%d" not in output, f"unsubstituted placeholders leaked: {output!r}"
+    assert "http://0.0.0.0:4000" in output
+
+
+def test_filter_redacts_secrets_substituted_into_color_message():
+    """The color_message substitution runs before the extra-field redaction
+    loop, so a secret arriving through record.args lands in color_message and
+    must still be scrubbed. Substituting after that loop would ship the secret
+    to any colorized handler."""
+    record = logging.LogRecord(
+        name="uvicorn.error",
+        level=logging.INFO,
+        pathname=__file__,
+        lineno=1,
+        msg="connecting with %s",
+        args=(SECRET,),
+        exc_info=None,
+    )
+    record.color_message = "connecting with %s"
+
+    _secret_filter.filter(record)
+
+    assert SECRET not in record.color_message
+    assert "REDACTED" in record.color_message
+
+
 def test_disable_redaction_passes_secrets_through():
     """When LITELLM_DISABLE_REDACT_SECRETS=true, secrets pass through."""
     with patch("litellm._logging._ENABLE_SECRET_REDACTION", False):