mirror of
https://github.com/BerriAI/litellm.git
synced 2026-09-27 01:22:18 +00:00
Since #37391 every log record went through the secret-redaction regex twice, once in the filter and again in the formatter, and the formatter pass ran on the whole formatted line. At DEBUG level a multi-megabyte request body (a multi-page PDF upload to /v1/ocr) turned each of those lines into ten seconds of synchronous regex work on the event loop, long enough for a Kubernetes liveness probe to restart the pod mid-request. The filter is now the complete scrubber (message, exception text, stack info, and extras) and stamps the record, so the formatters skip records that are already clean. The stdout truncation filter also collapses base64 runs longer than MAX_BASE64_LENGTH_STDOUT_LOG (4096 by default) at every level before the secret regex sees them, so a debug line carrying a request body costs milliseconds instead of seconds.
725 lines
26 KiB
Python
725 lines
26 KiB
Python
import logging
|
|
import logging.config
|
|
import sys
|
|
import time
|
|
import traceback
|
|
from collections.abc import Callable
|
|
from io import StringIO
|
|
from typing import Final
|
|
from unittest.mock import patch
|
|
|
|
import pytest
|
|
|
|
from litellm._logging import (
|
|
JsonFormatter,
|
|
_redact_string,
|
|
_secret_filter,
|
|
redact_internal_details_from_client_message,
|
|
verbose_logger,
|
|
verbose_proxy_logger,
|
|
verbose_router_logger,
|
|
)
|
|
from litellm.litellm_core_utils.secret_redaction import redact_internal_details, redact_string
|
|
|
|
SECRET = "sk-proj-abc123def456ghi789jklmnopqrst"
|
|
|
|
|
|
@pytest.fixture(autouse=True)
|
|
def _enable_redaction():
|
|
"""Ensure secret redaction is on (the default) for all tests in this module."""
|
|
with patch("litellm._logging._ENABLE_SECRET_REDACTION", True):
|
|
yield
|
|
|
|
|
|
def _capture_logger_output(fn):
|
|
"""Run fn with all litellm loggers wired to a StringIO buffer, return output."""
|
|
buf = StringIO()
|
|
h = logging.StreamHandler(buf)
|
|
h.addFilter(_secret_filter)
|
|
loggers = [verbose_logger, verbose_proxy_logger, verbose_router_logger]
|
|
saved = [(lg, lg.handlers[:], lg.level) for lg in loggers]
|
|
for lg in loggers:
|
|
lg.handlers.clear()
|
|
lg.addHandler(h)
|
|
lg.setLevel(logging.DEBUG)
|
|
try:
|
|
fn()
|
|
return buf.getvalue()
|
|
finally:
|
|
for lg, handlers, level in saved:
|
|
lg.handlers.clear()
|
|
for old_h in handlers:
|
|
lg.addHandler(old_h)
|
|
lg.setLevel(level)
|
|
|
|
|
|
def test_redact_string_catches_secret_patterns():
|
|
"""Core regex patterns redact known secret formats."""
|
|
cases = [
|
|
"Bearer eyJhbGciOiJSUzI1NiJ9.payload.sig",
|
|
"api_key=a1b2c3d4e5f6a7b8c9d0e1f2a3b4c5d6",
|
|
"password=supersecretpassword123",
|
|
"postgresql://admin:s3cretpass@db.example.com:5432/mydb",
|
|
SECRET,
|
|
]
|
|
for secret in cases:
|
|
result = redact_string("msg: " + secret)
|
|
assert secret not in result, f"{secret!r} was not redacted"
|
|
assert "REDACTED" in result
|
|
|
|
normal = "Loaded model gpt-4 with 3 replicas on us-east-1"
|
|
assert redact_string(normal) == normal
|
|
|
|
|
|
@pytest.mark.parametrize(
|
|
"connection_string",
|
|
[
|
|
"postgres://admin:pass3cret@db.example.com:5432/mydb",
|
|
"redis://:pass3cret@cache.example.com:6379",
|
|
"postgres://admin:pass/s3cret@db.example.com:5432/mydb",
|
|
"amqp://admin:pass:s3cret@rabbit:5672",
|
|
"https://ad@min:pass3cret@host",
|
|
# An unencoded "@" inside the password, with a ":" after it
|
|
"postgresql://admin:p@ss3cret:2026@db.example.com:5432/mydb",
|
|
"amqp://guest:gu@st3cret:1@rabbit:5672/",
|
|
# An AWS RDS IAM auth token is a presigned query string used as the
|
|
# password, so the userinfo runs to several hundred characters.
|
|
"postgresql://litellm:host%3A5432%2F%3FAction%3Dconnect%26X-Amz-Signature%3D"
|
|
+ "f" * 540
|
|
+ "s3cret@db.host:5432/litellm",
|
|
],
|
|
)
|
|
def test_redact_string_still_catches_connection_string_credentials(connection_string):
|
|
"""The bounded userinfo pattern must keep matching real connection strings."""
|
|
assert "s3cret" not in redact_string(connection_string)
|
|
|
|
|
|
def _redaction_cost(url_bytes: int) -> float:
|
|
url: Final = "/x?u=" + "a://" * (url_bytes // 4)
|
|
|
|
def once() -> float:
|
|
started = time.perf_counter()
|
|
redact_string(url)
|
|
return time.perf_counter() - started
|
|
|
|
return min(once() for _ in range(3))
|
|
|
|
|
|
def test_redact_string_stays_sub_quadratic_on_a_long_adversarial_url():
|
|
"""Access-log redaction runs on attacker-controlled request lines, so quadrupling
|
|
a URL of scheme separators must not multiply the cost by sixteen. Comparing two
|
|
sizes rather than asserting a wall-clock ceiling keeps this honest on a slow box:
|
|
the unbounded pattern this replaced cost 5s at 4 KB and 314s at 16 KB."""
|
|
growth: Final = _redaction_cost(16 * 1024) / _redaction_cost(4 * 1024)
|
|
|
|
assert growth < 11.0, f"cost grew {growth:.1f}x for 4x the URL length"
|
|
|
|
|
|
def test_redact_string_catches_minimum_length_virtual_key():
|
|
"""Regression test for LIT-4355: keys at the enforced 16-char minimum
|
|
(MINIMUM_CUSTOM_KEY_LENGTH) must be treated as key-shaped by the scrubber."""
|
|
minimum_length_key = "sk-abcdefghijklm"
|
|
assert len(minimum_length_key) == 16
|
|
result = redact_string("msg: " + minimum_length_key)
|
|
assert minimum_length_key not in result
|
|
assert "REDACTED" in result
|
|
|
|
|
|
def test_filter_redacts_secrets_in_logger_output():
|
|
def log_messages():
|
|
verbose_logger.debug("Key: " + SECRET)
|
|
verbose_logger.debug("Normal message with no secrets")
|
|
|
|
output = _capture_logger_output(log_messages)
|
|
assert SECRET not in output
|
|
assert "REDACTED" in output
|
|
assert "Normal message with no secrets" in output
|
|
|
|
|
|
def test_filter_redacts_percent_style_args():
|
|
"""Secrets passed as %-style args should be redacted."""
|
|
|
|
def log_messages():
|
|
verbose_logger.debug("key=%s region=%s", SECRET, "us-east-1")
|
|
|
|
output = _capture_logger_output(log_messages)
|
|
assert SECRET not in output
|
|
assert "us-east-1" in output
|
|
|
|
|
|
def test_filter_redacts_non_string_args():
|
|
"""Secrets inside dicts/lists passed as %-style args should be redacted."""
|
|
|
|
def log_messages():
|
|
verbose_logger.debug("Config: %s", {"nested": {"key": SECRET}})
|
|
verbose_logger.debug("Keys: %s", [SECRET])
|
|
|
|
output = _capture_logger_output(log_messages)
|
|
assert SECRET not in output
|
|
assert "REDACTED" in output
|
|
|
|
|
|
def test_filter_redacts_exception_tracebacks():
|
|
"""Secrets embedded in exception messages must be redacted in tracebacks."""
|
|
|
|
def log_messages():
|
|
try:
|
|
raise ValueError(f"Auth failed with key {SECRET}")
|
|
except ValueError:
|
|
verbose_logger.exception("Something went wrong")
|
|
|
|
output = _capture_logger_output(log_messages)
|
|
assert SECRET not in output
|
|
assert "REDACTED" in output
|
|
assert "Something went wrong" in output
|
|
|
|
|
|
def test_filter_redacts_extra_fields():
|
|
"""Secrets passed via extra={...} must be redacted on the record."""
|
|
record = logging.LogRecord(
|
|
name="test",
|
|
level=logging.DEBUG,
|
|
pathname="",
|
|
lineno=0,
|
|
msg="request completed",
|
|
args=(),
|
|
exc_info=None,
|
|
)
|
|
record.api_key = SECRET
|
|
record.region = "us-east-1"
|
|
|
|
_secret_filter.filter(record)
|
|
|
|
assert SECRET not in record.api_key
|
|
assert "REDACTED" in record.api_key
|
|
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):
|
|
record = logging.LogRecord(
|
|
name="test",
|
|
level=logging.DEBUG,
|
|
pathname="",
|
|
lineno=0,
|
|
msg="key=" + SECRET,
|
|
args=(),
|
|
exc_info=None,
|
|
)
|
|
_secret_filter.filter(record)
|
|
assert "sk-proj-" in record.msg
|
|
|
|
|
|
def test_x_api_key_regex_does_not_consume_json_delimiters():
|
|
"""x-api-key pattern must stop before closing quotes/braces so JSON stays valid."""
|
|
# Simulates a JSON log line containing an x-api-key header value
|
|
json_line = '{"headers": {"x-api-key": "secret123"}, "status": 200}'
|
|
result = redact_string(json_line)
|
|
# The secret value should be redacted
|
|
assert "secret123" not in result
|
|
assert "REDACTED" in result
|
|
# Closing delimiter must survive so the line is still valid-ish JSON
|
|
assert '"status": 200' in result
|
|
assert "}" in result
|
|
|
|
|
|
def test_json_excepthook_redacts_secrets():
|
|
"""Unhandled exceptions in JSON mode must have secrets redacted."""
|
|
buf = StringIO()
|
|
h = logging.StreamHandler(buf)
|
|
h.setFormatter(JsonFormatter())
|
|
h.addFilter(_secret_filter)
|
|
|
|
# Capture what the excepthook would emit
|
|
record = logging.LogRecord(
|
|
name="LiteLLM",
|
|
level=logging.ERROR,
|
|
pathname="",
|
|
lineno=0,
|
|
msg=f"Connection failed with key {SECRET}",
|
|
args=(),
|
|
exc_info=None,
|
|
)
|
|
# Simulate the filter + formatter pipeline
|
|
_secret_filter.filter(record)
|
|
output = h.formatter.format(record)
|
|
assert SECRET not in output
|
|
assert "REDACTED" in output
|
|
|
|
|
|
def test_json_excepthook_redacts_traceback_secrets():
|
|
"""Unhandled exception tracebacks in JSON mode must have secrets redacted."""
|
|
buf = StringIO()
|
|
h = logging.StreamHandler(buf)
|
|
h.setFormatter(JsonFormatter())
|
|
h.addFilter(_secret_filter)
|
|
|
|
try:
|
|
raise RuntimeError(f"Failed to auth with {SECRET}")
|
|
except RuntimeError:
|
|
exc_info = sys.exc_info()
|
|
|
|
record = logging.LogRecord(
|
|
name="LiteLLM",
|
|
level=logging.ERROR,
|
|
pathname="",
|
|
lineno=0,
|
|
msg=str(exc_info[1]),
|
|
args=(),
|
|
exc_info=exc_info,
|
|
)
|
|
_secret_filter.filter(record)
|
|
output = h.formatter.format(record)
|
|
assert SECRET not in output
|
|
assert "REDACTED" in output
|
|
|
|
|
|
def test_xai_key_redaction_catches_proxy_log_and_config_dump():
|
|
"""xai_key is redacted in proxy log and config dump formats."""
|
|
cases = [
|
|
("setting litellm.xai_key=xai-test-secret-123456", "xai-test-secret-123456"),
|
|
("'xai_key': 'xai-test-secret-123456'", "xai-test-secret-123456"),
|
|
]
|
|
for secret_line, secret in cases:
|
|
result = redact_string(secret_line)
|
|
assert secret not in result
|
|
assert "REDACTED" in result, f"xai_key redaction missed: {secret_line!r}"
|
|
|
|
|
|
def test_module_level_provider_key_redaction_catches_proxy_log_format():
|
|
"""Provider module-level keys are redacted when logged by proxy startup."""
|
|
cases = [
|
|
("setting litellm.groq_key=gsk-test-secret-123456", "gsk-test-secret-123456"),
|
|
(
|
|
"setting litellm.openai_key=openai-test-secret-123456",
|
|
"openai-test-secret-123456",
|
|
),
|
|
]
|
|
for secret_line, secret in cases:
|
|
result = redact_string(secret_line)
|
|
assert secret not in result
|
|
assert "REDACTED" in result, f"Module-level key redaction missed: {secret_line!r}"
|
|
|
|
safe = "cache_key=cache-value-123456"
|
|
assert redact_string(safe) == safe
|
|
|
|
|
|
def test_key_name_redaction_catches_secrets_in_dict_repr():
|
|
"""Secrets inside dict repr strings are redacted based on key names."""
|
|
cases = [
|
|
# Python dict repr (the exact leak format from the bug report)
|
|
"param_name=general_settings, param_value={'master_key': 'my-random-secret-key-1234', 'enable_jwt_auth': True}",
|
|
# database_url
|
|
"'database_url': 'postgres://admin:password@db.example.com:5432/litellm'",
|
|
# JSON format
|
|
'"database_url": "postgres://admin:password@db.example.com:5432/litellm"',
|
|
# access_token
|
|
"'access_token': 'some-opaque-token-value'",
|
|
# refresh_token
|
|
"refresh_token=my-refresh-tok-12345",
|
|
# auth_token
|
|
"'auth_token': 'random-auth-value'",
|
|
# slack_webhook_url
|
|
"'slack_webhook_url': 'https://hooks.slack.com/services/T00/B00/xxx'",
|
|
]
|
|
for secret_line in cases:
|
|
result = redact_string(secret_line)
|
|
assert "REDACTED" in result, f"Key-name redaction missed: {secret_line!r}"
|
|
|
|
# Non-sensitive keys should NOT be redacted
|
|
safe = "'enable_jwt_auth': True, 'store_model_in_db': True"
|
|
assert redact_string(safe) == safe
|
|
|
|
|
|
def test_key_name_redaction_in_general_settings_dict():
|
|
"""End-to-end: secrets inside a general_settings dict dump are redacted
|
|
when logged through the named litellm loggers."""
|
|
|
|
def log_messages():
|
|
general_settings = {
|
|
"master_key": "my-random-secret-key-1234",
|
|
"database_url": "postgres://admin:password@db.example.com:5432/litellm",
|
|
"enable_jwt_auth": True,
|
|
"store_model_in_db": True,
|
|
}
|
|
verbose_proxy_logger.debug(f"param_name=general_settings, param_value={general_settings}")
|
|
|
|
output = _capture_logger_output(log_messages)
|
|
assert "my-random-secret-key-1234" not in output
|
|
assert "REDACTED" in output
|
|
# Non-sensitive values should survive
|
|
assert "enable_jwt_auth" in output
|
|
|
|
|
|
# ── GCP service-account / Vertex credential redaction ──
|
|
|
|
|
|
_SAMPLE_SA_JSON = (
|
|
'{"type": "service_account", "project_id": "my-proj-123", '
|
|
'"private_key_id": "abc123def", '
|
|
'"private_key": "-----BEGIN PRIVATE KEY-----\\nMIIEvQIBADANBgkq\\n-----END PRIVATE KEY-----\\n", '
|
|
'"client_email": "sa@my-proj.iam.gserviceaccount.com", '
|
|
'"client_id": "123456789"}'
|
|
)
|
|
|
|
|
|
def test_pem_private_key_redacted_in_json():
|
|
result = redact_string(_SAMPLE_SA_JSON)
|
|
assert "MIIEvQIBADA" not in result
|
|
assert "-----BEGIN" not in result
|
|
|
|
|
|
def test_pem_private_key_redacted_in_dict_repr():
|
|
import json
|
|
|
|
sa = json.loads(_SAMPLE_SA_JSON)
|
|
result = redact_string(str(sa))
|
|
assert "MIIEvQIBADA" not in result
|
|
|
|
|
|
def test_service_account_blob_fully_redacted():
|
|
result = redact_string(f"Got={_SAMPLE_SA_JSON}")
|
|
assert "my-proj-123" not in result
|
|
assert "sa@my-proj.iam.gserviceaccount.com" not in result
|
|
assert "abc123def" not in result
|
|
assert "MIIEvQIBADA" not in result
|
|
|
|
|
|
def test_vertex_error_message_no_credential_leak():
|
|
"""The old Vertex error format leaked the full credential JSON.
|
|
The new format must not contain any credential material."""
|
|
new_msg = (
|
|
"Unable to load vertex credentials from environment. "
|
|
"Ensure the JSON is valid (check for unescaped newlines in private_key). "
|
|
"Parse error: JSONDecodeError"
|
|
)
|
|
result = _redact_string(new_msg)
|
|
assert result == new_msg # nothing to redact
|
|
|
|
|
|
def test_vertex_traceback_redacts_pem():
|
|
traceback_text = (
|
|
"Traceback (most recent call last):\n"
|
|
' File "vertex_llm_base.py", line 95\n'
|
|
" json_obj = json.loads(credentials)\n"
|
|
"json.decoder.JSONDecodeError: Invalid control character\n"
|
|
"Failed to load vertex credentials. Error: "
|
|
"Unable to load vertex credentials from environment. "
|
|
f"Got={_SAMPLE_SA_JSON}"
|
|
)
|
|
result = redact_string(traceback_text)
|
|
assert "MIIEvQIBADA" not in result
|
|
assert "-----BEGIN" not in result
|
|
|
|
|
|
def test_gcp_oauth_token_redacted():
|
|
result = redact_string("access token ya29.c.c0ASRK0GZvXlongtokenhere")
|
|
assert "ya29." not in result
|
|
assert "REDACTED" in result
|
|
|
|
|
|
def test_non_pem_private_key_value_redacted():
|
|
result = redact_string("'private_key': 'some-non-pem-secret-value'")
|
|
assert "some-non-pem-secret" not in result
|
|
|
|
|
|
def test_normal_vertex_log_not_redacted():
|
|
msg = "Vertex: Loading vertex credentials, is_file_path=True, current dir /app"
|
|
assert redact_string(msg) == msg
|
|
|
|
|
|
THIRD_PARTY_LOGGERS = (
|
|
"apscheduler.executors.default",
|
|
"apscheduler.scheduler",
|
|
"asyncio",
|
|
"backoff",
|
|
"httpx",
|
|
"uvicorn.error",
|
|
)
|
|
|
|
|
|
def _capture_from_logger(logger_name: str, emit: Callable[[logging.Logger], None]) -> str:
|
|
"""Emit via `logger_name` and return only that logger's output as seen by a root handler.
|
|
|
|
A handler on the root logger stands in for a log-shipping sink litellm does not own.
|
|
The name predicate keeps the assertion scoped to the logger under test, so records
|
|
from any other logger cannot decide the result.
|
|
|
|
This idiom only reaches root when nothing between the logger and root stops
|
|
propagation. `callHandlers` re-checks `propagate` at every level as it walks up, so
|
|
an ANCESTOR with `propagate = False` ends the walk early and this returns an empty
|
|
string no matter what was emitted; forcing it on the logger under test, as done
|
|
below, is not enough. For a logger whose ancestors are configured that way, attach
|
|
the capture handler to the logger itself and assert on that instead, and always
|
|
assert the captured output is non-empty so a silent miss cannot pass.
|
|
"""
|
|
buf = StringIO()
|
|
handler = logging.StreamHandler(buf)
|
|
handler.addFilter(lambda record: record.name == logger_name)
|
|
lg = logging.getLogger(logger_name)
|
|
saved = (lg.level, lg.propagate, logging.root.level)
|
|
lg.setLevel(logging.DEBUG)
|
|
lg.propagate = True
|
|
logging.root.setLevel(logging.DEBUG)
|
|
logging.root.addHandler(handler)
|
|
try:
|
|
emit(lg)
|
|
return buf.getvalue()
|
|
finally:
|
|
logging.root.removeHandler(handler)
|
|
lg.setLevel(saved[0])
|
|
lg.propagate = saved[1]
|
|
logging.root.setLevel(saved[2])
|
|
|
|
|
|
def test_third_party_logger_messages_are_redacted():
|
|
for logger_name in THIRD_PARTY_LOGGERS:
|
|
output = _capture_from_logger(logger_name, lambda lg: lg.error("value %s", SECRET))
|
|
|
|
assert output.strip(), f"no record captured for {logger_name}"
|
|
assert SECRET not in output, f"{logger_name} leaked a secret"
|
|
assert "REDACTED" in output, f"{logger_name} was not redacted"
|
|
|
|
|
|
def test_third_party_logger_tracebacks_are_redacted():
|
|
def emit(lg: logging.Logger) -> None:
|
|
try:
|
|
raise ValueError("value " + SECRET)
|
|
except ValueError:
|
|
lg.error("call failed", exc_info=True)
|
|
|
|
for logger_name in THIRD_PARTY_LOGGERS:
|
|
output = _capture_from_logger(logger_name, emit)
|
|
|
|
assert output.strip(), f"no record captured for {logger_name}"
|
|
assert SECRET not in output, f"{logger_name} leaked a secret in a traceback"
|
|
assert "REDACTED" in output, f"{logger_name} traceback was not redacted"
|
|
|
|
|
|
UVICORN_LOGGERS = ("uvicorn", "uvicorn.error", "uvicorn.access")
|
|
|
|
|
|
def test_redaction_survives_uvicorn_logging_reconfiguration():
|
|
"""Proxy startup hands uvicorn a logging config, and `dictConfig` replaces the handlers
|
|
of every logger it names. Redaction is attached to the logger rather than to a handler
|
|
so that it outlives that; moving it onto a handler would fail here.
|
|
|
|
The config below is written out rather than imported from the one litellm ships on
|
|
purpose. What is under test is `dictConfig` semantics, so any config that names the
|
|
loggers exercises it; importing the real one would add coupling without adding
|
|
coverage. The capture reads the reconfigured logger's own handler because the config
|
|
sets `propagate = False`, which is where uvicorn's handler sits in a running proxy.
|
|
"""
|
|
saved = tuple(
|
|
(logging.getLogger(name), logging.getLogger(name).handlers[:], logging.getLogger(name).level)
|
|
for name in UVICORN_LOGGERS
|
|
)
|
|
uvicorn_shaped_config: dict[str, object] = {
|
|
"version": 1,
|
|
"disable_existing_loggers": False,
|
|
"handlers": {"default": {"class": "logging.StreamHandler"}},
|
|
"loggers": {name: {"handlers": ["default"], "level": "INFO", "propagate": False} for name in UVICORN_LOGGERS},
|
|
}
|
|
try:
|
|
logging.config.dictConfig(uvicorn_shaped_config)
|
|
|
|
for logger_name in THIRD_PARTY_LOGGERS:
|
|
filters = logging.getLogger(logger_name).filters
|
|
assert _secret_filter in filters, f"{logger_name} lost redaction across reconfiguration"
|
|
|
|
buf = StringIO()
|
|
reconfigured = logging.getLogger("uvicorn.error")
|
|
reconfigured.addHandler(logging.StreamHandler(buf))
|
|
reconfigured.setLevel(logging.DEBUG)
|
|
reconfigured.error("value %s", SECRET)
|
|
output = buf.getvalue()
|
|
|
|
assert output.strip(), "no record captured for uvicorn.error"
|
|
assert SECRET not in output, "uvicorn.error leaked a secret after reconfiguration"
|
|
assert "REDACTED" in output, "uvicorn.error was not redacted after reconfiguration"
|
|
finally:
|
|
for lg, handlers, level in saved:
|
|
lg.handlers[:] = handlers
|
|
lg.setLevel(level)
|
|
lg.propagate = True
|
|
|
|
|
|
def test_aws_credential_redaction_catches_quoted_values():
|
|
"""AWS creds appear as quoted dict-repr values, not just bare key=value."""
|
|
cases = (
|
|
"{'aws_secret_access_key': 'wJalrXUtnFEMIK7MDENGbPxRfiCYEXAMPLEKEY'}",
|
|
'{"aws_session_token": "IQoJb3JpZ2luX2VjEaCXVzLWVhc3QtMSJHMEUCIQ"}',
|
|
"aws_session_token: 'FwoGZXIvYXdzEBYaDHh4eHh4eHh4eHh4eCLLAe'",
|
|
"aws_secret_access_key=wJalrXUtnFEMIK7MDENGbPxRfiCYEXAMPLEKEY",
|
|
"{'aws_access_key_id': 'not-an-akia-shaped-value'}",
|
|
)
|
|
for secret_line in cases:
|
|
result = redact_string(secret_line)
|
|
assert "REDACTED" in result, f"AWS redaction missed: {secret_line!r}"
|
|
assert "wJalrXUtnFEMIK7MDENGbPxRfiCYEXAMPLEKEY" not in result
|
|
assert "IQoJb3JpZ2luX2VjEaCXVzLWVhc3QtMSJHMEUCIQ" not in result
|
|
|
|
safe = "'aws_region_name': 'us-east-1'"
|
|
assert redact_string(safe) == safe
|
|
|
|
|
|
@pytest.mark.parametrize(
|
|
"extra",
|
|
(
|
|
{"api_base": {f"https://host/v1?key={SECRET}"}},
|
|
{"blob": {"authorization": f"Bearer {SECRET}"}},
|
|
{"blob": [f"Bearer {SECRET}"]},
|
|
{"blob": ({"nested": {"deep": SECRET}},)},
|
|
{"master_key": "opaque-value-with-no-pattern"},
|
|
),
|
|
ids=("set", "dict", "list", "nested", "key_name"),
|
|
)
|
|
def test_json_formatter_redacts_non_string_extra_values(extra):
|
|
"""Container extras and key-named str extras must come out scrubbed, whichever of the
|
|
filter and the formatter does the work."""
|
|
buf = StringIO()
|
|
handler = logging.StreamHandler(buf)
|
|
handler.setFormatter(JsonFormatter())
|
|
handler.addFilter(_secret_filter)
|
|
|
|
logger = logging.getLogger("test_json_extra_redaction")
|
|
logger.handlers = [handler]
|
|
logger.setLevel(logging.DEBUG)
|
|
logger.propagate = False
|
|
try:
|
|
logger.warning("request sent", extra=extra)
|
|
finally:
|
|
logger.handlers = []
|
|
|
|
output = buf.getvalue()
|
|
assert output.strip(), "no record captured"
|
|
assert SECRET not in output, f"non-string extra leaked a secret: {output}"
|
|
assert "REDACTED" in output
|
|
|
|
|
|
@pytest.mark.parametrize(
|
|
"text,leaked",
|
|
(
|
|
("config file /etc/litellm/secrets/db.yaml", "/etc/litellm/secrets/db.yaml"),
|
|
("home dir /Users/admin/.litellm/master_key.txt", "/Users/admin/.litellm/master_key.txt"),
|
|
("cache at /var/cache/litellm/tokens.db", "/var/cache/litellm/tokens.db"),
|
|
("path C:\\Users\\admin\\secrets.env", "C:\\Users\\admin\\secrets.env"),
|
|
("connecting to host 10.20.30.40", "10.20.30.40"),
|
|
("connecting to host 192.168.1.5", "192.168.1.5"),
|
|
("connecting to host 172.16.0.9", "172.16.0.9"),
|
|
("connecting to host 127.0.0.1", "127.0.0.1"),
|
|
("connecting to db-primary.internal", "db-primary.internal"),
|
|
("connecting to redis.corp", "redis.corp"),
|
|
),
|
|
)
|
|
def test_redact_internal_details_catches_paths_and_hostnames(text, leaked):
|
|
result = redact_internal_details(text)
|
|
assert leaked not in result, f"{leaked!r} was not redacted"
|
|
assert "REDACTED" in result
|
|
|
|
|
|
def test_redact_internal_details_leaves_public_hostnames_and_routes_alone():
|
|
"""litellm's own error messages rely on routes like /v1/models staying legible."""
|
|
safe_strings = (
|
|
"call https://api.openai.com/v1/chat/completions",
|
|
"/chat/completions: Invalid model name passed in model=gpt-9",
|
|
"Call `/v1/models` to view available models for your key",
|
|
"reducto:// file IDs are not accepted through the proxy OCR API",
|
|
)
|
|
for text in safe_strings:
|
|
assert redact_internal_details(text) == text
|
|
|
|
|
|
def test_redact_internal_details_layers_on_top_of_credential_redaction():
|
|
text = "postgresql://litellm_internal:S3cr3tPGPass@10.20.30.40:5432/litellm_prod"
|
|
result = redact_internal_details(text)
|
|
assert "S3cr3tPGPass" not in result
|
|
assert "10.20.30.40" not in result
|
|
|
|
|
|
def test_redact_internal_details_drops_embedded_traceback():
|
|
"""Regression for LIT-6747: the traceback exception_type() embeds for SDK callers
|
|
must never reach an HTTP client."""
|
|
try:
|
|
raise RuntimeError("socket hung up")
|
|
except RuntimeError:
|
|
raw_tb = traceback.format_exc()
|
|
message = f"litellm.APIConnectionError: MinimaxException - socket hung up\n{raw_tb}"
|
|
|
|
result = redact_internal_details(message)
|
|
|
|
assert result == "litellm.APIConnectionError: MinimaxException - socket hung up"
|
|
assert "Traceback (most recent call last)" not in result
|
|
assert __file__.split("/")[-1] not in result
|
|
|
|
|
|
def test_redact_internal_details_from_client_message_respects_disable_flag():
|
|
with patch("litellm._logging._ENABLE_SECRET_REDACTION", False): # test-quality-ok: the opt-out flag is the SUT
|
|
text = "config file /etc/litellm/secrets/db.yaml"
|
|
assert redact_internal_details_from_client_message(text) == text
|