mirror of
https://github.com/tiennm99/litellm.git
synced 2026-08-05 18:24:49 +00:00
fix(proxy): improve auth exception logging levels and add structured context (#22099)
* fix(proxy): improve auth exception logging levels and add structured context Downgrade expected auth failures (ProxyException, HTTPException < 500, BudgetExceededError) from ERROR to WARNING log level to reduce noise from routine rejected requests (e.g. missing/invalid API keys on polled endpoints like /schedule/model_cost_map_reload/status). Unexpected exceptions and HTTPException with status >= 500 still log at ERROR with full traceback. Enrich log messages with structured context: route, HTTP method, masked API key (using existing abbreviate_api_key), error type, and error code. All fields also passed via log extra dict for log aggregation tools. Fixes #21293 * Update tests/test_litellm/proxy/auth/test_auth_exception_handler.py Co-authored-by: greptile-apps[bot] <165735046+greptile-apps[bot]@users.noreply.github.com> --------- Co-authored-by: greptile-apps[bot] <165735046+greptile-apps[bot]@users.noreply.github.com>
This commit is contained in:
Benedikt Óskarsson
co-authored by
greptile-apps[bot] <165735046+greptile-apps[bot]@users.noreply.github.com>
greptile-apps[bot] <165735046+greptile-apps[bot]@users.noreply.github.com>
parent
f3e31bc8ef
commit
efeaf650aa
@@ -9,7 +9,7 @@ from fastapi import HTTPException, Request, status
|
||||
import litellm
|
||||
from litellm._logging import verbose_proxy_logger
|
||||
from litellm.proxy._types import ProxyErrorTypes, ProxyException, UserAPIKeyAuth
|
||||
from litellm.proxy.auth.auth_utils import _get_request_ip_address
|
||||
from litellm.proxy.auth.auth_utils import _get_request_ip_address, abbreviate_api_key
|
||||
from litellm.proxy.db.exception_handler import PrismaDBExceptionHandler
|
||||
from litellm.types.services import ServiceTypes
|
||||
|
||||
@@ -75,13 +75,69 @@ class UserAPIKeyAuthExceptionHandler:
|
||||
request=request,
|
||||
use_x_forwarded_for=general_settings.get("use_x_forwarded_for", False),
|
||||
)
|
||||
verbose_proxy_logger.exception(
|
||||
"litellm.proxy.proxy_server.user_api_key_auth(): Exception occured - {}\nRequester IP Address:{}".format(
|
||||
str(e),
|
||||
requester_ip,
|
||||
),
|
||||
extra={"requester_ip": requester_ip},
|
||||
|
||||
# Build structured context for the log message
|
||||
masked_key = abbreviate_api_key(api_key=api_key) if api_key else "None"
|
||||
http_method = getattr(request, "method", "UNKNOWN")
|
||||
|
||||
# Extract error category and status code from typed exceptions
|
||||
if isinstance(e, ProxyException):
|
||||
error_type = e.type
|
||||
error_code = e.code
|
||||
elif isinstance(e, HTTPException):
|
||||
error_type = "http_exception"
|
||||
error_code = str(getattr(e, "status_code", "unknown"))
|
||||
elif isinstance(e, litellm.BudgetExceededError):
|
||||
error_type = "budget_exceeded"
|
||||
error_code = "400"
|
||||
else:
|
||||
error_type = type(e).__name__
|
||||
error_code = "401"
|
||||
|
||||
log_extra = {
|
||||
"requester_ip": requester_ip,
|
||||
"route": route,
|
||||
"api_key": masked_key,
|
||||
"error_type": error_type,
|
||||
"error_code": error_code,
|
||||
"http_method": http_method,
|
||||
}
|
||||
|
||||
# Use warning level for expected auth failures to avoid noisy ERROR logs
|
||||
# and full tracebacks for routine rejected requests (e.g. missing/invalid key).
|
||||
# Reserve ERROR + traceback for truly unexpected exceptions and server errors.
|
||||
_is_expected_auth_error = isinstance(
|
||||
e, (ProxyException, litellm.BudgetExceededError)
|
||||
) or (
|
||||
isinstance(e, HTTPException)
|
||||
and getattr(e, "status_code", 500) < 500
|
||||
)
|
||||
if _is_expected_auth_error:
|
||||
verbose_proxy_logger.warning(
|
||||
"Auth failed: error_type={}, error_code={}, route={} {}, api_key={}, ip={} - {}".format(
|
||||
error_type,
|
||||
error_code,
|
||||
http_method,
|
||||
route,
|
||||
masked_key,
|
||||
requester_ip,
|
||||
str(e),
|
||||
),
|
||||
extra=log_extra,
|
||||
)
|
||||
else:
|
||||
verbose_proxy_logger.exception(
|
||||
"Auth exception: error_type={}, error_code={}, route={} {}, api_key={}, ip={} - {}".format(
|
||||
error_type,
|
||||
error_code,
|
||||
http_method,
|
||||
route,
|
||||
masked_key,
|
||||
requester_ip,
|
||||
str(e),
|
||||
),
|
||||
extra=log_extra,
|
||||
)
|
||||
|
||||
# Log this exception to OTEL, Datadog etc
|
||||
user_api_key_dict = UserAPIKeyAuth(
|
||||
|
||||
@@ -152,3 +152,199 @@ async def test_route_passed_to_post_call_failure_hook():
|
||||
mock_post_call_failure_hook.assert_called_once()
|
||||
call_args = mock_post_call_failure_hook.call_args[1]
|
||||
assert call_args["user_api_key_dict"].request_route == test_route
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_expected_auth_errors_log_at_warning_level():
|
||||
"""
|
||||
Expected auth failures (ProxyException, HTTPException < 500, BudgetExceededError)
|
||||
should log at WARNING level, not ERROR, to reduce log noise.
|
||||
"""
|
||||
handler = UserAPIKeyAuthExceptionHandler()
|
||||
|
||||
mock_request = MagicMock()
|
||||
mock_request.method = "GET"
|
||||
mock_request_data = {}
|
||||
mock_route = "/schedule/model_cost_map_reload/status"
|
||||
mock_span = None
|
||||
mock_api_key = "sk-test1234"
|
||||
|
||||
expected_auth_errors = [
|
||||
ProxyException(
|
||||
message="Token not found",
|
||||
type=ProxyErrorTypes.token_not_found_in_db,
|
||||
param="key",
|
||||
code=401,
|
||||
),
|
||||
HTTPException(status_code=401, detail="Invalid API key"),
|
||||
HTTPException(status_code=403, detail="Forbidden"),
|
||||
]
|
||||
|
||||
for error in expected_auth_errors:
|
||||
with patch(
|
||||
"litellm.proxy.proxy_server.general_settings",
|
||||
{"allow_requests_on_db_unavailable": False},
|
||||
), patch.object(
|
||||
verbose_proxy_logger, "warning"
|
||||
) as mock_warning, patch.object(
|
||||
verbose_proxy_logger, "exception"
|
||||
) as mock_exception:
|
||||
try:
|
||||
await handler._handle_authentication_error(
|
||||
error,
|
||||
mock_request,
|
||||
mock_request_data,
|
||||
mock_route,
|
||||
mock_span,
|
||||
mock_api_key,
|
||||
)
|
||||
except Exception:
|
||||
pass
|
||||
|
||||
assert mock_warning.call_count == 1, (
|
||||
f"Expected warning log for {type(error).__name__}, got none"
|
||||
)
|
||||
assert mock_exception.call_count == 0, (
|
||||
f"Did not expect exception log for {type(error).__name__}"
|
||||
)
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_unexpected_errors_log_at_error_level():
|
||||
"""
|
||||
Unexpected exceptions (bare Exception, HTTPException with 500) should
|
||||
still log at ERROR level with full traceback.
|
||||
"""
|
||||
handler = UserAPIKeyAuthExceptionHandler()
|
||||
|
||||
mock_request = MagicMock()
|
||||
mock_request.method = "POST"
|
||||
mock_request_data = {}
|
||||
mock_route = "/chat/completions"
|
||||
mock_span = None
|
||||
mock_api_key = "sk-test1234"
|
||||
|
||||
unexpected_errors = [
|
||||
Exception("Something unexpected broke"),
|
||||
HTTPException(status_code=500, detail="Master key type error"),
|
||||
]
|
||||
|
||||
for error in unexpected_errors:
|
||||
with patch(
|
||||
"litellm.proxy.proxy_server.general_settings",
|
||||
{"allow_requests_on_db_unavailable": False},
|
||||
), patch.object(
|
||||
verbose_proxy_logger, "warning"
|
||||
) as mock_warning, patch.object(
|
||||
verbose_proxy_logger, "exception"
|
||||
) as mock_exception:
|
||||
try:
|
||||
await handler._handle_authentication_error(
|
||||
error,
|
||||
mock_request,
|
||||
mock_request_data,
|
||||
mock_route,
|
||||
mock_span,
|
||||
mock_api_key,
|
||||
)
|
||||
except Exception:
|
||||
pass
|
||||
|
||||
mock_exception.assert_called_once(), (
|
||||
f"Expected exception log for {type(error).__name__}, got none"
|
||||
)
|
||||
mock_warning.assert_not_called(), (
|
||||
f"Did not expect warning log for {type(error).__name__}"
|
||||
)
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_auth_error_log_contains_structured_context():
|
||||
"""
|
||||
Log messages should include route, HTTP method, masked API key, error type,
|
||||
and error code for easier debugging.
|
||||
"""
|
||||
handler = UserAPIKeyAuthExceptionHandler()
|
||||
|
||||
mock_request = MagicMock()
|
||||
mock_request.method = "GET"
|
||||
mock_request_data = {}
|
||||
mock_route = "/schedule/model_cost_map_reload/status"
|
||||
mock_span = None
|
||||
mock_api_key = "sk-test1234"
|
||||
|
||||
error = ProxyException(
|
||||
message="Token not found",
|
||||
type=ProxyErrorTypes.token_not_found_in_db,
|
||||
param="key",
|
||||
code=401,
|
||||
)
|
||||
|
||||
with patch(
|
||||
"litellm.proxy.proxy_server.general_settings",
|
||||
{"allow_requests_on_db_unavailable": False},
|
||||
), patch.object(verbose_proxy_logger, "warning") as mock_warning:
|
||||
try:
|
||||
await handler._handle_authentication_error(
|
||||
error,
|
||||
mock_request,
|
||||
mock_request_data,
|
||||
mock_route,
|
||||
mock_span,
|
||||
mock_api_key,
|
||||
)
|
||||
except Exception:
|
||||
pass
|
||||
|
||||
mock_warning.assert_called_once()
|
||||
log_message = mock_warning.call_args[0][0]
|
||||
log_extra = mock_warning.call_args[1].get("extra", {})
|
||||
|
||||
# Verify structured fields are in the log message
|
||||
assert mock_route in log_message
|
||||
assert "GET" in log_message
|
||||
assert "sk-...1234" in log_message
|
||||
|
||||
# Verify structured extra dict for log aggregation tools
|
||||
assert log_extra["route"] == mock_route
|
||||
assert log_extra["http_method"] == "GET"
|
||||
assert log_extra["api_key"] == "sk-...1234"
|
||||
assert log_extra["error_type"] == ProxyErrorTypes.token_not_found_in_db
|
||||
|
||||
|
||||
@pytest.mark.asyncio
|
||||
async def test_auth_error_log_handles_none_api_key():
|
||||
"""
|
||||
When no API key is provided (None or empty), the log should show 'None'
|
||||
instead of crashing.
|
||||
"""
|
||||
handler = UserAPIKeyAuthExceptionHandler()
|
||||
|
||||
mock_request = MagicMock()
|
||||
mock_request.method = "GET"
|
||||
mock_request_data = {}
|
||||
mock_route = "/test"
|
||||
mock_span = None
|
||||
|
||||
error = Exception("No api key passed in.")
|
||||
|
||||
for empty_key in [None, ""]:
|
||||
with patch(
|
||||
"litellm.proxy.proxy_server.general_settings",
|
||||
{"allow_requests_on_db_unavailable": False},
|
||||
), patch.object(verbose_proxy_logger, "exception") as mock_exception:
|
||||
try:
|
||||
await handler._handle_authentication_error(
|
||||
error,
|
||||
mock_request,
|
||||
mock_request_data,
|
||||
mock_route,
|
||||
mock_span,
|
||||
empty_key,
|
||||
)
|
||||
except Exception:
|
||||
pass
|
||||
|
||||
mock_exception.assert_called_once()
|
||||
log_message = mock_exception.call_args[0][0]
|
||||
assert "None" in log_message
|
||||
|
||||
Reference in New Issue
Block a user