diff --git a/enterprise/litellm_enterprise/proxy/management_endpoints/project_endpoints.py b/enterprise/litellm_enterprise/proxy/management_endpoints/project_endpoints.py index 75229bacc8f..72e6342eee7 100644 --- a/enterprise/litellm_enterprise/proxy/management_endpoints/project_endpoints.py +++ b/enterprise/litellm_enterprise/proxy/management_endpoints/project_endpoints.py @@ -19,6 +19,7 @@ from litellm._uuid import uuid from litellm.proxy._types import * from litellm.proxy.auth.user_api_key_auth import user_api_key_auth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.management_endpoints.common_utils import _set_object_metadata_field from litellm.proxy.management_helpers.utils import ( management_endpoint_wrapper, @@ -468,11 +469,7 @@ async def new_project( return response except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.management_endpoints.project_endpoints.new_project(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/project/new", e) raise handle_exception_on_proxy(e) @@ -706,11 +703,7 @@ async def update_project( # noqa: PLR0915 return updated_project except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.management_endpoints.project_endpoints.update_project(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/project/update", e) raise handle_exception_on_proxy(e) @@ -814,11 +807,7 @@ async def delete_project( return deleted_projects except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.management_endpoints.project_endpoints.delete_project(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/project/delete", e) raise handle_exception_on_proxy(e) @@ -895,11 +884,7 @@ async def project_info( return project except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.management_endpoints.project_endpoints.project_info(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/project/info", e) raise handle_exception_on_proxy(e) @@ -955,9 +940,5 @@ async def list_projects( return projects except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.management_endpoints.project_endpoints.list_projects(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/project/list", e) raise handle_exception_on_proxy(e) diff --git a/litellm/proxy/_types.py b/litellm/proxy/_types.py index 593ec4fc56e..46a032eb59a 100644 --- a/litellm/proxy/_types.py +++ b/litellm/proxy/_types.py @@ -3760,7 +3760,44 @@ class ProxyErrorTypes(str, enum.Enum): auth_error = "auth_error" """ - General authentication error + General authentication error. Use only when the failure does not fit + one of the more specific auth_* types below — UI clients (litellm + dashboard) fall back to a heuristic redirect decision when they see + this type, so prefer a precise type whenever the cause is known. + """ + + auth_session_expired = "auth_session_expired" + """ + The caller's session/token was once valid but is no longer (expired, + revoked, deleted, key rotated). UI clients should clear local auth + state and redirect to the login page. Distinguish from + `auth_invalid_credentials` — that one means the credential format was + bad from the start (never authenticated). + """ + + auth_invalid_credentials = "auth_invalid_credentials" + """ + The supplied credential is malformed, never existed, or does not + parse — e.g. missing Authorization header, garbled bearer token, key + not found in DB. UI clients should treat this the same as + `auth_session_expired` (clear state + login) because there is no + valid session to recover. + """ + + auth_permission_denied = "auth_permission_denied" + """ + The caller is authenticated but lacks the role / scope / model + access needed for this specific endpoint or resource (admin-only, + team_id mismatch, model not in allowed list). UI clients must NOT + redirect to login — the session is still valid, only this one + operation is forbidden. Surface as a toast. + + Note: `key_model_access_denied`, `team_model_access_denied`, + `team_member_permission_error`, and the other granular + *_access_denied / *_permission_error types are already specific + enough; this catch-all is for the cases where the cause is "you're + not allowed" but doesn't fit those buckets (e.g. master-key-required + on a non-master-key request). """ internal_server_error = "internal_server_error" diff --git a/litellm/proxy/auth/auth_checks.py b/litellm/proxy/auth/auth_checks.py index 14f198e0f12..2521173f2df 100644 --- a/litellm/proxy/auth/auth_checks.py +++ b/litellm/proxy/auth/auth_checks.py @@ -61,6 +61,7 @@ UserAPIKeyAuth, ) from litellm.proxy.auth.route_checks import RouteChecks +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.common_utils.http_parsing_utils import ( _safe_get_request_headers, _safe_get_request_query_params, @@ -1467,11 +1468,12 @@ async def get_team_membership( ) return _response - except Exception: - verbose_proxy_logger.exception( - "Error getting team membership for user_id: %s, team_id: %s", - user_id, - team_id, + except Exception as e: + log_proxy_exception( + verbose_proxy_logger, + "get_team_membership", + e, + extra={"user_id": user_id, "team_id": team_id}, ) return None @@ -2099,9 +2101,11 @@ async def get_access_object( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception( - "Error getting access group for access_group_id: %s", - access_group_id, + log_proxy_exception( + verbose_proxy_logger, + "access_group_lookup", + e, + extra={"access_group_id": access_group_id}, ) raise HTTPException( status_code=404, @@ -2214,7 +2218,12 @@ async def get_team_object_by_alias( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception("Error looking up team by alias: %s", team_alias) + log_proxy_exception( + verbose_proxy_logger, + "team_alias_lookup", + e, + extra={"team_alias": team_alias}, + ) raise HTTPException( status_code=500, detail={ @@ -2306,8 +2315,11 @@ async def get_org_object_by_alias( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception( - "Error looking up organization by alias: %s", org_alias + log_proxy_exception( + verbose_proxy_logger, + "organization_alias_lookup", + e, + extra={"org_alias": org_alias}, ) raise HTTPException( status_code=500, diff --git a/litellm/proxy/auth/auth_exception_handler.py b/litellm/proxy/auth/auth_exception_handler.py index 431db4254eb..bd7dcb35a04 100644 --- a/litellm/proxy/auth/auth_exception_handler.py +++ b/litellm/proxy/auth/auth_exception_handler.py @@ -2,6 +2,7 @@ Handles Authentication Errors """ +import logging from typing import TYPE_CHECKING, Any, Optional, Union from fastapi import HTTPException, Request, status @@ -24,6 +25,119 @@ # user_id. DB_UNAVAILABLE_FALLBACK_USER_ID = "__db_unavailable_fallback__" +# Known auth-failure exception types. These reflect a normal 401/403 outcome +# (no key, expired key, invalid key, route not allowed, budget exceeded) and +# should NOT be logged at ERROR with a full traceback — they happen routinely +# from probes, expired sessions, and fat-fingered keys, and flooding the +# error monitoring stream with them buries genuine issues. +_KNOWN_AUTH_ERROR_TYPES = (ProxyException, HTTPException) + +# Substrings (lowercase) in an upstream HTTPException's `detail` that +# indicate the caller's session/token was once valid but is no longer. +# Used by `_classify_auth_failure` to pick the right ProxyErrorTypes value +# when wrapping HTTPException — so the UI can route on a structured type +# instead of regex-matching free-text again. +_SESSION_EXPIRED_DETAIL_MARKERS = ( + "expired", + "expir", # covers expired / expiration + "revoked", + "key has been deleted", + "key has expired", +) + +# Substrings indicating the supplied credential was never valid (bad +# format, missing entirely, not in DB). +_INVALID_CREDENTIALS_DETAIL_MARKERS = ( + "no auth header", + "no authentication", + "no api key passed", # bare `Exception("No api key passed in.")` from user_api_key_auth.py + "no api key", # broader form + "invalid api key", + "invalid token", + "invalid bearer", + "token not found", + "key not found", + "malformed", + "malformed api key", # bare `Exception("Malformed API Key passed in. ...")` + "virtual key expected", # bare `Exception("LiteLLM Virtual Key expected. ...")` + "expected to start with 'sk-'", # tail of the same exception +) + +# Substrings indicating the caller IS authenticated but lacks the +# privilege for this specific operation. The role/scope/admin language +# is the giveaway. Distinct from "expired" or "invalid" — the session is +# fine, just this endpoint isn't allowed. +_PERMISSION_DENIED_DETAIL_MARKERS = ( + "not allowed", + "not authorized", + "admin only", + "admin-only", + "proxy admin", # "Only proxy admin can be used to generate ..." + "your role", # "Your role=unknown" / "Your role is not allowed ..." + "master key", + "requires", # "requires admin role", "requires master key", etc. + "permission", + "forbidden", + "access denied", +) + + +def _classify_auth_failure(e: Exception) -> "ProxyErrorTypes": + """Pick a specific ProxyErrorTypes for an auth-pipeline exception + based on its status code (if any) and message text. + + Rationale: the wrapper used to collapse every wrapped auth failure + into the generic `auth_error` type, leaving UI clients no way to + tell "your session is gone, redirect to login" apart from "you're + logged in but not authorized for THIS endpoint" — both arrived as + 401 with `type=auth_error`. This function makes that decision once, + centrally, so the wire-format `type` field carries the action. + + Works for BOTH: + - HTTPException — uses status_code + detail text + - bare Exception — uses str(e). The auth pipeline raises plenty of + these as final messages, e.g. + Exception("No api key passed in.") + Exception("LiteLLM Virtual Key expected. Received=... start with 'sk-'") + Exception("Malformed API Key passed in. Ensure Key has `Bearer` prefix.") + so the classifier MUST inspect them or the bare-Exception + catch-all in the wrapper keeps emitting plain `auth_error` and + defeats the whole point of D1. + + Returns the most specific type we can confidently determine. Falls + back to `auth_error` only when truly ambiguous. + + Logic (in priority order): + - HTTP 403 -> `auth_permission_denied` (semantics of 403) + - text contains an expired/revoked marker -> `auth_session_expired` + - text contains an invalid/missing-credential marker -> `auth_invalid_credentials` + - text contains a permission/role marker -> `auth_permission_denied` + (LiteLLM uses 401 for role mismatch too) + - Otherwise -> `auth_error` (UI falls back to its heuristic) + """ + status_code = getattr(e, "status_code", None) + # Prefer HTTPException.detail; fall back to str(e) so the same + # function classifies bare Exceptions from the auth pipeline. + detail_attr = str(getattr(e, "detail", "") or "") + text = (detail_attr or str(e)).lower() + + if status_code == 403: + return ProxyErrorTypes.auth_permission_denied + + # Order matters: check expired first because revoked keys often + # surface as "invalid" too, and we want to label them as + # session-expired (the recovery action — re-login — is the same and + # more accurate semantically). + if any(marker in text for marker in _SESSION_EXPIRED_DETAIL_MARKERS): + return ProxyErrorTypes.auth_session_expired + if any(marker in text for marker in _INVALID_CREDENTIALS_DETAIL_MARKERS): + return ProxyErrorTypes.auth_invalid_credentials + if any(marker in text for marker in _PERMISSION_DENIED_DETAIL_MARKERS): + return ProxyErrorTypes.auth_permission_denied + + return ProxyErrorTypes.auth_error + + if TYPE_CHECKING: from opentelemetry.trace import Span as _Span @@ -92,12 +206,48 @@ async def _handle_authentication_error( 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}, + + # Known auth failures (no/expired/invalid key, role mismatch, + # budget exceeded) are normal 401/403 outcomes — log them at + # WARN without a traceback so the error stream stays signal. + # Truly unexpected exceptions still go to ERROR with a stack. + # + # Two-tier check: the wire-format types (ProxyException / + # HTTPException) are always known. Bare ``Exception`` is the + # tricky case — the auth pipeline raises a lot of these + # ("No api key passed in.", "Malformed API Key passed in. ...", + # "LiteLLM Virtual Key expected. ..."). Run the same + # text classifier we use for the wire `type` field; if it + # confidently routes to a specific auth_* type, treat the + # exception as known and drop the traceback. Only the catch-all + # `auth_error` outcome (genuinely ambiguous) keeps ERROR+stack. + _is_known = isinstance(e, _KNOWN_AUTH_ERROR_TYPES) or ( + _classify_auth_failure(e) != ProxyErrorTypes.auth_error + ) + _log_level = logging.WARNING if _is_known else logging.ERROR + + # `str(e)` is sometimes empty for ProxyException, which historically + # left the log line as just the exception type name with no signal + # for why the request was rejected. Fall back to the type name so + # there is always SOMETHING to grep on. + _message_part = str(e) or type(e).__name__ + + verbose_proxy_logger.log( + _log_level, + "user_api_key_auth failed: %s", + _message_part, + extra={ + "requester_ip": requester_ip, + "request_id": request.headers.get("x-litellm-call-id"), + "route": route, + "exception_type": type(e).__name__, + "http_status": ( + getattr(e, "code", None) or getattr(e, "status_code", None) + ), + }, + # Only attach a traceback for unexpected exceptions. Known + # auth errors are self-explanatory from the type + message. + exc_info=not _is_known, ) # Log this exception to OTEL, Datadog etc @@ -126,17 +276,30 @@ async def _handle_authentication_error( code=getattr(e, "status_code", status.HTTP_429_TOO_MANY_REQUESTS), ) if isinstance(e, HTTPException): + # Classify into the specific auth_* type so UI clients can + # route on `type` instead of regex-matching the free-text + # message. Centralized here rather than at each raise site + # because most HTTPExceptions in the auth pipeline come + # from FastAPI / upstream code we don't own. raise ProxyException( message=getattr(e, "detail", f"Authentication Error({str(e)})"), - type=ProxyErrorTypes.auth_error, + type=_classify_auth_failure(e), param=getattr(e, "param", "None"), code=getattr(e, "status_code", status.HTTP_401_UNAUTHORIZED), ) elif isinstance(e, ProxyException): + # Inner exception already carries a specific type + # (e.g. token_not_found_in_db, expired_key, *_access_denied); + # passing it through preserves that signal end-to-end. raise e + # Catch-all for bare Exception. Classify by message content + # so the wire-format type still carries an action signal — + # the auth pipeline raises plenty of these (e.g. missing/ + # malformed/wrong-prefix key checks). _classify_auth_failure + # transparently inspects str(e) when there's no `detail`. raise ProxyException( message="Authentication Error, " + str(e), - type=ProxyErrorTypes.auth_error, + type=_classify_auth_failure(e), param=getattr(e, "param", "None"), code=status.HTTP_401_UNAUTHORIZED, ) diff --git a/litellm/proxy/auth/user_api_key_auth.py b/litellm/proxy/auth/user_api_key_auth.py index 03278633928..5feff4d10a0 100644 --- a/litellm/proxy/auth/user_api_key_auth.py +++ b/litellm/proxy/auth/user_api_key_auth.py @@ -62,6 +62,7 @@ from litellm.proxy.auth.oauth2_proxy_hook import handle_oauth2_proxy_request from litellm.proxy.auth.route_checks import RouteChecks from litellm.proxy.common_utils.cache_coordinator import EventDrivenCacheCoordinator +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.common_utils.user_api_key_cache import UserApiKeyCache from litellm.proxy.common_utils.http_parsing_utils import ( _read_request_body, @@ -393,7 +394,7 @@ async def return_body(): try: return await user_api_key_auth(request=request, api_key=f"Bearer {api_key}") except Exception as e: - verbose_proxy_logger.exception(e) + log_proxy_exception(verbose_proxy_logger, "websocket_auth", e) await websocket.close(code=status.WS_1008_POLICY_VIOLATION) raise HTTPException(status_code=403, detail=str(e)) @@ -2336,8 +2337,12 @@ def get_api_key_from_custom_header( ) ) else: - verbose_proxy_logger.exception( - f"No LiteLLM Virtual Key pass. Please set header={custom_litellm_key_header_name}: Bearer " + # Not an exception at all — header just isn't set. Demote from + # .exception() (which used to print "(NoneType: None)" with no + # current exception) to a single WARNING line. + verbose_proxy_logger.warning( + "No LiteLLM Virtual Key pass. Please set header=%s: Bearer ", + custom_litellm_key_header_name, ) return api_key diff --git a/litellm/proxy/common_request_processing.py b/litellm/proxy/common_request_processing.py index faafa4aa090..ad3f6160850 100644 --- a/litellm/proxy/common_request_processing.py +++ b/litellm/proxy/common_request_processing.py @@ -44,6 +44,7 @@ get_logging_caching_headers, get_remaining_tokens_and_requests_from_request_data, ) +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.dd_span_tagger import DDSpanTagger from litellm.proxy.route_llm_request import route_request from litellm.proxy.utils import ProxyLogging @@ -305,9 +306,7 @@ async def empty_gen() -> AsyncGenerator[str, None]: ) except Exception as e: # Unexpected error consuming first chunk. - verbose_proxy_logger.exception( - f"Error consuming first chunk from generator: {e}" - ) + log_proxy_exception(verbose_proxy_logger, "stream[first-chunk]", e) # Preserve status code from HTTPException (e.g., guardrail blocks) error_status = getattr(e, "status_code", status.HTTP_500_INTERNAL_SERVER_ERROR) @@ -1501,8 +1500,10 @@ async def _on_deferred_stream_complete( ) ) except Exception as e: - verbose_proxy_logger.exception( - "Error in orphaned streaming async logging: %s", e + log_proxy_exception( + verbose_proxy_logger, + "orphaned_streaming_async_logging", + e, ) try: from litellm.litellm_core_utils.thread_pool_executor import ( @@ -1517,8 +1518,10 @@ async def _on_deferred_stream_complete( end_time=None, ) except Exception as e: - verbose_proxy_logger.exception( - "Error in orphaned streaming sync logging: %s", e + log_proxy_exception( + verbose_proxy_logger, + "orphaned_streaming_sync_logging", + e, ) # Always return the client-requested model name (not provider-prefixed internal identifiers) @@ -1781,10 +1784,15 @@ async def _run_deferred_stream_guardrails( if guardrail_result is not None: _response = guardrail_result except Exception as e: - verbose_proxy_logger.exception( - "Error running post-call guardrail %s on streaming response: %s", - getattr(cb, "guardrail_name", type(cb).__name__), + log_proxy_exception( + verbose_proxy_logger, + "post_call_streaming_guardrail", e, + extra={ + "guardrail": getattr( + cb, "guardrail_name", type(cb).__name__ + ) + }, ) if isinstance(e, HTTPException) and hasattr( captured_logging_obj, "model_call_details" @@ -1793,8 +1801,9 @@ async def _run_deferred_stream_guardrails( "metadata", {} )["guardrail_blocked"] = True except Exception as e: - verbose_proxy_logger.exception( - "Error in deferred streaming guardrail initialization: %s", + log_proxy_exception( + verbose_proxy_logger, + "deferred_streaming_guardrail_init", e, ) finally: @@ -1808,8 +1817,9 @@ async def _run_deferred_stream_guardrails( ) ) except Exception as e: - verbose_proxy_logger.exception( - "Error in deferred streaming async logging: %s", + log_proxy_exception( + verbose_proxy_logger, + "deferred_streaming_async_logging", e, ) @@ -1822,8 +1832,9 @@ async def _run_deferred_stream_guardrails( end_time=None, ) except Exception as e: - verbose_proxy_logger.exception( - "Error in deferred streaming sync logging: %s", + log_proxy_exception( + verbose_proxy_logger, + "deferred_streaming_sync_logging", e, ) @@ -1835,9 +1846,7 @@ async def _handle_llm_api_exception( version: Optional[str] = None, ): """Raises ProxyException (OpenAI API compatible) if an exception is raised""" - verbose_proxy_logger.exception( - f"litellm.proxy.proxy_server._handle_llm_api_exception(): Exception occured - {str(e)}" - ) + log_proxy_exception(verbose_proxy_logger, "llm_api[handle-exception]", e) # Allow callbacks to transform the error response transformed_exception = await proxy_logging_obj.post_call_failure_hook( user_api_key_dict=user_api_key_dict, @@ -2153,11 +2162,7 @@ async def async_streaming_data_generator( ) yield serialize_chunk(chunk) except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.async_data_generator(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "async_data_generator[stream]", e) transformed_exception = await proxy_logging_obj.post_call_failure_hook( user_api_key_dict=user_api_key_dict, original_exception=e, diff --git a/litellm/proxy/common_utils/exception_logging.py b/litellm/proxy/common_utils/exception_logging.py new file mode 100644 index 00000000000..d6ba3233dfe --- /dev/null +++ b/litellm/proxy/common_utils/exception_logging.py @@ -0,0 +1,154 @@ +""" +Classify and log exceptions raised inside proxy route handlers. + +Why this exists: + +Most management-endpoint route handlers in this codebase end with a +catch-all ``except Exception as e:`` block that calls +``verbose_proxy_logger.exception(...)`` before re-raising. ``.exception()`` +always emits at ERROR with a full traceback — which is the right thing +when the proxy itself crashes (Pydantic blew up, the DB went away, an +attribute is missing), but the wrong thing for the vast majority of +exceptions that actually flow through these routes: ``HTTPException(409)`` +"already exists", ``ProxyException(token_not_found_in_db)``, +``BudgetExceededError``, ``UnsupportedParamsError`` — the status code +and message ARE the response; the traceback adds no signal and just +buries genuine ERROR events under client-induced noise. + +The fix is to centralize the "is this exception interesting?" decision +in one place. Business / client-induced errors (4xx with a stable type) +go to WARN as a single line carrying status_code + route + +exception_type + message. Truly unexpected exceptions still hit ERROR +with a traceback. Upstream provider 5xx (502/503/504) is treated as +"not our bug" — WARN, optionally tracked by Prometheus. + +See ``classify_log_level`` for the exact rules. +""" + +import logging +from typing import Optional + +from fastapi import HTTPException + +import litellm +from litellm.proxy._types import ProxyException + +# Exceptions whose status_code + message fully describe what happened. +# Adding a traceback would only obscure the WARN line; we never want +# these to count as ERROR events. Order is taxonomic, not by frequency. +_KNOWN_BUSINESS_EXCEPTIONS: tuple = ( + HTTPException, + ProxyException, + litellm.BudgetExceededError, + litellm.RateLimitError, + litellm.AuthenticationError, + litellm.PermissionDeniedError, + litellm.NotFoundError, + litellm.BadRequestError, + litellm.UnsupportedParamsError, + litellm.ContextWindowExceededError, + litellm.ContentPolicyViolationError, + litellm.UnprocessableEntityError, + litellm.Timeout, +) + +# Upstream-provider failure status codes. These represent the +# *upstream* service (OpenAI/Anthropic/etc.) being unhealthy, not our +# proxy. A traceback through our request path does not help diagnose +# why OpenAI returned 503, so log at WARN and let Prometheus counters +# drive aggregation/alerting on these. +_UPSTREAM_5XX = frozenset({502, 503, 504}) + + +def _extract_status_code(e: Exception) -> Optional[int]: + """Pull a numeric HTTP status off an exception, regardless of which + library raised it. LiteLLM/OpenAI errors expose ``.status_code``; + ProxyException exposes ``.code``; FastAPI's HTTPException uses + ``.status_code``. Anything else returns None. + """ + for attr in ("status_code", "code"): + value = getattr(e, attr, None) + if isinstance(value, int): + return value + return None + + +def classify_log_level(e: Exception) -> int: + """Return the logging level a proxy route handler should use when + logging ``e``. + + Decision order: + + 1. If ``e`` is one of the known business-exception types, return + ``WARNING``. These are deliberate ``raise``s with a status code + and a stable wire-format type; the user did something the API + rejects, and a traceback adds nothing. + 2. If ``e`` carries a 4xx HTTP status code, return ``WARNING``. + Client error — even if the exception type is unfamiliar (some + library may subclass without inheriting from our known list), + the status code itself is the load-bearing signal. + 3. If ``e`` carries an upstream-5xx code (502/503/504), return + ``WARNING``. Provider problem, not ours. + 4. Otherwise — including bare ``Exception``, ``RuntimeError``, + ``KeyError``, ``AttributeError``, real 500s, and anything with + no status_code at all — return ``ERROR``. The traceback IS the + reason to log. + """ + if isinstance(e, _KNOWN_BUSINESS_EXCEPTIONS): + return logging.WARNING + + status_code = _extract_status_code(e) + if status_code is not None: + if 400 <= status_code < 500: + return logging.WARNING + if status_code in _UPSTREAM_5XX: + return logging.WARNING + + return logging.ERROR + + +def log_proxy_exception( + logger: logging.Logger, + route: str, + e: Exception, + *, + extra: Optional[dict] = None, +) -> None: + """Log ``e`` at the level determined by :func:`classify_log_level`. + + For WARN-level entries we emit a single line with structured + ``extra`` fields and no traceback. For ERROR-level entries we + attach ``exc_info`` so the traceback is preserved exactly as + ``logger.exception(...)`` would have done. + + ``route`` should be a stable identifier ("/user/new", "/team/update", + etc.) so log consumers can group by endpoint without parsing the + free-form message. + """ + level = classify_log_level(e) + status_code = _extract_status_code(e) + + # ``.detail`` is FastAPI/HTTPException; ``str(e)`` covers everything + # else. Fall back to the type name so the log line is never empty + # (some ProxyException instances stringify to ""), preserving the + # grep-ability guarantee from the earlier auth_exception_handler + # work. + detail = getattr(e, "detail", None) + message = str(detail) if detail else (str(e) or type(e).__name__) + + log_extra: dict = { + "route": route, + "exception_type": type(e).__name__, + "http_status": status_code, + } + if extra: + log_extra.update(extra) + + logger.log( + level, + "%s failed: %s", + route, + message, + extra=log_extra, + exc_info=(level >= logging.ERROR), + ) diff --git a/litellm/proxy/common_utils/http_parsing_utils.py b/litellm/proxy/common_utils/http_parsing_utils.py index 678ff289649..2da0ba0a154 100644 --- a/litellm/proxy/common_utils/http_parsing_utils.py +++ b/litellm/proxy/common_utils/http_parsing_utils.py @@ -112,9 +112,12 @@ async def _read_request_body(request: Optional[Request]) -> Dict: try: parsed_body = json.loads(body_str) except json.JSONDecodeError: - # If both orjson and json.loads fail, throw a proper error - verbose_proxy_logger.error( - f"Invalid JSON payload received: {str(e)}" + # If both orjson and json.loads fail, throw a proper error. + # This is a client-formatting problem (400), not a server + # bug — WARN, no traceback. The ProxyException raised + # below is the response; this line is purely diagnostic. + verbose_proxy_logger.warning( + "Invalid JSON payload received: %s", str(e) ) raise ProxyException( message=f"Invalid JSON payload: {str(e)}", @@ -128,11 +131,14 @@ async def _read_request_body(request: Optional[Request]) -> Dict: return parsed_body except (json.JSONDecodeError, orjson.JSONDecodeError, ProxyException) as e: - # Re-raise ProxyException as-is - verbose_proxy_logger.error(f"Invalid JSON payload received: {str(e)}") + # Re-raise ProxyException as-is. Same rationale as above — a 400 + # response, not a server bug. WARN without traceback. + verbose_proxy_logger.warning("Invalid JSON payload received: %s", str(e)) raise except Exception as e: - # Catch unexpected errors to avoid crashes + # Catch unexpected errors to avoid crashes. THIS is a real server + # fault path (we expected json/orjson to be the only decoders and + # something else blew up) — keep ERROR + traceback. verbose_proxy_logger.exception( "Unexpected error reading request body - {}".format(e) ) diff --git a/litellm/proxy/litellm_pre_call_utils.py b/litellm/proxy/litellm_pre_call_utils.py index 0d27b283c47..d0750e8d4f0 100644 --- a/litellm/proxy/litellm_pre_call_utils.py +++ b/litellm/proxy/litellm_pre_call_utils.py @@ -29,6 +29,7 @@ decrypt_callback_vars, get_metadata_variable_name_from_kwargs, ) +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.common_utils.http_parsing_utils import _safe_get_request_headers # Cache special headers as a frozenset for O(1) lookup performance @@ -406,9 +407,7 @@ def safe_add_api_version_from_query_params(data: dict, request: Request): except KeyError: pass except Exception as e: - verbose_logger.exception( - "error checking api version in query params: %s", str(e) - ) + log_proxy_exception(verbose_proxy_logger, "api_version_query_param_parse", e) def convert_key_logging_metadata_to_callback( diff --git a/litellm/proxy/management_endpoints/access_group_endpoints.py b/litellm/proxy/management_endpoints/access_group_endpoints.py index 62a770f46ae..41c67758083 100644 --- a/litellm/proxy/management_endpoints/access_group_endpoints.py +++ b/litellm/proxy/management_endpoints/access_group_endpoints.py @@ -17,6 +17,7 @@ _get_team_object_from_cache, ) from litellm.proxy.auth.user_api_key_auth import user_api_key_auth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.db.exception_handler import PrismaDBExceptionHandler from litellm.proxy.utils import get_prisma_client_or_throw from litellm.types.access_group import ( @@ -632,10 +633,11 @@ async def delete_access_group( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception( - "delete_access_group failed: access_group_id=%s error=%s", - access_group_id, + log_proxy_exception( + verbose_proxy_logger, + "/access_group/delete", e, + extra={"access_group_id": access_group_id}, ) if PrismaDBExceptionHandler.is_database_connection_error(e): raise HTTPException( diff --git a/litellm/proxy/management_endpoints/cache_settings_endpoints.py b/litellm/proxy/management_endpoints/cache_settings_endpoints.py index 55eb321185c..116ef0fbefb 100644 --- a/litellm/proxy/management_endpoints/cache_settings_endpoints.py +++ b/litellm/proxy/management_endpoints/cache_settings_endpoints.py @@ -26,6 +26,7 @@ UserAPIKeyAuth, ) from litellm.proxy.auth.user_api_key_auth import user_api_key_auth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.types.management_endpoints import ( CACHE_SETTINGS_FIELDS, REDIS_TYPE_DESCRIPTIONS, @@ -199,11 +200,7 @@ async def init_cache_settings_in_db(prisma_client, proxy_config): verbose_proxy_logger.info("Cache settings initialized from database") except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.management_endpoints.cache_settings_endpoints.py::CacheSettingsManager::init_cache_settings_in_db - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "init_cache_settings_in_db", e) @staticmethod def update_cache_params(cache_params: Dict[str, Any]): diff --git a/litellm/proxy/management_endpoints/common_daily_activity.py b/litellm/proxy/management_endpoints/common_daily_activity.py index d173cd745ba..90c944468fb 100644 --- a/litellm/proxy/management_endpoints/common_daily_activity.py +++ b/litellm/proxy/management_endpoints/common_daily_activity.py @@ -7,6 +7,7 @@ from litellm._logging import verbose_proxy_logger from litellm.proxy._types import CommonProxyErrors +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.utils import PrismaClient from litellm.types.proxy.management_endpoints.common_daily_activity import ( BreakdownMetrics, @@ -954,7 +955,7 @@ async def get_daily_activity( ) except Exception as e: - verbose_proxy_logger.exception(f"Error fetching daily activity: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "get_daily_activity", e) raise HTTPException( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, detail={"error": f"Failed to fetch analytics: {str(e)}"}, @@ -1044,9 +1045,7 @@ async def get_daily_activity_aggregated( ) except Exception as e: - verbose_proxy_logger.exception( - f"Error fetching aggregated daily activity: {str(e)}" - ) + log_proxy_exception(verbose_proxy_logger, "get_daily_activity_aggregated", e) raise HTTPException( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, detail={"error": f"Failed to fetch analytics: {str(e)}"}, diff --git a/litellm/proxy/management_endpoints/config_override_endpoints.py b/litellm/proxy/management_endpoints/config_override_endpoints.py index 7f7aa485fb3..dfb6bad8fed 100644 --- a/litellm/proxy/management_endpoints/config_override_endpoints.py +++ b/litellm/proxy/management_endpoints/config_override_endpoints.py @@ -30,6 +30,7 @@ UserAPIKeyAuth, ) from litellm.proxy.auth.user_api_key_auth import user_api_key_auth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.types.llms.custom_http import httpxSpecialProvider from litellm.types.proxy.management_endpoints.config_overrides import ( ConfigOverrideSettingsResponse, @@ -310,8 +311,10 @@ async def update_hashicorp_vault_config( proxy_config.initialize_secret_manager(key_management_system="hashicorp_vault") except Exception as e: _set_env_vars(previous_env) - verbose_proxy_logger.exception( - "Error reinitializing Hashicorp Vault secret manager: %s", str(e) + log_proxy_exception( + verbose_proxy_logger, + "hashicorp_vault_reinit", + e, ) raise HTTPException( status_code=500, diff --git a/litellm/proxy/management_endpoints/customer_endpoints.py b/litellm/proxy/management_endpoints/customer_endpoints.py index 1fd8320db20..b9fee2a6adf 100644 --- a/litellm/proxy/management_endpoints/customer_endpoints.py +++ b/litellm/proxy/management_endpoints/customer_endpoints.py @@ -21,6 +21,7 @@ from litellm._logging import verbose_proxy_logger from litellm.proxy._types import * from litellm.proxy.auth.user_api_key_auth import user_api_key_auth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.management_endpoints.common_daily_activity import get_daily_activity from litellm.proxy.management_helpers.object_permission_utils import ( _set_object_permission, @@ -393,11 +394,7 @@ async def new_end_user( return response_dict except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.management_endpoints.customer_endpoints.new_end_user(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/customer/new", e) if "Unique constraint failed on the fields: (`user_id`)" in str(e): raise ProxyException( message=f"Customer already exists, passed user_id={data.user_id}. Please pass a new user_id.", @@ -475,11 +472,7 @@ async def end_user_info( return response_dict except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.management_endpoints.customer_endpoints.end_user_info(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/customer/info", e) raise handle_exception_on_proxy(e) @@ -683,11 +676,7 @@ async def update_end_user( # update based on remaining passed in values except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.update_end_user(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/customer/update", e) raise handle_exception_on_proxy(e) @@ -849,11 +838,7 @@ async def list_end_user( return returned_response except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.management_endpoints.customer_endpoints.list_end_user(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/customer/list", e) raise handle_exception_on_proxy(e) diff --git a/litellm/proxy/management_endpoints/internal_user_endpoints.py b/litellm/proxy/management_endpoints/internal_user_endpoints.py index 75eb5cd55ef..17614d81277 100644 --- a/litellm/proxy/management_endpoints/internal_user_endpoints.py +++ b/litellm/proxy/management_endpoints/internal_user_endpoints.py @@ -27,6 +27,7 @@ from litellm.proxy._types import * from litellm.proxy.auth.auth_checks import get_team_object, get_user_object from litellm.proxy.auth.user_api_key_auth import user_api_key_auth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.hooks.user_management_event_hooks import UserManagementEventHooks from litellm.proxy.management_endpoints.common_daily_activity import ( get_daily_activity, @@ -523,9 +524,7 @@ async def new_user( return new_user_response except Exception as e: - verbose_proxy_logger.exception( - "/user/new: Exception occured - {}".format(str(e)) - ) + log_proxy_exception(verbose_proxy_logger, "/user/new", e) raise handle_exception_on_proxy(e) @@ -818,11 +817,7 @@ async def user_info( # noqa: PLR0915 return response_data except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.user_info(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/user/info", e) raise handle_exception_on_proxy(e) @@ -978,11 +973,7 @@ async def user_info_v2( teams=user_data.get("teams") or [], ) except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.user_info_v2(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/user/info_v2", e) raise handle_exception_on_proxy(e) @@ -1447,11 +1438,7 @@ async def user_update( ) return response except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.user_update(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/user/update", e) verbose_proxy_logger.debug(traceback.format_exc()) if isinstance(e, HTTPException): raise ProxyException( @@ -1503,14 +1490,17 @@ async def bulk_update_processed_users( ) successful_updates += 1 except Exception as e: - verbose_proxy_logger.exception( - f"Failed to update user {user_request.user_id or user_request.user_email}: {e}" + log_proxy_exception( + verbose_proxy_logger, + "/user/bulk_update[per-user]", + e, + extra={ + "user_id": user_request.user_id, + "user_email": user_request.user_email, + }, ) # Record failure error_message = str(e) - verbose_proxy_logger.error( - f"Failed to update user {user_request.user_id or user_request.user_email}: {error_message}" - ) results.append( UserUpdateResult( @@ -1529,7 +1519,7 @@ async def bulk_update_processed_users( failed_updates=failed_updates, ) except Exception as e: - verbose_proxy_logger.exception(f"Failed to update users: {e}") + log_proxy_exception(verbose_proxy_logger, "/user/bulk_update", e) raise HTTPException(status_code=500, detail={"error": str(e)}) @@ -1710,7 +1700,7 @@ async def bulk_user_update( ) except Exception as e: - verbose_proxy_logger.exception(f"Failed to perform bulk update: {e}") + log_proxy_exception(verbose_proxy_logger, "/user/bulk_update[batch]", e) # Fall back to individual updates if bulk update fails for user in all_users_in_db: user_update_request = data.user_updates.model_copy() @@ -2574,7 +2564,7 @@ async def ui_view_users( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception(f"Error searching users: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/user/filter/ui", e) raise HTTPException(status_code=500, detail=f"Error searching users: {str(e)}") @@ -2688,9 +2678,7 @@ async def get_user_daily_activity( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception( - "/spend/daily/analytics: Exception occured - {}".format(str(e)) - ) + log_proxy_exception(verbose_proxy_logger, "/spend/daily/analytics", e) raise HTTPException( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, detail={"error": f"Failed to fetch analytics: {str(e)}"}, @@ -2784,9 +2772,7 @@ async def get_user_daily_activity_aggregated( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception( - "/user/daily/activity/aggregated: Exception occured - {}".format(str(e)) - ) + log_proxy_exception(verbose_proxy_logger, "/user/daily/activity/aggregated", e) raise HTTPException( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, detail={"error": f"Failed to fetch analytics: {str(e)}"}, diff --git a/litellm/proxy/management_endpoints/key_management_endpoints.py b/litellm/proxy/management_endpoints/key_management_endpoints.py index a67d8d934bf..73ee6302e28 100644 --- a/litellm/proxy/management_endpoints/key_management_endpoints.py +++ b/litellm/proxy/management_endpoints/key_management_endpoints.py @@ -55,6 +55,7 @@ decrypt_callback_vars, encrypt_callback_vars, ) +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.common_utils.rbac_utils import check_org_admin_can_generate_keys from litellm.proxy.common_utils.timezone_utils import get_budget_reset_time from litellm.proxy.hooks.key_management_event_hooks import KeyManagementEventHooks @@ -1543,11 +1544,7 @@ async def generate_key_fn( ) except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.generate_key_fn(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/key/generate", e) raise handle_exception_on_proxy(e) @@ -1750,11 +1747,7 @@ def prepare_metadata_fields( casted_metadata[k] = v except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.prepare_metadata_fields(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "prepare_metadata_fields", e) non_default_values["metadata"] = encrypt_callback_vars(casted_metadata) return non_default_values @@ -2546,11 +2539,7 @@ async def update_key_fn( # noqa: PLR0915 return {"key": key, **response["data"]} # update based on remaining passed in values except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.update_key_fn(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/key/update", e) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "detail", f"Authentication Error({str(e)})"), @@ -2690,8 +2679,11 @@ async def bulk_update_keys( ) except Exception as e: - verbose_proxy_logger.exception( - f"Failed to update key {key_update_item.key}: {e}" + log_proxy_exception( + verbose_proxy_logger, + "/key/bulk_update[per-key]", + e, + extra={"key": key_update_item.key}, ) if isinstance(e, HTTPException): @@ -3136,11 +3128,7 @@ async def delete_key_fn( return {"deleted_keys": deleted_keys} except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.delete_key_fn(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/key/delete", e) raise handle_exception_on_proxy(e) @@ -3860,11 +3848,7 @@ async def delete_verification_tokens( else: raise Exception("DB not connected. prisma_client is None") except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.delete_verification_tokens(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "delete_verification_tokens", e) verbose_proxy_logger.debug(traceback.format_exc()) raise e @@ -4535,7 +4519,7 @@ async def regenerate_key_fn( # noqa: PLR0915 proxy_logging_obj=proxy_logging_obj, ) except Exception as e: - verbose_proxy_logger.exception("Error regenerating key: %s", e) + log_proxy_exception(verbose_proxy_logger, "/key/regenerate", e) raise handle_exception_on_proxy(e) @@ -4694,7 +4678,7 @@ async def reset_key_spend_fn( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception("Error resetting key spend: %s", e) + log_proxy_exception(verbose_proxy_logger, "/key/reset_spend", e) raise handle_exception_on_proxy(e) @@ -5049,7 +5033,7 @@ async def list_keys( return response except Exception as e: - verbose_proxy_logger.exception(f"Error in list_keys: {e}") + log_proxy_exception(verbose_proxy_logger, "/key/list", e) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "detail", f"error({str(e)})"), @@ -5213,7 +5197,7 @@ async def key_aliases( } except Exception as e: - verbose_proxy_logger.exception(f"Error in key_aliases: {e}") + log_proxy_exception(verbose_proxy_logger, "/key/aliases", e) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "detail", f"error({str(e)})"), diff --git a/litellm/proxy/management_endpoints/mcp_management_endpoints.py b/litellm/proxy/management_endpoints/mcp_management_endpoints.py index 431ff49c7ce..e18a4feee8d 100644 --- a/litellm/proxy/management_endpoints/mcp_management_endpoints.py +++ b/litellm/proxy/management_endpoints/mcp_management_endpoints.py @@ -56,6 +56,7 @@ decrypt_value_helper, encrypt_value_helper, ) +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.management_helpers.audit_logs import get_audit_log_changed_by router = APIRouter(prefix="/v1/mcp", tags=["mcp"]) @@ -1107,7 +1108,7 @@ async def register_mcp_server( touched_by=user_api_key_dict.user_id or user_api_key_dict.team_id, ) except Exception as e: - verbose_proxy_logger.exception(f"Error registering mcp server: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/v1/mcp/server/submit", e) raise HTTPException( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, detail={"error": f"Error registering mcp server: {str(e)}"}, @@ -1443,7 +1444,7 @@ async def add_mcp_server( # Ensure registry is up to date by reloading from database await global_mcp_server_manager.reload_servers_from_database() except Exception as e: - verbose_proxy_logger.exception(f"Error creating mcp server: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/v1/mcp/server", e) raise HTTPException( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, detail={"error": f"Error creating mcp server: {str(e)}"}, @@ -1507,9 +1508,7 @@ async def add_session_mcp_server( ttl_seconds=TEMPORARY_MCP_SERVER_TTL_SECONDS, ) except Exception as e: - verbose_proxy_logger.exception( - f"Error caching temporary mcp server: {str(e)}" - ) + log_proxy_exception(verbose_proxy_logger, "/v1/mcp/server/oauth/session", e) raise HTTPException( status_code=status.HTTP_500_INTERNAL_SERVER_ERROR, detail={"error": f"Error caching temporary mcp server: {str(e)}"}, @@ -2246,7 +2245,7 @@ async def make_mcp_servers_public( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception(f"Error making agent public: {e}") + log_proxy_exception(verbose_proxy_logger, "/v1/mcp/agent/make_public", e) raise HTTPException(status_code=500, detail=str(e)) # --- MCP Discovery --- diff --git a/litellm/proxy/management_endpoints/model_access_group_management_endpoints.py b/litellm/proxy/management_endpoints/model_access_group_management_endpoints.py index b05cfef5760..abd06e00e6a 100644 --- a/litellm/proxy/management_endpoints/model_access_group_management_endpoints.py +++ b/litellm/proxy/management_endpoints/model_access_group_management_endpoints.py @@ -13,6 +13,7 @@ from litellm._logging import verbose_proxy_logger from litellm.proxy._types import UserAPIKeyAuth from litellm.proxy.auth.user_api_key_auth import user_api_key_auth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception # Clear cache and reload models to pick up the access group changes from litellm.proxy.management_endpoints.model_management_endpoints import ( @@ -383,8 +384,11 @@ async def create_model_group( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception( - f"Error creating access group '{data.access_group}': {str(e)}" + log_proxy_exception( + verbose_proxy_logger, + "/access_group/new", + e, + extra={"access_group": data.access_group}, ) raise HTTPException( status_code=500, @@ -437,7 +441,7 @@ async def list_access_groups( return ListAccessGroupsResponse(access_groups=access_groups_list) except Exception as e: - verbose_proxy_logger.exception(f"Error listing access groups: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/access_group/list", e) raise HTTPException( status_code=500, detail={"error": f"Failed to list access groups: {str(e)}"}, @@ -496,8 +500,11 @@ async def get_access_group_info( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception( - f"Error getting access group info for '{access_group}': {str(e)}" + log_proxy_exception( + verbose_proxy_logger, + "/access_group/{access_group}/info", + e, + extra={"access_group": access_group}, ) raise HTTPException( status_code=500, @@ -653,8 +660,11 @@ async def update_access_group( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception( - f"Error updating access group '{access_group}': {str(e)}" + log_proxy_exception( + verbose_proxy_logger, + "/access_group/update", + e, + extra={"access_group": access_group}, ) raise HTTPException( status_code=500, @@ -756,8 +766,11 @@ async def delete_access_group( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception( - f"Error deleting access group '{access_group}': {str(e)}" + log_proxy_exception( + verbose_proxy_logger, + "/access_group/delete", + e, + extra={"access_group": access_group}, ) raise HTTPException( status_code=500, diff --git a/litellm/proxy/management_endpoints/model_management_endpoints.py b/litellm/proxy/management_endpoints/model_management_endpoints.py index 722fcd30033..69d6ea5e916 100644 --- a/litellm/proxy/management_endpoints/model_management_endpoints.py +++ b/litellm/proxy/management_endpoints/model_management_endpoints.py @@ -37,6 +37,7 @@ ) from litellm.proxy.auth.user_api_key_auth import user_api_key_auth from litellm.proxy.common_utils.encrypt_decrypt_utils import encrypt_value_helper +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.management_endpoints.common_utils import _is_user_team_admin from litellm.proxy.management_endpoints.team_endpoints import ( team_model_add, @@ -314,7 +315,7 @@ async def patch_model( return updated_model except Exception as e: - verbose_proxy_logger.exception(f"Error in patch_model: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/model/{model_id}/update", e) if isinstance(e, (HTTPException, ProxyException)): raise e @@ -896,9 +897,7 @@ async def delete_model( ) except Exception as e: - verbose_proxy_logger.exception( - f"Failed to delete model. Due to error - {str(e)}" - ) + log_proxy_exception(verbose_proxy_logger, "/model/delete", e) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "detail", f"Authentication Error({str(e)})"), @@ -1061,7 +1060,7 @@ async def add_new_model( passed_model_info=model_params.model_info, ) except Exception as e: - verbose_proxy_logger.exception(f"Exception in add_new_model: {e}") + log_proxy_exception(verbose_proxy_logger, "/model/new[inner]", e) else: raise HTTPException( @@ -1100,11 +1099,7 @@ async def add_new_model( return model_response except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.add_new_model(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/model/new", e) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "detail", f"Authentication Error({str(e)})"), @@ -1261,11 +1256,7 @@ async def update_model( return model_response except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.update_model(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/model/update", e) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "detail", f"Authentication Error({str(e)})"), @@ -1362,7 +1353,7 @@ async def update_public_model_groups( } except Exception as e: - verbose_proxy_logger.exception(f"Error updating public model groups: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/model_group/make_public", e) if isinstance(e, HTTPException): raise e @@ -1432,7 +1423,7 @@ async def update_useful_links( } except Exception as e: - verbose_proxy_logger.exception(f"Error updating public model groups: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/model_hub/update_useful_links", e) if isinstance(e, HTTPException): raise e @@ -1518,6 +1509,4 @@ async def clear_cache(): f"Cleared {len(db_model_ids)} DB models, preserved {len(config_models)} config models" ) except Exception as e: - verbose_proxy_logger.exception( - f"Failed to clear cache and reload models. Due to error - {str(e)}" - ) + log_proxy_exception(verbose_proxy_logger, "clear_cache_and_reload_models", e) diff --git a/litellm/proxy/management_endpoints/organization_endpoints.py b/litellm/proxy/management_endpoints/organization_endpoints.py index 4d4ed53aaa8..0b3aa86d337 100644 --- a/litellm/proxy/management_endpoints/organization_endpoints.py +++ b/litellm/proxy/management_endpoints/organization_endpoints.py @@ -23,6 +23,7 @@ from litellm.proxy._types import * from litellm.proxy.auth.auth_checks import can_user_call_model, get_user_object from litellm.proxy.auth.user_api_key_auth import user_api_key_auth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.management_endpoints.budget_management_endpoints import ( new_budget, update_budget, @@ -986,7 +987,7 @@ async def organization_member_add( updated_organization_memberships=updated_organization_memberships, ) except Exception as e: - verbose_proxy_logger.exception(f"Error adding member to organization: {e}") + log_proxy_exception(verbose_proxy_logger, "/organization/member_add", e) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "detail", f"Authentication Error({str(e)})"), @@ -1199,7 +1200,7 @@ async def organization_member_update( ) return final_organization_membership_pydantic except Exception as e: - verbose_proxy_logger.exception(f"Error updating member in organization: {e}") + log_proxy_exception(verbose_proxy_logger, "/organization/member_update", e) raise e @@ -1250,7 +1251,7 @@ async def organization_member_delete( return member_to_delete except Exception as e: - verbose_proxy_logger.exception(f"Error deleting member from organization: {e}") + log_proxy_exception(verbose_proxy_logger, "/organization/member_delete", e) raise e diff --git a/litellm/proxy/management_endpoints/scim/scim_v2.py b/litellm/proxy/management_endpoints/scim/scim_v2.py index 1f20764f837..f55eb98870d 100644 --- a/litellm/proxy/management_endpoints/scim/scim_v2.py +++ b/litellm/proxy/management_endpoints/scim/scim_v2.py @@ -22,6 +22,7 @@ import litellm from litellm._logging import verbose_proxy_logger +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.common_utils.http_parsing_utils import _safe_get_request_headers from litellm._uuid import uuid from litellm.litellm_core_utils.safe_json_dumps import safe_dumps @@ -493,7 +494,9 @@ async def _create_user_if_not_exists( return created_user except Exception as e: - verbose_proxy_logger.exception(f"Failed to create user {user_id}: {e}") + log_proxy_exception( + verbose_proxy_logger, "scim_create_user", e, extra={"user_id": user_id} + ) return None @@ -1344,11 +1347,19 @@ async def patch_team_membership( f"User {user_id} is already in team {_team_id}, skipping add" ) else: - verbose_proxy_logger.exception( - f"Error adding user to team {_team_id}: {e}" + log_proxy_exception( + verbose_proxy_logger, + "scim_add_user_to_team", + e, + extra={"team_id": _team_id}, ) except Exception as e: - verbose_proxy_logger.exception(f"Error adding user to team {_team_id}: {e}") + log_proxy_exception( + verbose_proxy_logger, + "scim_add_user_to_team", + e, + extra={"team_id": _team_id}, + ) for _team_id in teams_ids_to_remove_user_from: try: @@ -1359,8 +1370,11 @@ async def patch_team_membership( ), ) except Exception as e: - verbose_proxy_logger.exception( - f"Error removing user from team {_team_id}: {e}" + log_proxy_exception( + verbose_proxy_logger, + "scim_remove_user_from_team", + e, + extra={"team_id": _team_id}, ) return True diff --git a/litellm/proxy/management_endpoints/tag_management_endpoints.py b/litellm/proxy/management_endpoints/tag_management_endpoints.py index 49d9b67a28a..8a94b625edc 100644 --- a/litellm/proxy/management_endpoints/tag_management_endpoints.py +++ b/litellm/proxy/management_endpoints/tag_management_endpoints.py @@ -20,6 +20,7 @@ from litellm._logging import verbose_proxy_logger from litellm.proxy._types import UserAPIKeyAuth, user_api_key_has_admin_view from litellm.proxy.auth.user_api_key_auth import user_api_key_auth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.management_endpoints.common_daily_activity import ( SpendAnalyticsPaginatedResponse, get_daily_activity, @@ -254,7 +255,7 @@ async def new_tag( "tag": tag_config, } except Exception as e: - verbose_proxy_logger.exception(f"Error creating tag: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/tag/new", e) raise HTTPException(status_code=500, detail=str(e)) @@ -297,7 +298,7 @@ async def _add_tag_to_deployment(deployment: "Deployment", tag: str): data={"litellm_params": json.dumps(existing_params)}, ) except Exception as e: - verbose_proxy_logger.exception(f"Error adding tag to deployment: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/tag/add_deployment", e) raise HTTPException(status_code=500, detail=str(e)) @@ -388,7 +389,7 @@ async def update_tag( "tag": tag_config, } except Exception as e: - verbose_proxy_logger.exception(f"Error updating tag: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/tag/update", e) raise HTTPException(status_code=500, detail=str(e)) diff --git a/litellm/proxy/management_endpoints/team_callback_endpoints.py b/litellm/proxy/management_endpoints/team_callback_endpoints.py index 63b56425b0e..57642214b73 100644 --- a/litellm/proxy/management_endpoints/team_callback_endpoints.py +++ b/litellm/proxy/management_endpoints/team_callback_endpoints.py @@ -28,6 +28,7 @@ ) from litellm.proxy.auth.user_api_key_auth import user_api_key_auth from litellm.proxy.common_utils.callback_utils import encrypt_callback_vars +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.management_endpoints.team_endpoints import _verify_team_access from litellm.proxy.management_helpers.utils import management_endpoint_wrapper @@ -271,11 +272,7 @@ async def add_team_callbacks( except ProxyException as e: raise e except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.add_team_callbacks(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/team/{team_id}/callback", e) raise ProxyException( message="Internal Server Error, " + str(e), type=ProxyErrorTypes.internal_server_error.value, diff --git a/litellm/proxy/management_endpoints/team_endpoints.py b/litellm/proxy/management_endpoints/team_endpoints.py index 43fdc9ae1cf..1ab05fb3c7e 100644 --- a/litellm/proxy/management_endpoints/team_endpoints.py +++ b/litellm/proxy/management_endpoints/team_endpoints.py @@ -73,6 +73,7 @@ ) from litellm.proxy.auth.user_api_key_auth import user_api_key_auth from litellm.proxy.common_utils.callback_utils import encrypt_callback_vars +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.management_endpoints.common_utils import ( _check_passthrough_routes_caller_permission, _is_user_org_admin_for_team, @@ -3023,7 +3024,7 @@ async def bulk_team_member_add( except Exception as e: # If the entire operation fails, mark all members as failed - verbose_proxy_logger.exception(e) + log_proxy_exception(verbose_proxy_logger, "/team/member_add[bulk]", e) error_message = str(e) results = [ TeamMemberAddResult( @@ -4391,7 +4392,12 @@ async def list_team( team_exception = """Invalid team object for team_id: {}. team_object={}. Error: {} """.format(team.team_id, team.model_dump(), str(e)) - verbose_proxy_logger.exception(team_exception) + log_proxy_exception( + verbose_proxy_logger, + "/team/list[per-team]", + e, + extra={"team_id": team.team_id, "context": team_exception}, + ) continue # Sort the responses by team_alias returned_responses.sort(key=lambda x: (getattr(x, "team_alias", "") or "")) @@ -4439,9 +4445,7 @@ async def get_paginated_teams( ) return teams, total_count except Exception as e: - verbose_proxy_logger.exception( - f"[Non-Blocking] Error getting paginated teams: {e}" - ) + log_proxy_exception(verbose_proxy_logger, "get_paginated_teams", e) return [], 0 diff --git a/litellm/proxy/management_endpoints/tool_management_endpoints.py b/litellm/proxy/management_endpoints/tool_management_endpoints.py index 19ca2c9f6be..dacf3e0d57d 100644 --- a/litellm/proxy/management_endpoints/tool_management_endpoints.py +++ b/litellm/proxy/management_endpoints/tool_management_endpoints.py @@ -21,6 +21,7 @@ from litellm._logging import verbose_proxy_logger from litellm.proxy._types import CommonProxyErrors, UserAPIKeyAuth from litellm.proxy.auth.user_api_key_auth import user_api_key_auth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.types.tool_management import ( LiteLLM_ToolTableRow, ToolDetailResponse, @@ -115,7 +116,7 @@ async def list_tools( ) return ToolListResponse(tools=tools, total=len(tools)) except Exception as e: - verbose_proxy_logger.exception("Error listing tools: %s", e) + log_proxy_exception(verbose_proxy_logger, "/tool/list", e) raise HTTPException(status_code=500, detail=str(e)) @@ -152,7 +153,7 @@ async def get_tool_detail( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception("Error getting tool detail: %s", e) + log_proxy_exception(verbose_proxy_logger, "/tool/detail", e) raise HTTPException(status_code=500, detail=str(e)) @@ -301,7 +302,7 @@ async def get_tool_usage_logs( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception("Error getting tool usage logs: %s", e) + log_proxy_exception(verbose_proxy_logger, "/tool/usage_logs", e) raise HTTPException(status_code=500, detail=str(e)) @@ -334,7 +335,7 @@ async def get_tool( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception("Error getting tool: %s", e) + log_proxy_exception(verbose_proxy_logger, "/tool/get", e) raise HTTPException(status_code=500, detail=str(e)) @@ -527,7 +528,7 @@ async def update_tool_policy( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception("Error updating tool policy: %s", e) + log_proxy_exception(verbose_proxy_logger, "/tool/policy/update", e) raise HTTPException(status_code=500, detail=str(e)) @@ -601,5 +602,5 @@ async def delete_tool_policy_override( except HTTPException: raise except Exception as e: - verbose_proxy_logger.exception("Error deleting tool policy override: %s", e) + log_proxy_exception(verbose_proxy_logger, "/tool/policy/delete", e) raise HTTPException(status_code=500, detail=str(e)) diff --git a/litellm/proxy/management_endpoints/ui_sso.py b/litellm/proxy/management_endpoints/ui_sso.py index d6082899c02..0d3f54b2a65 100644 --- a/litellm/proxy/management_endpoints/ui_sso.py +++ b/litellm/proxy/management_endpoints/ui_sso.py @@ -88,6 +88,7 @@ admin_ui_disabled, show_missing_vars_in_env, ) +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.common_utils.html_forms.jwt_display_template import ( jwt_display_template, ) @@ -1316,10 +1317,11 @@ def _handle_generic_sso_error( additional_headers, ) else: - verbose_proxy_logger.exception( - "Error verifying and processing generic SSO: %s. Passed in headers: %s", + log_proxy_exception( + verbose_proxy_logger, + "generic_sso_verify", e, - additional_headers, + extra={"additional_headers": additional_headers}, ) raise e @@ -1661,9 +1663,7 @@ async def get_user_info_from_db( return user_info except Exception as e: - verbose_proxy_logger.exception( - f"[Non-Blocking] Error trying to add sso user to db: {e}" - ) + log_proxy_exception(verbose_proxy_logger, "sso_add_user_to_db", e) return None @@ -2898,9 +2898,7 @@ async def upsert_sso_user( ) return user_info except Exception as e: - verbose_proxy_logger.exception( - f"Error upserting SSO user into LiteLLM DB: {e}" - ) + log_proxy_exception(verbose_proxy_logger, "sso_upsert_user", e) return user_info @staticmethod @@ -3020,7 +3018,7 @@ async def create_litellm_team_from_sso_group( ), ) except Exception as e: - verbose_proxy_logger.exception(f"Error creating Litellm Team: {e}") + log_proxy_exception(verbose_proxy_logger, "sso_create_team", e) @staticmethod def _cast_and_deepcopy_litellm_default_team_params( diff --git a/litellm/proxy/proxy_server.py b/litellm/proxy/proxy_server.py index f7943497e1d..e9e15a9652c 100644 --- a/litellm/proxy/proxy_server.py +++ b/litellm/proxy/proxy_server.py @@ -288,6 +288,7 @@ def generate_feedback_box(): decrypt_value_helper, encrypt_value_helper, ) +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.common_utils.html_forms.ui_login import build_ui_login_form from litellm.proxy.common_utils.http_parsing_utils import ( _read_request_body, @@ -6706,11 +6707,7 @@ async def async_assistants_data_generator( done_message = "[DONE]" yield f"data: {done_message}\n\n" except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.async_assistants_data_generator(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/v1/assistants[stream]", e) await proxy_logging_obj.post_call_failure_hook( user_api_key_dict=user_api_key_dict, original_exception=e, @@ -7033,11 +7030,7 @@ async def async_data_generator( # noqa: PLR0915 done_message = "[DONE]" yield f"data: {done_message}\n\n" except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.async_data_generator(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/v1/chat/completions[stream]", e) await proxy_logging_obj.post_call_failure_hook( user_api_key_dict=user_api_key_dict, original_exception=e, @@ -8740,11 +8733,7 @@ async def completion( # noqa: PLR0915 await proxy_logging_obj.post_call_failure_hook( user_api_key_dict=user_api_key_dict, original_exception=e, request_data=data ) - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.completion(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/v1/completions", e) error_msg = f"{str(e)}" raise ProxyException( message=getattr(e, "message", error_msg), @@ -9006,11 +8995,7 @@ async def moderations( await proxy_logging_obj.post_call_failure_hook( user_api_key_dict=user_api_key_dict, original_exception=e, request_data=data ) - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.moderations(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/v1/moderations", e) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "message", str(e)), @@ -9298,11 +9283,7 @@ async def audio_transcriptions( await proxy_logging_obj.post_call_failure_hook( user_api_key_dict=user_api_key_dict, original_exception=e, request_data=data ) - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.audio_transcription(): Exception occured - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/v1/audio/transcriptions", e) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "message", str(e.detail)), @@ -9461,7 +9442,7 @@ async def return_body(): route_type="_arealtime", ) except Exception as e: - verbose_proxy_logger.exception("Realtime pre-call error") + log_proxy_exception(verbose_proxy_logger, "/realtime[pre-call]", e) try: await websocket.send_text( json.dumps( @@ -9490,10 +9471,10 @@ async def return_body(): ) await llm_call except websockets.exceptions.InvalidStatusCode as e: # type: ignore - verbose_proxy_logger.exception("Invalid status code") + log_proxy_exception(verbose_proxy_logger, "/realtime[upstream-status]", e) await websocket.close(code=e.status_code, reason="Invalid status code") - except Exception: - verbose_proxy_logger.exception("Internal server error") + except Exception as e: + log_proxy_exception(verbose_proxy_logger, "/realtime", e) await websocket.close(code=1011, reason="Internal server error") @@ -10456,9 +10437,9 @@ async def token_counter(request: TokenCountRequest, call_endpoint: bool = False) model=request.model, request_kwargs={}, ) - except Exception: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.token_counter(): Exception occured while getting deployment" + except Exception as e: + log_proxy_exception( + verbose_proxy_logger, "/utils/token_counter[get-deployment]", e ) pass if deployment is not None: @@ -13084,11 +13065,7 @@ async def login_v2(request: Request): # noqa: PLR0915 json_response.set_cookie(key="token", value=jwt_token) return json_response except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.login_v2(): Exception occurred - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/login_v2", e) if isinstance(e, ProxyException): raise e elif isinstance(e, HTTPException): @@ -13175,11 +13152,7 @@ async def login_v3(request: Request): # noqa: PLR0915 status_code=status.HTTP_200_OK, ) except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.login_v3(): Exception occurred - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/login_v3", e) if isinstance(e, ProxyException): raise e elif isinstance(e, HTTPException): @@ -13254,11 +13227,7 @@ async def login_v3_exchange(request: Request): except ProxyException: raise except Exception as e: - verbose_proxy_logger.exception( - "litellm.proxy.proxy_server.login_v3_exchange(): Exception occurred - {}".format( - str(e) - ) - ) + log_proxy_exception(verbose_proxy_logger, "/login_v3/exchange", e) raise ProxyException( message=str(e), type=ProxyErrorTypes.auth_error, @@ -14917,7 +14886,7 @@ async def reload_model_cost_map( "timestamp": current_time.isoformat(), } except Exception as e: - verbose_proxy_logger.exception(f"Failed to reload model cost map: {str(e)}") + log_proxy_exception(verbose_proxy_logger, "/reload/model_cost_map", e) raise HTTPException( status_code=500, detail=f"Failed to reload model cost map: {str(e)}" ) @@ -14986,9 +14955,7 @@ async def schedule_model_cost_map_reload( "timestamp": datetime.utcnow().isoformat(), } except Exception as e: - verbose_proxy_logger.exception( - f"Failed to schedule model cost map reload: {str(e)}" - ) + log_proxy_exception(verbose_proxy_logger, "/schedule/model_cost_map_reload", e) raise HTTPException( status_code=500, detail=f"Failed to schedule model cost map reload: {str(e)}", @@ -15037,8 +15004,8 @@ async def cancel_model_cost_map_reload( "timestamp": datetime.utcnow().isoformat(), } except Exception as e: - verbose_proxy_logger.exception( - f"Failed to cancel model cost map reload: {str(e)}" + log_proxy_exception( + verbose_proxy_logger, "/schedule/model_cost_map_reload[cancel]", e ) raise HTTPException( status_code=500, detail=f"Failed to cancel model cost map reload: {str(e)}" @@ -15132,8 +15099,8 @@ async def get_model_cost_map_reload_status( "next_run": next_run, } except Exception as e: - verbose_proxy_logger.exception( - f"Failed to get model cost map reload status: {str(e)}" + log_proxy_exception( + verbose_proxy_logger, "/schedule/model_cost_map_reload/status", e ) raise HTTPException( status_code=500, @@ -15182,9 +15149,7 @@ async def get_model_cost_map_source( "model_count": model_count, } except Exception as e: - verbose_proxy_logger.exception( - f"Failed to get model cost map source info: {str(e)}" - ) + log_proxy_exception(verbose_proxy_logger, "/get/model_cost_map_source", e) raise HTTPException( status_code=500, detail=f"Failed to get model cost map source info: {str(e)}", @@ -15275,9 +15240,7 @@ async def reload_anthropic_beta_headers( "timestamp": current_time.isoformat(), } except Exception as e: - verbose_proxy_logger.exception( - f"Failed to reload anthropic beta headers: {str(e)}" - ) + log_proxy_exception(verbose_proxy_logger, "/reload/anthropic_beta_headers", e) raise HTTPException( status_code=500, detail=f"Failed to reload anthropic beta headers: {str(e)}" ) @@ -15346,8 +15309,8 @@ async def schedule_anthropic_beta_headers_reload( "timestamp": datetime.utcnow().isoformat(), } except Exception as e: - verbose_proxy_logger.exception( - f"Failed to schedule anthropic beta headers reload: {str(e)}" + log_proxy_exception( + verbose_proxy_logger, "/schedule/anthropic_beta_headers_reload", e ) raise HTTPException( status_code=500, @@ -15397,8 +15360,8 @@ async def cancel_anthropic_beta_headers_reload( "timestamp": datetime.utcnow().isoformat(), } except Exception as e: - verbose_proxy_logger.exception( - f"Failed to cancel anthropic beta headers reload: {str(e)}" + log_proxy_exception( + verbose_proxy_logger, "/schedule/anthropic_beta_headers_reload[cancel]", e ) raise HTTPException( status_code=500, @@ -15497,8 +15460,8 @@ async def get_anthropic_beta_headers_reload_status( "next_run": next_run, } except Exception as e: - verbose_proxy_logger.exception( - f"Failed to get anthropic beta headers reload status: {str(e)}" + log_proxy_exception( + verbose_proxy_logger, "/schedule/anthropic_beta_headers_reload/status", e ) raise HTTPException( status_code=500, diff --git a/litellm/proxy/route_llm_request.py b/litellm/proxy/route_llm_request.py index 8f6f7084a0c..0eb6dd20ab5 100644 --- a/litellm/proxy/route_llm_request.py +++ b/litellm/proxy/route_llm_request.py @@ -5,6 +5,7 @@ import litellm from litellm.proxy._types import UserAPIKeyAuth +from litellm.proxy.common_utils.exception_logging import log_proxy_exception # Router-internal mock_testing_* flag names — kept in sync with # ``litellm.types.router.MockRouterTestingParams`` by the test @@ -207,9 +208,9 @@ async def add_shared_session_to_data(data: dict) -> None: new_session = ( await proxy_server._initialize_shared_aiohttp_session() ) - except Exception: - verbose_proxy_logger.exception( - "SESSION REUSE: Exception during shared session recreation" + except Exception as e: + log_proxy_exception( + verbose_proxy_logger, "shared_aiohttp_session[recreate]", e ) new_session = None if new_session is not None: diff --git a/litellm/proxy/utils.py b/litellm/proxy/utils.py index 14f7f411e41..0e9a8e36be4 100644 --- a/litellm/proxy/utils.py +++ b/litellm/proxy/utils.py @@ -105,6 +105,7 @@ UserAPIKeyAuth, ) from litellm.proxy.auth.route_checks import RouteChecks +from litellm.proxy.common_utils.exception_logging import log_proxy_exception from litellm.proxy.common_utils.user_api_key_cache import UserApiKeyCache from litellm.proxy.db.create_views import ( create_missing_views, @@ -2045,12 +2046,16 @@ async def post_call_failure_hook( transformed_exception = e except Exception as e: # Log non-HTTPException errors from callbacks but don't break the flow - verbose_proxy_logger.exception( - f"[Non-Blocking] Error in async_post_call_failure_hook callback: {e}" + log_proxy_exception( + verbose_proxy_logger, + "async_post_call_failure_hook_callback", + e, ) except Exception as e: - verbose_proxy_logger.exception( - f"[Non-Blocking] Error setting up post_call_failure_hook callback: {e}" + log_proxy_exception( + verbose_proxy_logger, + "post_call_failure_hook_setup", + e, ) return transformed_exception @@ -2349,8 +2354,8 @@ async def post_call_response_headers_hook( if result is not None: merged_headers.update(result) except Exception as e: - verbose_proxy_logger.exception( - "Error in post_call_response_headers_hook: %s", str(e) + log_proxy_exception( + verbose_proxy_logger, "post_call_response_headers_hook", e ) return merged_headers @@ -5060,9 +5065,7 @@ async def send_email( ) except Exception as e: - verbose_proxy_logger.exception( - "An error occurred while sending the email:" + str(e) - ) + log_proxy_exception(verbose_proxy_logger, "send_email", e) def hash_token(token: str): @@ -5794,11 +5797,18 @@ def _get_openapi_url() -> Optional[str]: def handle_exception_on_proxy(e: Exception) -> ProxyException: """ - Returns an Exception as ProxyException, this ensures all exceptions are OpenAI API compatible + Returns an Exception as ProxyException, this ensures all exceptions are OpenAI API compatible. + + Callers are expected to have logged this exception via + ``log_proxy_exception`` already (which classifies 4xx / upstream 5xx + as WARN without a traceback). Emit only a DEBUG line here so the + ERROR stream stays signal — calling ``.exception()`` unconditionally + re-emitted every routine 401/404/409 with a full traceback, which is + exactly what the WARN routing in the endpoints was meant to silence. """ from fastapi import status - verbose_proxy_logger.exception(f"Exception: {e}") + verbose_proxy_logger.debug("handle_exception_on_proxy: %s", e) if isinstance(e, HTTPException): return ProxyException( 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 4ccde85dae2..e32fb242b1f 100644 --- a/tests/test_litellm/proxy/auth/test_auth_exception_handler.py +++ b/tests/test_litellm/proxy/auth/test_auth_exception_handler.py @@ -143,6 +143,421 @@ async def test_handle_authentication_error_budget_exceeded(): assert int(exc_info.value.code) == status.HTTP_429_TOO_MANY_REQUESTS +@pytest.mark.asyncio +async def test_known_auth_failure_logs_at_warning_without_traceback(caplog): + """ + Regression for log-level mismatch: routine auth failures (no key, + expired key, invalid key, role mismatch) used to be logged at ERROR + with a full traceback via verbose_proxy_logger.exception. That fired + on every 401 from a probe/scanner and buried real errors. They must + now log at WARNING without exc_info, while truly unexpected exceptions + keep ERROR + traceback. + """ + import logging + + handler = UserAPIKeyAuthExceptionHandler() + + mock_request = MagicMock() + mock_request.headers = {"x-litellm-call-id": "call-abc-123"} + mock_request_data: dict = {} + test_route = "/v1/chat/completions" + mock_span = None + mock_api_key = "test-key" + + with ( + patch( + "litellm.proxy.proxy_server.general_settings", + {"allow_requests_on_db_unavailable": False}, + ), + patch( + "litellm.proxy.proxy_server.proxy_logging_obj.post_call_failure_hook", + new_callable=AsyncMock, + ), + ): + caplog.set_level(logging.WARNING, logger=verbose_proxy_logger.name) + # ProxyException is a known auth failure type — should log at WARN. + proxy_exc = ProxyException( + message="Authentication Error - Expired Key", + type=ProxyErrorTypes.auth_error, + param=None, + code=401, + ) + try: + await handler._handle_authentication_error( + proxy_exc, + mock_request, + mock_request_data, + test_route, + mock_span, + mock_api_key, + ) + except Exception: + pass + + auth_records = [ + r for r in caplog.records if "user_api_key_auth failed" in r.getMessage() + ] + assert len(auth_records) == 1, "expected exactly one auth-failure log record" + record = auth_records[0] + # WARN level for the known auth error class. + assert record.levelno == logging.WARNING + # No traceback attached — exc_info=False sets the record attribute to + # False, not None. Treat both as "no traceback". + assert not record.exc_info + # Structured extras carry the useful signal for log search / alerting. + assert getattr(record, "request_id", None) == "call-abc-123" + assert getattr(record, "route", None) == test_route + assert getattr(record, "exception_type", None) == "ProxyException" + # ProxyException.code is stored as string; whichever attribute the + # exception exposed, the structured field carries it through. Compare + # via str() so the test is robust to int/str representation. + assert str(getattr(record, "http_status", None)) == "401" + + +@pytest.mark.asyncio +async def test_unknown_exception_logs_at_error_with_traceback(caplog): + """ + Counterpart to the previous test: unexpected exceptions (not a known + auth failure type) must still log at ERROR with a full traceback so + operators see real bugs. + """ + import logging + + handler = UserAPIKeyAuthExceptionHandler() + + mock_request = MagicMock() + mock_request.headers = {} + mock_request_data: dict = {} + test_route = "/v1/chat/completions" + + with ( + patch( + "litellm.proxy.proxy_server.general_settings", + {"allow_requests_on_db_unavailable": False}, + ), + patch( + "litellm.proxy.proxy_server.proxy_logging_obj.post_call_failure_hook", + new_callable=AsyncMock, + ), + ): + caplog.set_level(logging.WARNING, logger=verbose_proxy_logger.name) + # ValueError is NOT in _KNOWN_AUTH_ERROR_TYPES — must surface as ERROR. + try: + await handler._handle_authentication_error( + ValueError("totally unexpected"), + mock_request, + mock_request_data, + test_route, + None, + "test-key", + ) + except Exception: + pass + + auth_records = [ + r for r in caplog.records if "user_api_key_auth failed" in r.getMessage() + ] + assert len(auth_records) == 1 + record = auth_records[0] + assert record.levelno == logging.ERROR + # Traceback attached — exc_info=True populates this tuple at log time. + assert record.exc_info is not None + assert getattr(record, "exception_type", None) == "ValueError" + + +@pytest.mark.asyncio +@pytest.mark.parametrize( + "message", + [ + # Bare Exception raised from litellm/proxy/auth/user_api_key_auth.py:944 + # when the request has no Authorization header. Before the + # classifier-aware _is_known check, this surfaced as + # ERROR + traceback on every unauthenticated probe — the + # exact noise that motivated this work. + "No api key passed in.", + # Same shape, different raise site (Malformed key, virtual-key prefix). + "Malformed API Key passed in. Ensure Key has `Bearer` prefix.", + "LiteLLM Virtual Key expected. Received=foo, expected to start with 'sk-'", + ], +) +async def test_bare_exception_with_known_auth_marker_logs_at_warning( + message: str, caplog +): + """ + Regression: ``user_api_key_auth`` raises bare ``Exception(...)`` + objects for missing/malformed credentials. These are normal 401 + outcomes from probes and fat-fingered keys — they must log at + WARN without a traceback, even though the exception's *type* is + not in ``_KNOWN_AUTH_ERROR_TYPES``. The classifier identifies + them by message content; the WARN routing must trust that + classification. + + Discovered in e2e: a stream of unauthenticated requests was + flooding the ERROR log with ``Exception: No api key passed in.`` + tracebacks because ``isinstance(e, _KNOWN_AUTH_ERROR_TYPES)`` + alone missed bare Exceptions. + """ + import logging + + handler = UserAPIKeyAuthExceptionHandler() + + mock_request = MagicMock() + mock_request.headers = {} + mock_request_data: dict = {} + test_route = "/v1/chat/completions" + + with ( + patch( + "litellm.proxy.proxy_server.general_settings", + {"allow_requests_on_db_unavailable": False}, + ), + patch( + "litellm.proxy.proxy_server.proxy_logging_obj.post_call_failure_hook", + new_callable=AsyncMock, + ), + ): + caplog.set_level(logging.WARNING, logger=verbose_proxy_logger.name) + try: + await handler._handle_authentication_error( + Exception(message), + mock_request, + mock_request_data, + test_route, + None, + "test-key", + ) + except Exception: + pass + + auth_records = [ + r for r in caplog.records if "user_api_key_auth failed" in r.getMessage() + ] + assert len(auth_records) == 1 + record = auth_records[0] + assert record.levelno == logging.WARNING + # No traceback — that's the whole point of routing this to WARN. + assert not record.exc_info + + +@pytest.mark.asyncio +async def test_empty_exception_message_falls_back_to_type_name(caplog): + """ + ProxyException sometimes carries an empty `message` field; without the + fallback the log line collapses to just the type name with no signal. + Verify the format string substitutes the type name when str(e) is empty. + """ + import logging + + handler = UserAPIKeyAuthExceptionHandler() + + mock_request = MagicMock() + mock_request.headers = {} + mock_request_data: dict = {} + + with ( + patch( + "litellm.proxy.proxy_server.general_settings", + {"allow_requests_on_db_unavailable": False}, + ), + patch( + "litellm.proxy.proxy_server.proxy_logging_obj.post_call_failure_hook", + new_callable=AsyncMock, + ), + ): + caplog.set_level(logging.WARNING, logger=verbose_proxy_logger.name) + empty_exc = ProxyException( + message="", + type=ProxyErrorTypes.auth_error, + param=None, + code=401, + ) + try: + await handler._handle_authentication_error( + empty_exc, + mock_request, + mock_request_data, + "/v1/chat/completions", + None, + "test-key", + ) + except Exception: + pass + + auth_records = [ + r for r in caplog.records if "user_api_key_auth failed" in r.getMessage() + ] + assert len(auth_records) == 1 + # Message body should contain the exception type name (the fallback), + # not be empty after the "user_api_key_auth failed:" prefix. + assert "ProxyException" in auth_records[0].getMessage() + + +class TestClassifyAuthFailure: + """Pure unit tests for `_classify_auth_failure` — guards the + contract that wrapped HTTPExceptions surface as a specific auth_* + type, so UI clients can route on `error.type` instead of regex- + matching free-text messages.""" + + def test_403_maps_to_permission_denied_regardless_of_detail(self): + from litellm.proxy.auth.auth_exception_handler import _classify_auth_failure + + e = HTTPException(status_code=403, detail="anything at all") + assert _classify_auth_failure(e) == ProxyErrorTypes.auth_permission_denied + + @pytest.mark.parametrize( + "detail", + [ + "Key has expired", + "Authentication Error - Expired Key", + "Your API key has been revoked", + "Key has been deleted", + ], + ) + def test_401_with_expired_marker_maps_to_session_expired(self, detail): + from litellm.proxy.auth.auth_exception_handler import _classify_auth_failure + + e = HTTPException(status_code=401, detail=detail) + assert _classify_auth_failure(e) == ProxyErrorTypes.auth_session_expired + + @pytest.mark.parametrize( + "detail", + [ + "No auth header passed in", + "No authentication credentials supplied", + "Invalid API Key", + "Invalid token format", + "Invalid bearer credentials", + "Token not found in database", + "Key not found in database", + "Malformed authorization header", + ], + ) + def test_401_with_invalid_credential_marker_maps_to_invalid_credentials( + self, detail + ): + from litellm.proxy.auth.auth_exception_handler import _classify_auth_failure + + e = HTTPException(status_code=401, detail=detail) + assert _classify_auth_failure(e) == ProxyErrorTypes.auth_invalid_credentials + + @pytest.mark.parametrize( + "detail", + [ + "Not allowed to access this endpoint", + "Not authorized for this resource", + "Admin only endpoint", + "Admin-only operation", + "Master Key required", + "Requires admin role to access", + "Insufficient permission", + "Forbidden", + "Access denied", + ], + ) + def test_401_with_permission_marker_maps_to_permission_denied(self, detail): + from litellm.proxy.auth.auth_exception_handler import _classify_auth_failure + + e = HTTPException(status_code=401, detail=detail) + assert _classify_auth_failure(e) == ProxyErrorTypes.auth_permission_denied + + def test_401_with_unknown_detail_falls_back_to_auth_error(self): + # Critical fallback: ambiguous messages must NOT silently map to + # a wrong specific type. The UI's heuristic handles auth_error. + from litellm.proxy.auth.auth_exception_handler import _classify_auth_failure + + e = HTTPException(status_code=401, detail="something we have never seen") + assert _classify_auth_failure(e) == ProxyErrorTypes.auth_error + + def test_401_with_empty_detail_falls_back_to_auth_error(self): + from litellm.proxy.auth.auth_exception_handler import _classify_auth_failure + + e = HTTPException(status_code=401, detail="") + assert _classify_auth_failure(e) == ProxyErrorTypes.auth_error + + def test_expired_markers_take_priority_over_invalid_markers(self): + # A revoked key can surface as both "invalid" and "revoked" — we + # prefer session_expired (the recovery flow is the same and the + # label is semantically more accurate). + from litellm.proxy.auth.auth_exception_handler import _classify_auth_failure + + e = HTTPException(status_code=401, detail="Invalid API Key - has been revoked") + assert _classify_auth_failure(e) == ProxyErrorTypes.auth_session_expired + + +@pytest.mark.asyncio +async def test_wrapped_httpexception_carries_classified_type(): + """Wire-format contract: a wrapped HTTPException emerges as a + ProxyException with the classified specific type, not the generic + `auth_error`. UI's PR D2 handleErrorResponse keys off this.""" + handler = UserAPIKeyAuthExceptionHandler() + mock_request = MagicMock() + mock_request.headers = {} + + with ( + patch( + "litellm.proxy.proxy_server.general_settings", + {"allow_requests_on_db_unavailable": False}, + ), + patch( + "litellm.proxy.proxy_server.proxy_logging_obj.post_call_failure_hook", + # AsyncMock's default return is a MagicMock — the wrapper at + # auth_exception_handler.py treats any truthy return as + # `transformed_exception` and replaces the original `e`, + # which destroys the type we want to assert. Pin + # return_value=None so the HTTPException flows through. + new=AsyncMock(return_value=None), + ), + ): + expired_http_exc = HTTPException( + status_code=401, detail="Authentication Error - Expired Key" + ) + with pytest.raises(ProxyException) as exc_info: + await handler._handle_authentication_error( + expired_http_exc, + mock_request, + {}, + "/v1/chat/completions", + None, + "test-key", + ) + + assert exc_info.value.type == ProxyErrorTypes.auth_session_expired + + +@pytest.mark.asyncio +async def test_wrapped_httpexception_permission_denied_carries_specific_type(): + handler = UserAPIKeyAuthExceptionHandler() + mock_request = MagicMock() + mock_request.headers = {} + + with ( + patch( + "litellm.proxy.proxy_server.general_settings", + {"allow_requests_on_db_unavailable": False}, + ), + patch( + "litellm.proxy.proxy_server.proxy_logging_obj.post_call_failure_hook", + # Pin return None — see comment in + # test_wrapped_httpexception_carries_classified_type. + new=AsyncMock(return_value=None), + ), + ): + perm_http_exc = HTTPException( + status_code=401, detail="Master Key required to access this endpoint" + ) + with pytest.raises(ProxyException) as exc_info: + await handler._handle_authentication_error( + perm_http_exc, + mock_request, + {}, + "/key/new", + None, + "test-key", + ) + + assert exc_info.value.type == ProxyErrorTypes.auth_permission_denied + + @pytest.mark.asyncio async def test_route_passed_to_post_call_failure_hook(): """ diff --git a/tests/test_litellm/proxy/common_utils/test_exception_logging.py b/tests/test_litellm/proxy/common_utils/test_exception_logging.py new file mode 100644 index 00000000000..ddfda7965b1 --- /dev/null +++ b/tests/test_litellm/proxy/common_utils/test_exception_logging.py @@ -0,0 +1,274 @@ +"""Tests for litellm.proxy.common_utils.exception_logging. + +The contract under test: every exception raised in a proxy route +handler gets routed to WARN (no traceback) or ERROR (with traceback) +based on whether it represents a client-induced/business outcome or +an unexpected server fault. These tests pin that policy so future +edits to the classifier can't silently re-introduce the +ERROR+traceback flood that triggered this work. +""" + +import logging + +import pytest +from fastapi import HTTPException + +import litellm +from litellm.proxy._types import ProxyException +from litellm.proxy.common_utils.exception_logging import ( + classify_log_level, + log_proxy_exception, +) + + +# --------------------------------------------------------------------------- +# classify_log_level — known business exception types must be WARN +# --------------------------------------------------------------------------- + + +class TestBusinessExceptionsAreWarnings: + """The whole point of this module is that these never become + ERROR-level traceback floods. If any of these regresses, this file + is the canary.""" + + def test_http_exception_409_is_warning(self) -> None: + e = HTTPException(status_code=409, detail="User already exists") + assert classify_log_level(e) == logging.WARNING + + def test_http_exception_404_is_warning(self) -> None: + e = HTTPException(status_code=404, detail="not found") + assert classify_log_level(e) == logging.WARNING + + def test_proxy_exception_is_warning(self) -> None: + e = ProxyException( + message="Invalid token", + type="auth_invalid_credentials", + param=None, + code=401, + ) + assert classify_log_level(e) == logging.WARNING + + def test_budget_exceeded_is_warning(self) -> None: + e = litellm.BudgetExceededError(current_cost=10.0, max_budget=5.0) + assert classify_log_level(e) == logging.WARNING + + def test_unsupported_params_is_warning(self) -> None: + # The trigger case from the original investigation: zai + # rejecting context_management should not be an ERROR. + e = litellm.UnsupportedParamsError( + status_code=400, + message="zai does not support parameters: ['context_management']", + ) + assert classify_log_level(e) == logging.WARNING + + def test_context_window_exceeded_is_warning(self) -> None: + e = litellm.ContextWindowExceededError( + message="too long", model="gpt-4", llm_provider="openai" + ) + assert classify_log_level(e) == logging.WARNING + + +# --------------------------------------------------------------------------- +# classify_log_level — status-code based fallback +# --------------------------------------------------------------------------- + + +class TestStatusCodeFallback: + """Even when the type isn't in our known list, a 4xx status_code + or an upstream-5xx code is enough to route to WARN. Catches + third-party subclasses we haven't named explicitly.""" + + def test_unknown_exception_with_4xx_status_code_is_warning(self) -> None: + class CustomClientError(Exception): + status_code = 422 + + assert classify_log_level(CustomClientError()) == logging.WARNING + + def test_unknown_exception_with_503_is_warning(self) -> None: + class UpstreamUnavailable(Exception): + status_code = 503 + + assert classify_log_level(UpstreamUnavailable()) == logging.WARNING + + def test_unknown_exception_with_502_is_warning(self) -> None: + class BadGateway(Exception): + status_code = 502 + + assert classify_log_level(BadGateway()) == logging.WARNING + + def test_unknown_exception_with_504_is_warning(self) -> None: + class GatewayTimeout(Exception): + status_code = 504 + + assert classify_log_level(GatewayTimeout()) == logging.WARNING + + def test_exception_with_code_attr_instead_of_status_code(self) -> None: + """ProxyException-shaped objects expose ``.code`` not ``.status_code``.""" + + class CodeOnly(Exception): + code = 409 + + assert classify_log_level(CodeOnly()) == logging.WARNING + + +# --------------------------------------------------------------------------- +# classify_log_level — unexpected exceptions must remain ERROR +# --------------------------------------------------------------------------- + + +class TestUnexpectedExceptionsAreErrors: + """The other side of the contract: real bugs must keep their + traceback. If WARN spreads to these, we lose ERROR signal entirely. + """ + + def test_runtime_error_is_error(self) -> None: + assert classify_log_level(RuntimeError("boom")) == logging.ERROR + + def test_key_error_is_error(self) -> None: + assert classify_log_level(KeyError("missing")) == logging.ERROR + + def test_attribute_error_is_error(self) -> None: + assert classify_log_level(AttributeError("no attr")) == logging.ERROR + + def test_bare_exception_is_error(self) -> None: + assert classify_log_level(Exception("???")) == logging.ERROR + + def test_unknown_exception_with_500_is_error(self) -> None: + """A plain 500 (not 502/503/504) is "we crashed". Keep the + traceback.""" + + class WeCrashed(Exception): + status_code = 500 + + assert classify_log_level(WeCrashed()) == logging.ERROR + + def test_unknown_exception_with_no_status_code_is_error(self) -> None: + class Mystery(Exception): + pass + + assert classify_log_level(Mystery()) == logging.ERROR + + +# --------------------------------------------------------------------------- +# log_proxy_exception — emission shape +# --------------------------------------------------------------------------- + + +class TestLogProxyExceptionEmission: + """Verify the emitted LogRecord shape: level, exc_info, extra + fields. Downstream log consumers grep on these, so this is part of + the public contract.""" + + def _capture(self, logger_name: str, level: int = logging.DEBUG): + logger = logging.getLogger(logger_name) + logger.setLevel(level) + records: list[logging.LogRecord] = [] + + class _H(logging.Handler): + def emit(self, record): # noqa: D401 + records.append(record) + + handler = _H() + logger.addHandler(handler) + return logger, records, handler + + def test_business_exception_emits_warning_without_traceback(self) -> None: + logger, records, handler = self._capture("test.exc.warn") + try: + log_proxy_exception( + logger, + "/user/new", + HTTPException(status_code=409, detail="User already exists"), + ) + finally: + logger.removeHandler(handler) + + assert len(records) == 1 + rec = records[0] + assert rec.levelno == logging.WARNING + # exc_info must be falsy — that's how we suppress the traceback + assert not rec.exc_info + assert rec.route == "/user/new" + assert rec.http_status == 409 + assert rec.exception_type == "HTTPException" + # The detail (not the type name) must appear in the formatted message + assert "User already exists" in rec.getMessage() + + def test_unexpected_exception_emits_error_with_traceback(self) -> None: + logger, records, handler = self._capture("test.exc.err") + try: + try: + raise RuntimeError("kaboom") + except RuntimeError as e: + log_proxy_exception(logger, "/user/new", e) + finally: + logger.removeHandler(handler) + + assert len(records) == 1 + rec = records[0] + assert rec.levelno == logging.ERROR + # exc_info must be present (a tuple) so the traceback formatter + # has something to work with + assert rec.exc_info is not None + assert rec.exception_type == "RuntimeError" + assert rec.http_status is None + + def test_empty_str_exception_falls_back_to_type_name(self) -> None: + """Some ProxyException instances stringify to ''. The log line + must never be empty — fall back to the class name so logs are + always grep-able by exception_type or message.""" + logger, records, handler = self._capture("test.exc.empty") + + class Silent(Exception): + def __str__(self): # noqa: D401 + return "" + + try: + log_proxy_exception(logger, "/user/new", Silent()) + finally: + logger.removeHandler(handler) + + assert len(records) == 1 + assert "Silent" in records[0].getMessage() + + def test_extra_kwargs_are_merged(self) -> None: + logger, records, handler = self._capture("test.exc.extra") + try: + log_proxy_exception( + logger, + "/team/update", + HTTPException(status_code=403, detail="forbidden"), + extra={"team_id": "abc123"}, + ) + finally: + logger.removeHandler(handler) + + assert len(records) == 1 + rec = records[0] + assert rec.team_id == "abc123" + assert rec.route == "/team/update" + assert rec.http_status == 403 + + +# --------------------------------------------------------------------------- +# Parametric coverage for the wider 4xx range, since the body of +# classify_log_level uses a range check. +# --------------------------------------------------------------------------- + + +@pytest.mark.parametrize("code", [400, 401, 402, 403, 404, 409, 422, 429, 499]) +def test_all_4xx_codes_route_to_warning(code: int) -> None: + class _E(Exception): + status_code = code + + assert classify_log_level(_E()) == logging.WARNING + + +@pytest.mark.parametrize("code", [500, 501, 505, 599]) +def test_non_upstream_5xx_codes_route_to_error(code: int) -> None: + """502/503/504 are upstream, everything else in 5xx is ours.""" + + class _E(Exception): + status_code = code + + assert classify_log_level(_E()) == logging.ERROR