diff --git a/litellm/__init__.py b/litellm/__init__.py index 5d10737e876..e1da202b9ee 100644 --- a/litellm/__init__.py +++ b/litellm/__init__.py @@ -210,6 +210,7 @@ standard_logging_payload_excluded_fields: Optional[List[str]] = ( ) log_raw_request_response: bool = False log_client_error_tracebacks: bool = False +log_auth_failure_key_identity: bool = False request_correlation_in_logs: bool = False redact_messages_in_exceptions: Optional[bool] = False redact_user_api_key_info: Optional[bool] = False diff --git a/litellm/constants.py b/litellm/constants.py index a292b654778..5675a7e1ea5 100644 --- a/litellm/constants.py +++ b/litellm/constants.py @@ -1877,6 +1877,7 @@ LITELLM_SETTINGS_SAFE_DB_OVERRIDES: Final = [ "cost_margin_config", "block_requests_for_models_without_pricing", "budget_exceeded_throttle_percentage", + "log_auth_failure_key_identity", # Every field editable from the Admin UI (proxy_server._GENERAL_SETTINGS_UI_LITELLM_FIELDS) # must be listed here so a DB write from one worker overrides the live litellm attribute on # the others when config reloads; otherwise peer workers stay on their startup value. diff --git a/litellm/proxy/auth/auth_exception_handler.py b/litellm/proxy/auth/auth_exception_handler.py index 9bf7f6cab96..618f0c647ac 100644 --- a/litellm/proxy/auth/auth_exception_handler.py +++ b/litellm/proxy/auth/auth_exception_handler.py @@ -104,6 +104,25 @@ def _with_client_context( return {**request_data, key: {**base, **stamped}} # mutable-ok: logging needs dicts +def _escape_control_chars(value: str) -> str: + return "".join(ch if ch.isprintable() else ch.encode("unicode_escape").decode("ascii") for ch in value) + + +def _identity_log_suffix(resolved_identity: UserAPIKeyAuth | None) -> str: + """Names the owner of the rejected key so the failure log line alone identifies the caller.""" + if resolved_identity is None or not litellm.log_auth_failure_key_identity: + return "" + fields: Final = ( + ("key_alias", resolved_identity.key_alias), + ("user_id", resolved_identity.user_id), + ("user_email", resolved_identity.user_email), + ("team_id", resolved_identity.team_id), + ("team_alias", resolved_identity.team_alias), + ) + known: Final = " ".join(f"{name}={_escape_control_chars(value)}" for name, value in fields if value) + return f"\nKey Identity: {known}" if known else "" + + class UserAPIKeyAuthExceptionHandler: @staticmethod async def _handle_authentication_error( @@ -176,9 +195,10 @@ class UserAPIKeyAuthExceptionHandler: logger: Final = verbose_proxy_stdout_logger if is_quiet_log else verbose_proxy_logger logger.log( logging.WARNING if is_quiet_log else logging.ERROR, - "litellm.proxy.proxy_server.user_api_key_auth(): Exception occured - %s\nRequester IP Address:%s", + "litellm.proxy.proxy_server.user_api_key_auth(): Exception occured - %s\nRequester IP Address:%s%s", e, requester_ip, + _identity_log_suffix(resolved_identity), exc_info=True if litellm.log_client_error_tracebacks or not is_expected_client_error(e) else None, extra=log_extra, ) diff --git a/tests/test_litellm/proxy/auth/test_auth_exception_handler.py b/tests/test_litellm/proxy/auth/test_auth_exception_handler.py index 3edc57af124..521cbd8daad 100644 --- a/tests/test_litellm/proxy/auth/test_auth_exception_handler.py +++ b/tests/test_litellm/proxy/auth/test_auth_exception_handler.py @@ -25,7 +25,7 @@ from prisma.errors import ( UniqueViolationError, ) - +import litellm from litellm._logging import verbose_proxy_logger from litellm.constants import INVALID_VIRTUAL_KEY_ERROR_MARKER from litellm.exceptions import BudgetExceededError @@ -593,6 +593,101 @@ async def test_resolved_identity_exported_on_auth_failure(): assert seeded["model"] == "gpt-4o" +@pytest.mark.asyncio +@pytest.mark.parametrize( + "log_identity_enabled, resolved_identity, expected_fragment, absent_fragment", + [ + pytest.param( + True, + UserAPIKeyAuth( + token="hashed-token", + key_alias="skip-laptop-key", + user_id="skip-user", + user_email="skip@example.com", + team_id="team-123", + team_alias="research-team", + ), + "Key Identity: key_alias=skip-laptop-key user_id=skip-user user_email=skip@example.com " + "team_id=team-123 team_alias=research-team", + None, + id="expired_key_owner_named_in_log", + ), + pytest.param( + True, + UserAPIKeyAuth(token="hashed-token", user_id="skip-user"), + "Key Identity: user_id=skip-user", + "key_alias=", + id="unset_fields_omitted", + ), + pytest.param( + True, + UserAPIKeyAuth(token="hashed-token", team_alias="ops\nRequester IP Address:10.0.0.1"), + "Key Identity: team_alias=ops\\nRequester IP Address:10.0.0.1", + "\nRequester IP Address:10.0.0.1", + id="control_chars_in_alias_cannot_forge_log_lines", + ), + pytest.param(True, None, None, "Key Identity", id="unknown_key_has_no_identity_line"), + pytest.param( + False, + UserAPIKeyAuth(token="hashed-token", key_alias="skip-laptop-key", user_email="skip@example.com"), + None, + "Key Identity", + id="identity_logging_is_opt_in_and_off_by_default", + ), + ], +) +async def test_expired_key_error_log_names_the_key_owner( + log_identity_enabled, resolved_identity, expected_fragment, absent_fragment, caplog, monkeypatch +): + """With `litellm.log_auth_failure_key_identity` on, an expired key rejection is logged with the + key alias, user and team auth already resolved, so an operator can trace the caller from the + log line alone. It defaults off because some deployments must keep PII out of logs.""" + monkeypatch.setattr(litellm, "log_auth_failure_key_identity", log_identity_enabled) + handler = UserAPIKeyAuthExceptionHandler() + expired_key_error = ProxyException( + message="Authentication Error - Expired Key.", + type=ProxyErrorTypes.expired_key, + param="sk-...", + code=status.HTTP_401_UNAUTHORIZED, + ) + + with ( + patch( # test-quality-ok: handler reads proxy_server globals at call time + "litellm.proxy.proxy_server.proxy_logging_obj.post_call_failure_hook", + new_callable=AsyncMock, + return_value=None, + ), + patch("litellm.proxy.auth.auth_exception_handler.seed_request_identity"), + patch( # test-quality-ok: handler reads proxy_server globals at call time + "litellm.proxy.proxy_server.general_settings", + {"allow_requests_on_db_unavailable": False}, + ), + ): + verbose_proxy_logger.propagate = True + try: + with caplog.at_level("ERROR", logger="LiteLLM Proxy"), pytest.raises(ProxyException): + await handler._handle_authentication_error( + expired_key_error, + MagicMock(), + {"model": "gpt-4o"}, + "/v1/chat/completions", + None, + "sk-raw-key", + resolved_identity=resolved_identity, + ) + finally: + verbose_proxy_logger.propagate = False + + records = [r for r in caplog.records if "user_api_key_auth(): Exception occured" in r.getMessage()] + assert len(records) == 1, [r.getMessage() for r in caplog.records] + logged = records[0].getMessage() + assert "Expired Key" in logged and "Requester IP Address:" in logged, logged + if expected_fragment is not None: + assert expected_fragment in logged, logged + if absent_fragment is not None: + assert absent_fragment not in logged, logged + + @pytest.mark.asyncio async def test_auth_failure_without_resolved_identity_still_logs(): """When auth fails before any identity is resolved (e.g. an unknown key), diff --git a/tests/test_litellm/proxy/test_proxy_server.py b/tests/test_litellm/proxy/test_proxy_server.py index df8feb74305..d5b57fcc309 100644 --- a/tests/test_litellm/proxy/test_proxy_server.py +++ b/tests/test_litellm/proxy/test_proxy_server.py @@ -11944,6 +11944,23 @@ def test_prompt_caching_settings_propagate_on_config_reload(monkeypatch, field_n assert getattr(litellm, field_name) == db_value +@pytest.mark.parametrize("worker_value, db_value", [(True, False), (False, True)]) +def test_log_auth_failure_key_identity_follows_db_config_reload(monkeypatch, worker_value, db_value): + """A /config/update that flips `log_auth_failure_key_identity` lands on the DB row; every + worker must take that value on its next config reload, so turning the PII suffix off stops + it without a restart.""" + import litellm.proxy.proxy_server as ps + + monkeypatch.setattr(litellm, "log_auth_failure_key_identity", worker_value) + + pc = ps.ProxyConfig() + pc._apply_litellm_settings_db_values( + pc._prepared_db_settings_values("litellm_settings", {"log_auth_failure_key_identity": db_value}) + ) + + assert litellm.log_auth_failure_key_identity is db_value + + @pytest.mark.asyncio async def test_db_stored_datadog_redaction_settings_apply_before_logger_init(monkeypatch: pytest.MonkeyPatch): """A DB-only litellm_settings row that pairs success_callback: ["datadog"] with