scriptoriumadmin/litellm
1
0
Fork 0
mirror of https://github.com/BerriAI/litellm.git synced 2026-09-05 08:07:05 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions 137

fix(auth): quiet malformed virtual key rejections to stdout (#38838)

Browse source 
* fix(auth): quiet malformed virtual key rejections to stdout

Reduce noisy invalid-api-key error logs by classifying malformed virtual
keys and routing their rejections to stdout as WARNING instead of stderr
as ERROR. Suppressible via LITELLM_LOG=ERROR or log_client_error_tracebacks=true.

Changes:
- auth_utils: is_invalid_virtual_key_error() classifier and marker functions
- auth_exception_handler: log invalid keys as WARNING to child logger before
  identity seeding and callbacks, escalate non-401 transforms to ERROR
- user_api_key_auth: websocket early-raise WebSocketException(1008) to avoid
  double-logging at HTTP layer
- _logging: child logger verbose_proxy_stdout_logger with no handler/level;
  LevelRoutingStreamHandler routes its WARNING records to stdout; handler
  setLevel in _turn_on_json() closes JSON config handler level leak
- test_auth_exception_handler: new test case verifying malformed-key logs
  at WARNING with marker retention through transformations

Fixes LIT-5362

* fix(auth): classify malformed-key 401 by raise-site marker, not message text

Review round 1 (Greptile P2, veria Low):
- Move the marker attribute name to litellm/constants.py per the shared
  sentinel convention
- Stamp the marker on the malformed-key 401 where it is raised and classify
  only by it. Message text is caller-influenceable on other 401s (vector
  store ids, organization ids are interpolated into their messages), so a
  phrase match would let a request body demote an authorization failure to
  the quiet log path
- Regression test: a 401 carrying the phrase but not the marker stays at
  ERROR on stderr
This commit is contained in:
yucheng-berri 2026-08-31 18:19:40 -07:00 • committed by GitHub
parent b473339ac0
commit 3fadcd7155
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
6 changed files with 162 additions and 50 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

15
litellm/_logging.py
View file

@ -264,13 +264,17 @@ def _plain_log_format(stdout: TextIO | None, stderr: TextIO | None) -> str:
class LevelRoutingStreamHandler(logging.StreamHandler):
"""Writes records below WARNING to stdout and WARNING and above to stderr.
"""Writes records below WARNING and invalid-key warnings to stdout, others to stderr.
Collectors that derive severity from the stream report every stderr line as an error.
Invalid-key warnings route to stdout so LITELLM_LOG=ERROR can suppress them.
"""
def emit(self, record: logging.LogRecord) -> None:
preferred: Final = sys.stdout if record.levelno < logging.WARNING else sys.stderr
is_stdout_record: Final = record.levelno < logging.WARNING or (
record.levelno == logging.WARNING and record.name == verbose_proxy_stdout_logger.name
)
preferred: Final = sys.stdout if is_stdout_record else sys.stderr
if preferred is None or getattr(preferred, "closed", False):
self.stream = sys.stderr # rebind-ok: fall back to the pre-fix stream rather than raising per record
else:
@ -508,6 +512,9 @@ else:
handler.setFormatter(formatter)
verbose_proxy_logger = logging.getLogger("LiteLLM Proxy")
# Malformed virtual key rejections log through this child; LevelRoutingStreamHandler
# writes its WARNING records to stdout. It has no handler or level of its own.
verbose_proxy_stdout_logger: Final = verbose_proxy_logger.getChild("stdout")
verbose_router_logger = logging.getLogger("LiteLLM Router")
verbose_logger = logging.getLogger("LiteLLM")
@ -520,6 +527,7 @@ verbose_logger.addHandler(handler)
# handlers (JSON mode, uvicorn log config, a host app's root handler).
verbose_router_logger.addFilter(_stdout_truncation_filter)
verbose_proxy_logger.addFilter(_stdout_truncation_filter)
verbose_proxy_stdout_logger.addFilter(_stdout_truncation_filter)
verbose_logger.addFilter(_stdout_truncation_filter)
@ -683,6 +691,7 @@ def _turn_on_json():
- Adds a JSON formatter to all loggers
"""
handler: Final = LevelRoutingStreamHandler()
handler.setLevel(numeric_level)
handler.setFormatter(JsonFormatter())
_initialize_loggers_with_handler(handler)
# Set up exception handlers
@ -700,12 +709,14 @@ def _disable_debugging():
verbose_logger.disabled = True
verbose_router_logger.disabled = True
verbose_proxy_logger.disabled = True
verbose_proxy_stdout_logger.disabled = True
def _enable_debugging():
verbose_logger.disabled = False
verbose_router_logger.disabled = False
verbose_proxy_logger.disabled = False
verbose_proxy_stdout_logger.disabled = False
def print_verbose(print_statement):

6
litellm/constants.py
View file

@ -1427,6 +1427,12 @@ DEFAULT_SOFT_BUDGET: Final = float(
) # by default all litellm proxy keys have a soft budget of 50.0
# makes it clear this is a rate limit error for a litellm virtual key
RATE_LIMIT_ERROR_MESSAGE_FOR_VIRTUAL_KEY: Final = "LiteLLM Virtual Key user_api_key_hash"
# Prefix of the 401 raised when a submitted virtual key is not shaped like one.
INVALID_VIRTUAL_KEY_ERROR_MESSAGE: Final = "LiteLLM Virtual Key expected"
# Attribute stamped on that 401 at its raise site so log routing recognises it by
# provenance. Message text is caller-influenceable on other 401s, so it must not
# be used to classify.
INVALID_VIRTUAL_KEY_ERROR_MARKER: Final = "_litellm_invalid_virtual_key_error"
# Python garbage collection threshold configuration
# Format: "gen0,gen1,gen2" e.g., "1000,50,50"

103
litellm/proxy/auth/auth_exception_handler.py
View file

@ -2,13 +2,14 @@
Handles Authentication Errors
"""
import logging
from collections.abc import Mapping
from typing import TYPE_CHECKING, Any, Final
from fastapi import HTTPException, Request, status
import litellm
from litellm._logging import verbose_proxy_logger
from litellm._logging import verbose_proxy_logger, verbose_proxy_stdout_logger
from litellm.constants import EMPTY_MAPPING
from litellm.integrations.otel.runtime import seed_request_identity
from litellm.litellm_core_utils.core_helpers import is_expected_client_error
@ -18,7 +19,11 @@ from litellm.proxy._types import (
ProxyException,
UserAPIKeyAuth,
)
from litellm.proxy.auth.auth_utils import _get_request_ip_address
from litellm.proxy.auth.auth_utils import (
_get_request_ip_address,
is_invalid_virtual_key_error,
mark_invalid_virtual_key_error,
)
from litellm.proxy.db.exception_handler import PrismaDBExceptionHandler
from litellm.types.services import ServiceTypes
@ -36,6 +41,41 @@ else:
Span = Any
def _as_proxy_exception(e: Exception) -> ProxyException:
"""Convert an authentication failure into the ProxyException the client receives."""
if isinstance(e, litellm.BudgetExceededError):
return ProxyException(
message=e.message,
type=ProxyErrorTypes.budget_exceeded,
param=None,
code=getattr(e, "status_code", status.HTTP_429_TOO_MANY_REQUESTS),
)
if isinstance(e, HTTPException):
return ProxyException(
message=getattr(e, "detail", f"Authentication Error({e})"),
type=ProxyErrorTypes.auth_error,
param=getattr(e, "param", "None"),
code=getattr(e, "status_code", status.HTTP_401_UNAUTHORIZED),
)
if isinstance(e, ProxyException):
return e
if PrismaDBExceptionHandler.is_database_service_unavailable_error(e):
return ProxyException(
message=(
"Service Unavailable, the authentication database is temporarily unreachable. Please retry shortly."
),
type=ProxyErrorTypes.no_db_connection,
param="None",
code=status.HTTP_503_SERVICE_UNAVAILABLE,
)
return ProxyException(
message="Authentication Error, " + str(e),
type=ProxyErrorTypes.auth_error,
param=getattr(e, "param", "None"),
code=status.HTTP_401_UNAUTHORIZED,
)
def _with_requester_ip_address(request_data: dict[str, object], requester_ip: str | None) -> dict[str, object]:
"""Auth gate rejections are raised before `add_litellm_data_to_request` records the
caller IP, so their failure logs would otherwise carry no IP nor key/user identity."""
@ -110,16 +150,21 @@ class UserAPIKeyAuthExceptionHandler:
request=request,
use_x_forwarded_for=general_settings.get("use_x_forwarded_for") is True,
)
log_fn: Final = (
verbose_proxy_logger.error
if is_expected_client_error(e) and not litellm.log_client_error_tracebacks
else verbose_proxy_logger.exception
)
log_fn(
# Log authentication failures before identity seeding and callbacks, so the log
# survives a raising callback pipeline. Classify and route malformed virtual-key
# rejections to WARNING on stdout (suppressible via LITELLM_LOG=ERROR).
log_extra: Final = {"requester_ip": requester_ip}
is_invalid_virtual_key: Final = is_invalid_virtual_key_error(e)
is_quiet_log: Final = is_invalid_virtual_key and not litellm.log_client_error_tracebacks
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",
e,
requester_ip,
extra={"requester_ip": requester_ip},
exc_info=True if litellm.log_client_error_tracebacks or not is_expected_client_error(e) else None,
extra=log_extra,
)
# Log this exception to OTEL, Datadog etc. Reuse the identity resolved
@ -167,35 +212,13 @@ class UserAPIKeyAuthExceptionHandler:
if transformed_exception is not None:
e = transformed_exception
if isinstance(e, litellm.BudgetExceededError):
raise ProxyException(
message=e.message,
type=ProxyErrorTypes.budget_exceeded,
param=None,
code=getattr(e, "status_code", status.HTTP_429_TOO_MANY_REQUESTS),
final_exception: Final = mark_invalid_virtual_key_error(_as_proxy_exception(e), is_invalid_virtual_key)
# If a quiet-logged malformed-key transform yields non-401, escalate to ERROR
if is_quiet_log and str(final_exception.code) != str(status.HTTP_401_UNAUTHORIZED):
verbose_proxy_logger.error(
"litellm.proxy.proxy_server.user_api_key_auth(): Exception occured - %s\nRequester IP Address:%s",
final_exception,
requester_ip,
extra=log_extra,
)
if isinstance(e, HTTPException):
raise ProxyException(
message=getattr(e, "detail", f"Authentication Error({e})"),
type=ProxyErrorTypes.auth_error,
param=getattr(e, "param", "None"),
code=getattr(e, "status_code", status.HTTP_401_UNAUTHORIZED),
)
elif isinstance(e, ProxyException):
raise e
if PrismaDBExceptionHandler.is_database_service_unavailable_error(e):
raise ProxyException(
message=(
"Service Unavailable, the authentication database is "
"temporarily unreachable. Please retry shortly."
),
type=ProxyErrorTypes.no_db_connection,
param="None",
code=status.HTTP_503_SERVICE_UNAVAILABLE,
)
raise ProxyException(
message="Authentication Error, " + str(e),
type=ProxyErrorTypes.auth_error,
param=getattr(e, "param", "None"),
code=status.HTTP_401_UNAUTHORIZED,
)
raise final_exception

38
litellm/proxy/auth/auth_utils.py
View file

@ -15,6 +15,7 @@ from litellm._logging import verbose_proxy_logger
from litellm.constants import (
BATCH_ENQUEUED_TOKEN_LIMIT_METADATA_KEY,
EMPTY_MAPPING,
INVALID_VIRTUAL_KEY_ERROR_MARKER,
MINIMUM_CUSTOM_KEY_LENGTH,
STANDARD_CUSTOMER_ID_HEADERS,
)
@ -34,6 +35,43 @@ from litellm.types.router import CONFIGURABLE_CLIENTSIDE_AUTH_PARAMS
from litellm.types.utils import CustomPricingLiteLLMParams
def is_invalid_virtual_key_error(exception: BaseException | None) -> bool:
"""True when an authentication error rejects a malformed virtual key.
Classifies only by the marker stamped where that 401 is raised. Message
content is never inspected: other 401s interpolate caller-supplied values
(vector store ids, organization ids) into their messages, so a phrase
match would let a request body demote an authorization failure to the
quiet log path.
"""
if not isinstance(exception, (HTTPException, ProxyException)):
return False
code: Final[object] = getattr(exception, "code", None)
status_code: Final[object] = code if code is not None else getattr(exception, "status_code", None)
if str(status_code) != str(status.HTTP_401_UNAUTHORIZED):
return False
return getattr(exception, INVALID_VIRTUAL_KEY_ERROR_MARKER, False) is True
def mark_invalid_virtual_key_error(exception: ProxyException, is_invalid_virtual_key: bool) -> ProxyException:
"""Return an independently marked malformed-key exception after callback transformations."""
if not is_invalid_virtual_key or str(exception.code) != str(status.HTTP_401_UNAUTHORIZED):
return exception
marked_exception: Final = ProxyException(
message=exception.message,
type=exception.type,
param=exception.param,
code=exception.code,
headers=exception.headers.copy(),
openai_code=None if exception.openai_code is None else str(exception.openai_code),
provider_specific_fields=exception.provider_specific_fields,
)
setattr(marked_exception, INVALID_VIRTUAL_KEY_ERROR_MARKER, True)
return marked_exception
def _get_request_ip_address(request: Request, use_x_forwarded_for: bool | None = False) -> str | None:
client_ip = None
if use_x_forwarded_for is True and "x-forwarded-for" in request.headers:

14
litellm/proxy/auth/user_api_key_auth.py
View file

@ -19,12 +19,15 @@ import fastapi
import orjson
from fastapi import HTTPException, Request, WebSocket, status
from fastapi.security.api_key import APIKeyHeader
from starlette.exceptions import WebSocketException
import litellm
from litellm._logging import verbose_logger, verbose_proxy_logger
from litellm._service_logger import ServiceLogging
from litellm.constants import (
GLOBAL_PROXY_SPEND_CACHE_KEY,
INVALID_VIRTUAL_KEY_ERROR_MARKER,
INVALID_VIRTUAL_KEY_ERROR_MESSAGE,
LITELLM_PROXY_BUDGET_NAME,
LITELLM_PROXY_MASTER_KEY_ALIAS,
)
@ -65,6 +68,7 @@ from litellm.proxy.auth.auth_utils import (
get_model_from_request,
get_request_route,
get_request_route_template,
is_invalid_virtual_key_error,
iter_request_fallback_targets,
normalize_request_route,
pre_db_read_auth_checks,
@ -539,6 +543,8 @@ async def user_api_key_auth_websocket(websocket: WebSocket):
try:
return await user_api_key_auth(request=request, api_key=f"Bearer {api_key}")
except Exception as e:
if is_invalid_virtual_key_error(e):
raise WebSocketException(code=status.WS_1008_POLICY_VIOLATION)
verbose_proxy_logger.exception(e)
await websocket.close(code=status.WS_1008_POLICY_VIOLATION)
raise HTTPException(status_code=403, detail=str(e))
@ -1867,13 +1873,17 @@ async def _user_api_key_auth_builder(
_masked_key: Final = f"{api_key[:4]}****{api_key[-4:]}" if len(api_key) > 8 else "****"
if not api_key.startswith("sk-"):
_hint = _JWT_AUTH_DISABLED_HINT if not enable_jwt_auth and JWTHandler.is_jwt(token=api_key) else ""
raise HTTPException(
_malformed_key_error = HTTPException(
status_code=status.HTTP_401_UNAUTHORIZED,
detail=(
f"LiteLLM Virtual Key expected. Received={_masked_key}, "
f"{INVALID_VIRTUAL_KEY_ERROR_MESSAGE}. Received={_masked_key}, "
f"expected to start with 'sk-'.{_hint}"
),
) # prevent token hashes from being used
# Stamp provenance here so log routing classifies this 401 by
# where it was raised, never by its message text.
setattr(_malformed_key_error, INVALID_VIRTUAL_KEY_ERROR_MARKER, True)
raise _malformed_key_error
else:
verbose_logger.warning(
"litellm.proxy.proxy_server.user_api_key_auth(): Warning - Key is not a string. Got type={}".format(

36
tests/test_litellm/proxy/auth/test_auth_exception_handler.py
View file

@ -26,6 +26,7 @@ from prisma.errors import (
from litellm._logging import verbose_proxy_logger
from litellm.constants import INVALID_VIRTUAL_KEY_ERROR_MARKER
from litellm.exceptions import BudgetExceededError
from litellm.proxy._types import ProxyErrorTypes, ProxyException, UserAPIKeyAuth
from litellm.proxy.auth.auth_exception_handler import UserAPIKeyAuthExceptionHandler
@ -703,23 +704,43 @@ async def test_auth_failure_ip_stamp_does_not_mutate_callers_request_data():
assert request_data == {"model": "gpt-4o"}
def _marked_malformed_key_error() -> HTTPException:
"""Build the malformed-key 401 as its raise site does: marker stamped on it."""
error = HTTPException(status_code=401, detail="LiteLLM Virtual Key expected. Received=test")
setattr(error, INVALID_VIRTUAL_KEY_ERROR_MARKER, True)
return error
@pytest.mark.asyncio
@pytest.mark.parametrize(
"auth_error,expect_traceback",
"auth_error,expect_traceback,expect_level",
[
pytest.param(
ProxyException(
message="Authentication Error", type=ProxyErrorTypes.auth_error, param=None, code=401
),
False,
"ERROR",
id="expected_401_no_traceback",
),
pytest.param(ValueError("unexpected internal error"), True, id="unexpected_error_keeps_traceback"),
pytest.param(ValueError("unexpected internal error"), True, "ERROR", id="unexpected_error_keeps_traceback"),
pytest.param(
_marked_malformed_key_error(),
False,
"WARNING",
id="malformed_virtual_key_warning_no_traceback",
),
pytest.param(
HTTPException(status_code=401, detail="LiteLLM Virtual Key expected. Received=test"),
False,
"ERROR",
id="phrase_without_marker_stays_loud",
),
],
)
async def test_handle_authentication_error_traceback_only_for_unexpected_errors(auth_error, expect_traceback, caplog):
async def test_handle_authentication_error_traceback_only_for_unexpected_errors(auth_error, expect_traceback, expect_level, caplog):
"""Regression for LIT-6043: expected 4xx auth rejections must not format a
traceback via logger.exception; unexpected errors must keep it."""
traceback via logger.exception; malformed virtual keys log at WARNING."""
handler = UserAPIKeyAuthExceptionHandler()
with (
@ -740,8 +761,8 @@ async def test_handle_authentication_error_traceback_only_for_unexpected_errors(
try:
try:
raise auth_error
except (ProxyException, ValueError) as caught:
with caplog.at_level("ERROR", logger="LiteLLM Proxy"), pytest.raises(ProxyException):
except (ProxyException, ValueError, HTTPException) as caught:
with caplog.at_level(expect_level, logger="LiteLLM Proxy"), pytest.raises((ProxyException, HTTPException)):
await handler._handle_authentication_error(
caught,
MagicMock(),
@ -756,3 +777,6 @@ async def test_handle_authentication_error_traceback_only_for_unexpected_errors(
records = [r for r in caplog.records if "user_api_key_auth(): Exception occured" in r.getMessage()]
assert len(records) == 1
assert (records[0].exc_info is not None) is expect_traceback
assert records[0].levelname == expect_level
expected_logger_name = "LiteLLM Proxy.stdout" if expect_level == "WARNING" else "LiteLLM Proxy"
assert records[0].name == expected_logger_name