fix(proxy): log key owner identity on expired key auth failures (#43105)

* fix(proxy): log key owner identity on expired key auth failures

Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>

* fix(proxy): escape control characters in logged key identity fields

Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>

* feat(proxy): gate key identity in auth failure logs behind log_auth_failure_key_identity

Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>

* fix(proxy): apply log_auth_failure_key_identity from DB config reloads

Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>

---------

Co-authored-by: mrinal <mrinal@berri.ai>
Co-authored-by: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>
This commit is contained in:
devin-ai-integration[bot] 2026-09-28 08:18:48 -07:00 • committed by GitHub
parent c60c714278
commit f191e08d67
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
5 changed files with 136 additions and 2 deletions

View file

@ -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

View file

@ -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.

View file

@ -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,
)

View file

@ -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),

View file

@ -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