diff --git a/litellm/proxy/anthropic_endpoints/endpoints.py b/litellm/proxy/anthropic_endpoints/endpoints.py index d4cb3b84ee4..644778bcb9f 100644 --- a/litellm/proxy/anthropic_endpoints/endpoints.py +++ b/litellm/proxy/anthropic_endpoints/endpoints.py @@ -8,7 +8,6 @@ from fastapi import APIRouter, Depends, HTTPException, Request, Response from fastapi.responses import JSONResponse import litellm -from litellm._logging import verbose_proxy_logger from litellm.anthropic_interface.exceptions import AnthropicErrorResponse, AnthropicExceptionMapping from litellm.integrations.custom_guardrail import ModifyResponseException from litellm.llms.anthropic.experimental_pass_through.context_management import ( @@ -22,13 +21,16 @@ from litellm.proxy.auth.user_api_key_auth import user_api_key_auth from litellm.proxy.common_request_processing import ( ProxyBaseLLMRequestProcessing, create_response, + log_llm_api_exception, proxy_exception_from_http_exception, + resolve_litellm_call_id, ) from litellm.proxy.common_utils.http_parsing_utils import _read_request_body from litellm.proxy.common_utils.openai_error_payload import ( error_status_code, openai_error_param, openai_error_type, + with_litellm_call_id, ) from litellm.types.utils import TokenCountResponse @@ -218,10 +220,12 @@ async def anthropic_response( await proxy_logging_obj.post_call_failure_hook( user_api_key_dict=user_api_key_dict, original_exception=e, request_data=base_llm_response_processor.data ) - verbose_proxy_logger.exception("litellm.proxy.proxy_server.anthropic_response(): Exception occured - %s", e) + log_llm_api_exception(e, base_llm_response_processor.litellm_call_id) if isinstance(e, ProxyException): - return _anthropic_error_json_response(e, request) + return _anthropic_error_json_response( + with_litellm_call_id(e, base_llm_response_processor.litellm_call_id), request + ) # Extract model_id from request metadata (same as success path) litellm_metadata: Final = data.get("litellm_metadata", {}) or {} @@ -231,7 +235,7 @@ async def anthropic_response( # Get headers headers: Final = ProxyBaseLLMRequestProcessing.get_custom_headers( user_api_key_dict=user_api_key_dict, - call_id=data.get("litellm_call_id", ""), + call_id=base_llm_response_processor.litellm_call_id, model_id=model_id, version=version, response_cost=0, @@ -288,6 +292,7 @@ async def count_tokens( """ from litellm.proxy.proxy_server import token_counter as internal_token_counter + litellm_call_id: Final = resolve_litellm_call_id(request.headers.get("x-litellm-call-id")) try: request_data: Final = await _read_request_body(request=request) data: Final[dict] = {**request_data} @@ -339,7 +344,7 @@ async def count_tokens( detail=detail, ) except Exception as e: - verbose_proxy_logger.exception("litellm.proxy.anthropic_endpoints.count_tokens(): Exception occurred - %s", e) + log_llm_api_exception(e, litellm_call_id) raise HTTPException(status_code=500, detail={"error": f"Internal server error: {e}"}) diff --git a/litellm/proxy/batches_endpoints/endpoints.py b/litellm/proxy/batches_endpoints/endpoints.py index 5c4bacd757c..5d9ecddd4c2 100644 --- a/litellm/proxy/batches_endpoints/endpoints.py +++ b/litellm/proxy/batches_endpoints/endpoints.py @@ -7,6 +7,7 @@ import asyncio import os from collections.abc import Mapping +from types import MappingProxyType from typing import Any, Final, cast from fastapi import APIRouter, Depends, HTTPException, Path, Request, Response @@ -17,7 +18,11 @@ from litellm.batches.main import CancelBatchRequest, RetrieveBatchRequest from litellm.proxy._types import * from litellm.proxy.auth.user_api_key_auth import user_api_key_auth from litellm.proxy.batches_endpoints.common_utils import validate_batch_list_limit -from litellm.proxy.common_request_processing import ProxyBaseLLMRequestProcessing +from litellm.proxy.common_request_processing import ( + ProxyBaseLLMRequestProcessing, + log_llm_api_exception, + request_litellm_call_id, +) from litellm.proxy.common_utils.callback_utils import sanitize_openai_provider_metadata from litellm.proxy.common_utils.http_parsing_utils import _read_request_body from litellm.proxy.common_utils.openai_endpoint_utils import ( @@ -383,8 +388,9 @@ async def create_batch( 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.create_batch(): Exception occured - %s", e) - raise handle_exception_on_proxy(e) + litellm_call_id: Final = request_litellm_call_id(data) + log_llm_api_exception(e, litellm_call_id) + raise handle_exception_on_proxy(e, litellm_call_id) @router.get( @@ -674,8 +680,9 @@ async def retrieve_batch( 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.retrieve_batch(): Exception occured - %s", e) - raise handle_exception_on_proxy(e) + litellm_call_id: Final = request_litellm_call_id(data) + log_llm_api_exception(e, litellm_call_id) + raise handle_exception_on_proxy(e, litellm_call_id) @router.get( @@ -725,6 +732,7 @@ async def list_batches( ) verbose_proxy_logger.debug("GET /v1/batches after=%s limit=%s", after, limit) + data: Mapping[str, object] = MappingProxyType({}) try: if llm_router is None: raise HTTPException( @@ -854,10 +862,11 @@ async def list_batches( await proxy_logging_obj.post_call_failure_hook( user_api_key_dict=user_api_key_dict, original_exception=e, - request_data={"after": after, "limit": limit}, + request_data={**data, "after": after, "limit": limit}, ) - verbose_proxy_logger.error("litellm.proxy.proxy_server.retrieve_batch(): Exception occured - %s", e) - raise handle_exception_on_proxy(e) + litellm_call_id: Final = request_litellm_call_id(data) + log_llm_api_exception(e, litellm_call_id) + raise handle_exception_on_proxy(e, litellm_call_id) @router.post( @@ -1079,8 +1088,9 @@ async def cancel_batch( 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.create_batch(): Exception occured - %s", e) - raise handle_exception_on_proxy(e) + litellm_call_id: Final = request_litellm_call_id(data) + log_llm_api_exception(e, litellm_call_id) + raise handle_exception_on_proxy(e, litellm_call_id) ###################################################################### diff --git a/litellm/proxy/common_request_processing.py b/litellm/proxy/common_request_processing.py index 46b222a4fc9..ba8f48b88be 100644 --- a/litellm/proxy/common_request_processing.py +++ b/litellm/proxy/common_request_processing.py @@ -7,7 +7,18 @@ from collections.abc import AsyncGenerator, Awaitable, Callable, Mapping, Sequen from datetime import datetime from functools import lru_cache from types import MappingProxyType -from typing import TYPE_CHECKING, Any, Final, Literal, NamedTuple, Protocol, TypeAlias, TypeVar, overload +from typing import ( + TYPE_CHECKING, + Any, + Final, + Literal, + NamedTuple, + Protocol, + TypeAlias, + TypeVar, + overload, + runtime_checkable, +) import anyio import httpx @@ -1452,7 +1463,19 @@ def _has_attribute_error_in_chain(exc: Exception) -> bool: _CLIENT_DISCONNECT_DETAIL: Final = "Client disconnected the request" -def _log_llm_api_exception(e: Exception, litellm_call_id: str | None) -> None: +@runtime_checkable +class _CarriesLitellmCallId(Protocol): + litellm_call_id: str | None + + +def request_litellm_call_id(data: Mapping[str, object]) -> str | None: + logging_obj: Final = data.get("litellm_logging_obj") + logged_id: Final = logging_obj.litellm_call_id if isinstance(logging_obj, _CarriesLitellmCallId) else None + call_id: Final = logged_id or data.get("litellm_call_id") + return call_id if isinstance(call_id, str) else None + + +def log_llm_api_exception(e: Exception, litellm_call_id: str | None) -> None: if getattr(e, "status_code", None) == 499 and getattr(e, "detail", None) == _CLIENT_DISCONNECT_DETAIL: verbose_proxy_logger.info( "litellm.proxy.proxy_server._handle_llm_api_exception(): client disconnected, " @@ -1532,6 +1555,10 @@ class ProxyBaseLLMRequestProcessing: def __init__(self, data: dict): self.data = data + @property + def litellm_call_id(self) -> str | None: + return request_litellm_call_id(self.data) + @staticmethod def _merge_passthrough_streaming_headers( response_headers: httpx.Headers | dict | None, @@ -3429,11 +3456,7 @@ class ProxyBaseLLMRequestProcessing: version: str | None = None, ): """Raises ProxyException (OpenAI API compatible) if an exception is raised""" - logging_obj: Final[LiteLLMLoggingObj | None] = self.data.get("litellm_logging_obj", None) - _log_llm_api_exception( - e, - (logging_obj.litellm_call_id if logging_obj is not None else None) or self.data.get("litellm_call_id"), - ) + log_llm_api_exception(e, self.litellm_call_id) # Allow callbacks to transform the error response transformed_exception: Final = await proxy_logging_obj.post_call_failure_hook( user_api_key_dict=user_api_key_dict, @@ -3463,9 +3486,7 @@ class ProxyBaseLLMRequestProcessing: custom_headers: Final = ProxyBaseLLMRequestProcessing.get_custom_headers( user_api_key_dict=user_api_key_dict, - call_id=( - _litellm_logging_obj.litellm_call_id if _litellm_logging_obj else self.data.get("litellm_call_id") - ), + call_id=self.litellm_call_id, model_id=model_id, version=version, response_cost=0, diff --git a/litellm/proxy/common_utils/openai_error_payload.py b/litellm/proxy/common_utils/openai_error_payload.py index fe23ab2c4b6..202c61b620e 100644 --- a/litellm/proxy/common_utils/openai_error_payload.py +++ b/litellm/proxy/common_utils/openai_error_payload.py @@ -9,6 +9,9 @@ from typing import Final from fastapi import status from litellm.constants import STRINGIFIED_NONE +from litellm.proxy._types import ProxyException + +LITELLM_CALL_ID_HEADER: Final = "x-litellm-call-id" _OPENAI_ERROR_TYPE_BY_STATUS: Final[Mapping[int, str]] = MappingProxyType( { @@ -52,3 +55,23 @@ def openai_error_param(exc: object) -> str | None: serializes as JSON ``null``.""" carried: Final = attribute_of(exc, "param") return carried if isinstance(carried, str) and carried != STRINGIFIED_NONE else None + + +def litellm_call_id_headers(litellm_call_id: str | None) -> dict[str, str] | None: # mutable-ok: ProxyException.headers + if litellm_call_id is None: + return None + return {LITELLM_CALL_ID_HEADER: litellm_call_id} # mutable-ok: ProxyException mutates its headers dict + + +def with_litellm_call_id(exc: ProxyException, litellm_call_id: str | None) -> ProxyException: + """The same error object, answering with ``x-litellm-call-id`` when it was raised without one.""" + if litellm_call_id is not None: + exc.headers.setdefault(LITELLM_CALL_ID_HEADER, litellm_call_id) + return exc + + +def headers_with_litellm_call_id(headers: Mapping[str, str] | None, litellm_call_id: str) -> Mapping[str, str]: + """``headers`` plus ``x-litellm-call-id``, keeping the value they already carry under that name.""" + if headers is None: + return MappingProxyType({LITELLM_CALL_ID_HEADER: litellm_call_id}) + return MappingProxyType({LITELLM_CALL_ID_HEADER: litellm_call_id, **headers}) diff --git a/litellm/proxy/image_endpoints/endpoints.py b/litellm/proxy/image_endpoints/endpoints.py index 3f044855ce8..5b90c0ff830 100644 --- a/litellm/proxy/image_endpoints/endpoints.py +++ b/litellm/proxy/image_endpoints/endpoints.py @@ -1,6 +1,5 @@ import asyncio import io -import traceback from collections.abc import Sequence from typing import Final, get_type_hints @@ -9,19 +8,23 @@ from fastapi import APIRouter, Depends, File, HTTPException, Request, Response, from fastapi.responses import ORJSONResponse import litellm -from litellm._logging import verbose_proxy_logger from litellm.litellm_core_utils.prompt_templates.common_utils import ( get_str_from_messages, ) from litellm.proxy._types import * from litellm.proxy.auth.user_api_key_auth import UserAPIKeyAuth, user_api_key_auth -from litellm.proxy.common_request_processing import ProxyBaseLLMRequestProcessing +from litellm.proxy.common_request_processing import ( + ProxyBaseLLMRequestProcessing, + log_llm_api_exception, + resolve_litellm_call_id, +) from litellm.proxy.common_utils.http_parsing_utils import ( coerce_numeric_form_fields, numeric_form_fields, ) from litellm.proxy.common_utils.openai_error_payload import ( error_status_code, + litellm_call_id_headers, openai_error_param, openai_error_type, ) @@ -91,11 +94,12 @@ async def image_generation( version, ) - data = {} + litellm_call_id: Final = resolve_litellm_call_id(request.headers.get("x-litellm-call-id")) + data = {"litellm_call_id": litellm_call_id} try: # Use orjson to parse JSON data, orjson speeds up requests significantly body: Final = await request.body() - data = orjson.loads(body) + data = orjson.loads(body) | data # Include original request and headers in the data data = await add_litellm_data_to_request( @@ -153,9 +157,7 @@ async def image_generation( response = await llm_call ### ALERTING ### - asyncio.create_task( - proxy_logging_obj.update_request_status(litellm_call_id=data.get("litellm_call_id", ""), status="success") - ) + asyncio.create_task(proxy_logging_obj.update_request_status(litellm_call_id=litellm_call_id, status="success")) ### CALL HOOKS ### - modify outgoing data (guardrails, otel, etc.) response = await proxy_logging_obj.post_call_success_hook( @@ -168,7 +170,7 @@ async def image_generation( cache_key: Final = hidden_params.get("cache_key", None) or "" api_base: Final = hidden_params.get("api_base", None) or "" response_cost: Final = hidden_params.get("response_cost", None) or "" - litellm_call_id: Final = hidden_params.get("litellm_call_id", None) or "" + response_call_id: Final = hidden_params.get("litellm_call_id", None) or "" fastapi_response.headers.update( ProxyBaseLLMRequestProcessing.get_custom_headers( @@ -179,7 +181,7 @@ async def image_generation( version=version, response_cost=response_cost, model_region=getattr(user_api_key_dict, "allowed_model_region", ""), - call_id=litellm_call_id, + call_id=response_call_id, request_data=data, hidden_params=hidden_params, ) @@ -200,13 +202,13 @@ async def image_generation( 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.error("litellm.proxy.proxy_server.image_generation(): Exception occured - %s", e) - verbose_proxy_logger.debug(traceback.format_exc()) + log_llm_api_exception(e, litellm_call_id) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "message", str(e)), type=openai_error_type(e, error_status_code(e, status.HTTP_400_BAD_REQUEST)), param=openai_error_param(e), + headers=litellm_call_id_headers(litellm_call_id), code=error_status_code(e, status.HTTP_400_BAD_REQUEST), ) else: @@ -215,6 +217,7 @@ async def image_generation( message=getattr(e, "message", error_msg), type=openai_error_type(e, error_status_code(e, 500)), param=openai_error_param(e), + headers=litellm_call_id_headers(litellm_call_id), openai_code=getattr(e, "code", None), code=error_status_code(e, 500), ) diff --git a/litellm/proxy/pass_through_endpoints/pass_through_endpoints.py b/litellm/proxy/pass_through_endpoints/pass_through_endpoints.py index 974312ab2a5..685c19062bb 100644 --- a/litellm/proxy/pass_through_endpoints/pass_through_endpoints.py +++ b/litellm/proxy/pass_through_endpoints/pass_through_endpoints.py @@ -72,7 +72,9 @@ from litellm.proxy.auth.auth_utils import request_dispatched_to_pass_through_end from litellm.proxy.auth.user_api_key_auth import user_api_key_auth from litellm.proxy.common_request_processing import ( ProxyBaseLLMRequestProcessing, + log_llm_api_exception, open_sse_before_first_byte, + resolve_litellm_call_id, ) from litellm.proxy.common_utils.http_parsing_utils import ( _read_request_body, @@ -80,6 +82,7 @@ from litellm.proxy.common_utils.http_parsing_utils import ( ) from litellm.proxy.common_utils.openai_error_payload import ( error_status_code, + litellm_call_id_headers, openai_error_param, openai_error_type, ) @@ -196,14 +199,15 @@ async def chat_completion_pass_through_endpoint( version, ) - data = {} + litellm_call_id: Final = resolve_litellm_call_id(request.headers.get("x-litellm-call-id")) + data = {"litellm_call_id": litellm_call_id} try: body: Final = await request.body() body_str: Final = body.decode() try: - data = ast.literal_eval(body_str) + data = ast.literal_eval(body_str) | data except Exception: - data = json.loads(body_str) + data = json.loads(body_str) | data data["adapter_id"] = adapter_id @@ -290,9 +294,7 @@ async def chat_completion_pass_through_endpoint( response_cost: Final = hidden_params.get("response_cost", None) or "" ### ALERTING ### - asyncio.create_task( - proxy_logging_obj.update_request_status(litellm_call_id=data.get("litellm_call_id", ""), status="success") - ) + asyncio.create_task(proxy_logging_obj.update_request_status(litellm_call_id=litellm_call_id, status="success")) verbose_proxy_logger.debug("final response: %s", response) @@ -313,12 +315,13 @@ async def chat_completion_pass_through_endpoint( 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 - %s", e) + log_llm_api_exception(e, litellm_call_id) error_msg: Final = f"{e}" raise ProxyException( message=getattr(e, "message", error_msg), type=openai_error_type(e, error_status_code(e, 500)), param=openai_error_param(e), + headers=litellm_call_id_headers(litellm_call_id), code=error_status_code(e, 500), ) diff --git a/litellm/proxy/proxy_server.py b/litellm/proxy/proxy_server.py index 1f31597c010..b7e63391d35 100644 --- a/litellm/proxy/proxy_server.py +++ b/litellm/proxy/proxy_server.py @@ -350,7 +350,10 @@ from litellm.proxy.common_request_processing import ( _is_azure_model_router_request, _should_return_raw_model_name, create_response, + log_llm_api_exception, open_sse_before_first_byte, + request_litellm_call_id, + resolve_litellm_call_id, ttft_keepalive_interval, ) from litellm.proxy.common_utils.auth_cache_invalidation_pubsub import ( @@ -389,6 +392,11 @@ from litellm.proxy.common_utils.model_listing_utils import ( from litellm.proxy.common_utils.openai_endpoint_utils import ( remove_sensitive_info_from_deployment, ) +from litellm.proxy.common_utils.openai_error_payload import ( + headers_with_litellm_call_id, + litellm_call_id_headers, + with_litellm_call_id, +) from litellm.proxy.common_utils.periodic_reload_schedule import ( MODEL_COST_MAP_RELOAD_PARAM_NAME, clear_reload_interval, @@ -11302,12 +11310,14 @@ async def completion( 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 - %s", e) + litellm_call_id: Final = request_litellm_call_id(data) + log_llm_api_exception(e, litellm_call_id) error_msg: Final = f"{e}" raise ProxyException( message=getattr(e, "message", error_msg), type=getattr(e, "type", "None"), param=getattr(e, "param", "None"), + headers=litellm_call_id_headers(litellm_call_id), openai_code=getattr(e, "code", None), code=getattr(e, "status_code", 500), ) @@ -11464,11 +11474,12 @@ async def moderations( ``` """ global proxy_logging_obj - data: dict = {} + litellm_call_id: Final = resolve_litellm_call_id(request.headers.get("x-litellm-call-id")) + data: dict = {"litellm_call_id": litellm_call_id} try: # Use orjson to parse JSON data, orjson speeds up requests significantly body: Final = await request.body() - data = orjson.loads(body) + data = orjson.loads(body) | data # Include original request and headers in the data data = await add_litellm_data_to_request( @@ -11505,9 +11516,7 @@ async def moderations( response: Final = await llm_call ### ALERTING ### - asyncio.create_task( - proxy_logging_obj.update_request_status(litellm_call_id=data.get("litellm_call_id", ""), status="success") - ) + asyncio.create_task(proxy_logging_obj.update_request_status(litellm_call_id=litellm_call_id, status="success")) ### RESPONSE HEADERS ### hidden_params: Final = getattr(response, "_hidden_params", {}) or {} @@ -11533,14 +11542,15 @@ 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 - %s", e) + log_llm_api_exception(e, litellm_call_id) if isinstance(e, ProxyException): - raise + raise with_litellm_call_id(e, litellm_call_id) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "message", str(e)), type=getattr(e, "type", "None"), param=getattr(e, "param", "None"), + headers=litellm_call_id_headers(litellm_call_id), code=getattr(e, "status_code", status.HTTP_400_BAD_REQUEST), ) else: @@ -11549,6 +11559,7 @@ async def moderations( message=getattr(e, "message", error_msg), type=getattr(e, "type", "None"), param=getattr(e, "param", "None"), + headers=litellm_call_id_headers(litellm_call_id), code=getattr(e, "status_code", 500), ) @@ -11586,11 +11597,12 @@ async def audio_speech( https://platform.openai.com/docs/api-reference/audio/createSpeech """ global proxy_logging_obj - data: dict = {} + litellm_call_id: Final = resolve_litellm_call_id(request.headers.get("x-litellm-call-id")) + data: dict = {"litellm_call_id": litellm_call_id} try: # Use orjson to parse JSON data, orjson speeds up requests significantly body: Final = await request.body() - data = orjson.loads(body) + data = orjson.loads(body) | data # Include original request and headers in the data data = await add_litellm_data_to_request( @@ -11623,9 +11635,7 @@ async def audio_speech( response: Final = await llm_call ### ALERTING ### - asyncio.create_task( - proxy_logging_obj.update_request_status(litellm_call_id=data.get("litellm_call_id", ""), status="success") - ) + asyncio.create_task(proxy_logging_obj.update_request_status(litellm_call_id=litellm_call_id, status="success")) ### RESPONSE HEADERS ### hidden_params: Final = getattr(response, "_hidden_params", {}) or {} @@ -11633,7 +11643,7 @@ async def audio_speech( cache_key: Final = hidden_params.get("cache_key", None) or "" api_base: Final = hidden_params.get("api_base", None) or "" response_cost: Final = hidden_params.get("response_cost", None) or "" - litellm_call_id: Final = hidden_params.get("litellm_call_id", None) or "" + response_call_id: Final = hidden_params.get("litellm_call_id", None) or "" custom_headers: Final = ProxyBaseLLMRequestProcessing.get_custom_headers( user_api_key_dict=user_api_key_dict, @@ -11644,7 +11654,7 @@ async def audio_speech( response_cost=response_cost, model_region=getattr(user_api_key_dict, "allowed_model_region", ""), fastest_response_batch_completion=None, - call_id=litellm_call_id, + call_id=response_call_id, request_data=data, hidden_params=hidden_params, ) @@ -11680,14 +11690,20 @@ async def audio_speech( original_exception=e, request_data=data, ) - verbose_proxy_logger.error("litellm.proxy.proxy_server.audio_speech(): Exception occured - %s", e) - verbose_proxy_logger.debug(traceback.format_exc()) - if isinstance(e, (ProxyException, HTTPException)): - raise e + log_llm_api_exception(e, litellm_call_id) + if isinstance(e, ProxyException): + raise with_litellm_call_id(e, litellm_call_id) + if isinstance(e, HTTPException): + raise HTTPException( + status_code=e.status_code, + detail=e.detail, + headers=headers_with_litellm_call_id(e.headers, litellm_call_id), + ) raise ProxyException( message=getattr(e, "message", f"{e}"), type=getattr(e, "type", "None"), param=getattr(e, "param", "None"), + headers=litellm_call_id_headers(litellm_call_id), openai_code=getattr(e, "code", None), code=getattr(e, "status_code", 500), ) @@ -11715,11 +11731,12 @@ async def audio_transcriptions( https://platform.openai.com/docs/api-reference/audio/createTranscription?lang=curl """ global proxy_logging_obj - data: dict = {} + litellm_call_id: Final = resolve_litellm_call_id(request.headers.get("x-litellm-call-id")) + data: dict = {"litellm_call_id": litellm_call_id} try: # Use orjson to parse JSON data, orjson speeds up requests significantly form_data: Final = await get_form_data(request) - data = {key: value for key, value in form_data.items() if key != "file"} + data = {key: value for key, value in form_data.items() if key != "file"} | data # Include original request and headers in the data data = await add_litellm_data_to_request( @@ -11786,9 +11803,7 @@ async def audio_transcriptions( file_object.close() # close the file read in by io library ### ALERTING ### - asyncio.create_task( - proxy_logging_obj.update_request_status(litellm_call_id=data.get("litellm_call_id", ""), status="success") - ) + asyncio.create_task(proxy_logging_obj.update_request_status(litellm_call_id=litellm_call_id, status="success")) ### RESPONSE HEADERS ### hidden_params: Final = getattr(response, "_hidden_params", {}) or {} @@ -11796,7 +11811,7 @@ async def audio_transcriptions( cache_key: Final = hidden_params.get("cache_key", None) or "" api_base: Final = hidden_params.get("api_base", None) or "" response_cost: Final = hidden_params.get("response_cost", None) or "" - litellm_call_id: Final = hidden_params.get("litellm_call_id", None) or "" + response_call_id: Final = hidden_params.get("litellm_call_id", None) or "" additional_headers: Final[dict] = hidden_params.get("additional_headers", {}) or {} fastapi_response.headers.update( @@ -11808,7 +11823,7 @@ async def audio_transcriptions( version=version, response_cost=response_cost, model_region=getattr(user_api_key_dict, "allowed_model_region", ""), - call_id=litellm_call_id, + call_id=response_call_id, request_data=data, hidden_params=hidden_params, **additional_headers, @@ -11830,12 +11845,13 @@ 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 - %s", e) + log_llm_api_exception(e, litellm_call_id) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "message", str(e.detail)), type=getattr(e, "type", "None"), param=getattr(e, "param", "None"), + headers=litellm_call_id_headers(litellm_call_id), code=getattr(e, "status_code", status.HTTP_400_BAD_REQUEST), ) else: @@ -11844,6 +11860,7 @@ async def audio_transcriptions( message=getattr(e, "message", error_msg), type=getattr(e, "type", "None"), param=getattr(e, "param", "None"), + headers=litellm_call_id_headers(litellm_call_id), openai_code=getattr(e, "code", None), code=getattr(e, "status_code", 500), ) diff --git a/litellm/proxy/rerank_endpoints/endpoints.py b/litellm/proxy/rerank_endpoints/endpoints.py index 16cd7368e4a..4f2daed15ed 100644 --- a/litellm/proxy/rerank_endpoints/endpoints.py +++ b/litellm/proxy/rerank_endpoints/endpoints.py @@ -7,12 +7,16 @@ import orjson from fastapi import APIRouter, Depends, HTTPException, Request, Response, status from fastapi.responses import ORJSONResponse -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_request_processing import ProxyBaseLLMRequestProcessing +from litellm.proxy.common_request_processing import ( + ProxyBaseLLMRequestProcessing, + log_llm_api_exception, + resolve_litellm_call_id, +) from litellm.proxy.common_utils.openai_error_payload import ( error_status_code, + litellm_call_id_headers, openai_error_param, openai_error_type, ) @@ -54,10 +58,11 @@ async def rerank( version, ) - data = {} + litellm_call_id: Final = resolve_litellm_call_id(request.headers.get("x-litellm-call-id")) + data = {"litellm_call_id": litellm_call_id} try: body: Final = await request.body() - data = orjson.loads(body) + data = orjson.loads(body) | data # Include original request and headers in the data data = await add_litellm_data_to_request( @@ -82,9 +87,7 @@ async def rerank( response: Final = await llm_call ### ALERTING ### - asyncio.create_task( - proxy_logging_obj.update_request_status(litellm_call_id=data.get("litellm_call_id", ""), status="success") - ) + asyncio.create_task(proxy_logging_obj.update_request_status(litellm_call_id=litellm_call_id, status="success")) ### RESPONSE HEADERS ### hidden_params: Final = getattr(response, "_hidden_params", {}) or {} @@ -95,7 +98,7 @@ async def rerank( fastapi_response.headers.update( ProxyBaseLLMRequestProcessing.get_custom_headers( user_api_key_dict=user_api_key_dict, - call_id=hidden_params.get("litellm_call_id", None) or data.get("litellm_call_id", None), + call_id=hidden_params.get("litellm_call_id", None) or litellm_call_id, model_id=model_id, cache_key=cache_key, api_base=api_base, @@ -113,12 +116,13 @@ async def rerank( 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.error("litellm.proxy.proxy_server.rerank(): Exception occured - %s", e) + log_llm_api_exception(e, litellm_call_id) if isinstance(e, HTTPException): raise ProxyException( message=getattr(e, "message", str(e)), type=openai_error_type(e, error_status_code(e, status.HTTP_400_BAD_REQUEST)), param=openai_error_param(e), + headers=litellm_call_id_headers(litellm_call_id), code=error_status_code(e, status.HTTP_400_BAD_REQUEST), ) else: @@ -127,5 +131,6 @@ async def rerank( message=getattr(e, "message", error_msg), type=openai_error_type(e, error_status_code(e, 500)), param=openai_error_param(e), + headers=litellm_call_id_headers(litellm_call_id), code=error_status_code(e, 500), ) diff --git a/litellm/proxy/utils.py b/litellm/proxy/utils.py index 18e58861266..8225fef3492 100644 --- a/litellm/proxy/utils.py +++ b/litellm/proxy/utils.py @@ -38,7 +38,11 @@ from litellm.proxy._types import ( SpendLogsMetadata, SpendLogsPayload, ) -from litellm.proxy.common_utils.openai_error_payload import openai_error_param +from litellm.proxy.common_utils.openai_error_payload import ( + litellm_call_id_headers, + openai_error_param, + with_litellm_call_id, +) from litellm.proxy.spend_tracking.spend_log_error_logger import spend_log_error from litellm.types.guardrails import GuardrailEventHooks from litellm.types.proxy.model_listing import ModelInfoResponse @@ -3050,7 +3054,7 @@ class ProxyLogging: if litellm_logging_obj is None: from litellm._uuid import uuid - request_data["litellm_call_id"] = str(uuid.uuid4()) + request_data.setdefault("litellm_call_id", str(uuid.uuid4())) user_api_key_logged_metadata: Final = LiteLLMProxyRequestSetup.get_sanitized_user_information_from_key( user_api_key_dict=user_api_key_dict ) @@ -7659,7 +7663,7 @@ def _recreate_writer_on_read_only_transaction(prisma_client: "PrismaClient | Non asyncio.create_task(prisma_client.recreate_read_only_writer(reason="postgres_read_only_transaction")) -def handle_exception_on_proxy(e: Exception) -> ProxyException: +def handle_exception_on_proxy(e: Exception, litellm_call_id: str | None = None) -> ProxyException: """ Returns an Exception as ProxyException, this ensures all exceptions are OpenAI API compatible """ @@ -7671,20 +7675,23 @@ def handle_exception_on_proxy(e: Exception) -> ProxyException: _recreate_writer_on_read_only_transaction(prisma_client) + headers: Final = litellm_call_id_headers(litellm_call_id) if isinstance(e, HTTPException): return ProxyException( message=getattr(e, "detail", f"error({e})"), type=ProxyErrorTypes.internal_server_error, param=openai_error_param(e), + headers=headers, code=getattr(e, "status_code", status.HTTP_500_INTERNAL_SERVER_ERROR), ) elif isinstance(e, ProxyException): - return e + return with_litellm_call_id(e, litellm_call_id) _status_code: Final = getattr(e, "status_code", status.HTTP_500_INTERNAL_SERVER_ERROR) return ProxyException( message=str(e), type=ProxyErrorTypes.internal_server_error, param=openai_error_param(e), + headers=headers, code=_status_code, ) diff --git a/tests/proxy_unit_tests/test_proxy_server.py b/tests/proxy_unit_tests/test_proxy_server.py index 9c8dd90dd2b..1fcdaa67143 100644 --- a/tests/proxy_unit_tests/test_proxy_server.py +++ b/tests/proxy_unit_tests/test_proxy_server.py @@ -809,6 +809,7 @@ def test_img_gen(mock_aimage_generation, client_no_auth): n=1, size="1024x1024", imageConfig={"aspectRatio": "9:16", "imageSize": "1K"}, + litellm_call_id=mock.ANY, metadata=mock.ANY, proxy_server_request=mock.ANY, secret_fields=mock.ANY, diff --git a/tests/test_litellm/proxy/anthropic_endpoints/test_endpoints.py b/tests/test_litellm/proxy/anthropic_endpoints/test_endpoints.py index f809fadc879..9a9ccd9a213 100644 --- a/tests/test_litellm/proxy/anthropic_endpoints/test_endpoints.py +++ b/tests/test_litellm/proxy/anthropic_endpoints/test_endpoints.py @@ -3,12 +3,14 @@ Test for anthropic_endpoints/endpoints.py, focusing on handling dictionary objec """ import json +import logging import unittest from unittest.mock import AsyncMock, MagicMock, patch import pytest from fastapi.testclient import TestClient +from litellm._logging import verbose_proxy_logger from litellm.proxy.common_request_processing import ProxyBaseLLMRequestProcessing @@ -285,6 +287,115 @@ class TestFailureHookRequestData: assert hook_request_data["litellm_logging_obj"] == "logging-obj-sentinel" +class TestErrorLogCarriesCallId: + """LIT-7836: the /v1/messages and /v1/messages/count_tokens error lines must carry + the request's litellm_call_id, rendered in the message and as a structured field.""" + + @pytest.fixture(autouse=True) + def propagating_proxy_logger(self): + verbose_proxy_logger.propagate = True + try: + yield + finally: + verbose_proxy_logger.propagate = False + + @staticmethod + def _error_record(caplog: pytest.LogCaptureFixture) -> logging.LogRecord: + return next(r for r in caplog.records if "Exception occured" in r.getMessage()) + + @pytest.mark.asyncio + async def test_messages_failure_log_carries_call_id(self, caplog: pytest.LogCaptureFixture): + import litellm.proxy.anthropic_endpoints.endpoints as ep + import litellm.proxy.proxy_server as proxy_server + from litellm.proxy._types import UserAPIKeyAuth + + call_id = "messages-call-7836" + + async def fake_process(self, **kwargs): + self.data = {**self.data, "litellm_call_id": call_id} + raise RuntimeError("provider timeout") + + request = MagicMock() + request.headers = {} + + with ( + patch.object(ep, "_read_request_body", new=AsyncMock(return_value={"model": "claude-sonnet"})), # test-quality-ok: endpoint reads the body via a module function; no injection seam + patch.object(ep.ProxyBaseLLMRequestProcessing, "base_process_llm_request", new=fake_process), # test-quality-ok: the provider failure happens inside this call; the test targets the endpoint's except block + patch.object(proxy_server, "proxy_logging_obj") as mock_logging, # test-quality-ok: module global imported at call time; no injection seam + caplog.at_level(logging.ERROR, logger="LiteLLM Proxy"), + ): + mock_logging.post_call_failure_hook = AsyncMock() + response = await ep.anthropic_response( + fastapi_response=MagicMock(), + request=request, + user_api_key_dict=UserAPIKeyAuth(), + ) + + assert response.status_code == 500 + record = self._error_record(caplog) + assert record.litellm_call_id == call_id + assert call_id in record.getMessage() + + @pytest.mark.asyncio + async def test_messages_already_shaped_failure_answers_with_the_call_id(self): + import litellm.proxy.anthropic_endpoints.endpoints as ep + import litellm.proxy.proxy_server as proxy_server + from litellm.proxy._types import ProxyErrorTypes, ProxyException, UserAPIKeyAuth + + call_id = "messages-call-7836-shaped" + + async def fake_process(self, **kwargs): + self.data = {**self.data, "litellm_call_id": call_id} + raise ProxyException(message="budget exceeded", type=ProxyErrorTypes.budget_exceeded, param="key", code=402) + + request = MagicMock() + request.headers = {} + + with ( + patch.object(ep, "_read_request_body", new=AsyncMock(return_value={"model": "claude-sonnet"})), # test-quality-ok: endpoint reads the body via a module function; no injection seam + patch.object(ep.ProxyBaseLLMRequestProcessing, "base_process_llm_request", new=fake_process), # test-quality-ok: the proxy shaped failure happens inside this call; the test targets the endpoint's except block + patch.object(proxy_server, "proxy_logging_obj") as mock_logging, # test-quality-ok: module global imported at call time; no injection seam + ): + mock_logging.post_call_failure_hook = AsyncMock() + response = await ep.anthropic_response( + fastapi_response=MagicMock(), + request=request, + user_api_key_dict=UserAPIKeyAuth(), + ) + + assert response.status_code == 402 + assert response.headers["x-litellm-call-id"] == call_id + + @pytest.mark.asyncio + async def test_count_tokens_failure_log_carries_callers_call_id(self, caplog: pytest.LogCaptureFixture): + from fastapi import HTTPException + + import litellm.proxy.anthropic_endpoints.endpoints as ep + import litellm.proxy.proxy_server as proxy_server + from litellm.proxy._types import UserAPIKeyAuth + + call_id = "count-tokens-call-7836" + request = MagicMock() + request.headers = {"x-litellm-call-id": call_id} + + with ( + patch.object( # test-quality-ok: endpoint reads the body via a module function; no injection seam + ep, + "_read_request_body", + new=AsyncMock(return_value={"model": "claude-sonnet", "messages": [{"role": "user", "content": "hi"}]}), + ), + patch.object(proxy_server, "token_counter", new=AsyncMock(side_effect=RuntimeError("tokenizer down"))), # test-quality-ok: module global imported at call time; the test targets the endpoint's except block + caplog.at_level(logging.ERROR, logger="LiteLLM Proxy"), + pytest.raises(HTTPException) as raised, + ): + await ep.count_tokens(request=request, user_api_key_dict=UserAPIKeyAuth()) + + assert raised.value.status_code == 500 + record = self._error_record(caplog) + assert record.litellm_call_id == call_id + assert call_id in record.getMessage() + + class TestEventLoggingBatchEndpoint: """Test the stubbed event logging batch endpoint""" diff --git a/tests/test_litellm/proxy/batches_endpoints/test_endpoints.py b/tests/test_litellm/proxy/batches_endpoints/test_endpoints.py index a37c8ff2bb4..d9bfb3fe3da 100644 --- a/tests/test_litellm/proxy/batches_endpoints/test_endpoints.py +++ b/tests/test_litellm/proxy/batches_endpoints/test_endpoints.py @@ -31,6 +31,7 @@ cannot drift without a test failure. import base64 import json +import logging from contextlib import ExitStack from dataclasses import dataclass from typing import Any, Dict, Optional @@ -1088,6 +1089,28 @@ async def test_create__exception_calls_failure_hook(harness, openai_env_creds): assert harness.logging.post_call_failure_hook.call_args.kwargs["original_exception"].args[0] == "provider boom" +async def test_create__exception_carries_the_litellm_call_id(harness, openai_env_creds, caplog): + call_id = "lit7836-batch-call-id" + set_body( + harness, + { + "input_file_id": "file-plain", + "endpoint": "/v1/chat/completions", + "completion_window": "24h", + "litellm_call_id": call_id, + }, + ) + harness.litellm_acreate.side_effect = ValueError("provider boom") + + with caplog.at_level(logging.ERROR, logger="LiteLLM Proxy"), pytest.raises(ProxyException) as raised: + await call_create(harness) + + assert raised.value.headers["x-litellm-call-id"] == call_id + record = next(r for r in caplog.records if "Exception occured" in r.getMessage()) + assert record.litellm_call_id == call_id + assert call_id in record.getMessage() + + # =========================================================================== # # # # GET /v1/batches/{batch_id} - retrieve_batch routing-contract tests # @@ -1953,6 +1976,24 @@ async def test_list__exception_calls_failure_hook(list_harness): assert list_harness.logging.post_call_failure_hook.call_args.kwargs["original_exception"].args[0] == "provider boom" +@pytest.mark.asyncio +async def test_list__failure_hook_and_response_share_the_request_litellm_call_id(list_harness): + call_id = "lit7836-list-batches-call-id" + list_harness.pre_call.side_effect = lambda **kw: ( + {**list_harness.body["body"], "litellm_call_id": call_id}, + MagicMock(), + ) + list_harness.litellm_alist.side_effect = ValueError("provider boom") + + with pytest.raises(ProxyException) as raised: + await call_list(list_harness, after="batch-0", limit=5) + + failure_request_data = list_harness.logging.post_call_failure_hook.call_args.kwargs["request_data"] + assert failure_request_data["litellm_call_id"] == call_id + assert (failure_request_data["after"], failure_request_data["limit"]) == ("batch-0", 5) + assert raised.value.headers["x-litellm-call-id"] == call_id + + # =========================================================================== # # # # POST /v1/batches/{batch_id}/cancel - cancel_batch routing-contract tests # diff --git a/tests/test_litellm/proxy/common_utils/test_openai_error_payload.py b/tests/test_litellm/proxy/common_utils/test_openai_error_payload.py index 90850840ab4..c09b8742b50 100644 --- a/tests/test_litellm/proxy/common_utils/test_openai_error_payload.py +++ b/tests/test_litellm/proxy/common_utils/test_openai_error_payload.py @@ -6,8 +6,10 @@ from fastapi import HTTPException from litellm.proxy._types import ProxyErrorTypes, ProxyException from litellm.proxy.common_utils.openai_error_payload import ( error_status_code, + litellm_call_id_headers, openai_error_param, openai_error_type, + with_litellm_call_id, ) @@ -158,3 +160,32 @@ def test_a_stringified_none_type_or_param_is_treated_as_absent(): assert carried.type == "None" assert openai_error_type(carried, 400) == "invalid_request_error" assert openai_error_param(carried) is None + + +def test_a_failed_request_answers_with_the_call_id_it_was_logged_under(): + assert litellm_call_id_headers("call-7836") == {"x-litellm-call-id": "call-7836"} + assert litellm_call_id_headers(None) is None + + +def test_an_already_shaped_proxy_error_answers_with_the_call_id_it_was_logged_under(): + raised_without_id = ProxyException(message="budget exceeded", type="budget_exceeded", param="key", code=402) + + carried = with_litellm_call_id(raised_without_id, "call-7836") + + assert carried is raised_without_id + assert carried.headers == {"x-litellm-call-id": "call-7836"} + assert (carried.message, carried.type, carried.param, carried.code) == ( + "budget exceeded", + "budget_exceeded", + "key", + "402", + ) + + +def test_a_proxy_error_keeps_the_call_id_it_was_raised_with(): + raised_with_id = ProxyException( + message="nope", type="None", param=None, code=400, headers={"x-litellm-call-id": "first"} + ) + + assert with_litellm_call_id(raised_with_id, "second").headers == {"x-litellm-call-id": "first"} + assert with_litellm_call_id(ProxyException(message="nope", type="None", param=None, code=400), None).headers == {} diff --git a/tests/test_litellm/proxy/image_endpoints/test_endpoints.py b/tests/test_litellm/proxy/image_endpoints/test_endpoints.py index d8b3eef98bd..31b87530c94 100644 --- a/tests/test_litellm/proxy/image_endpoints/test_endpoints.py +++ b/tests/test_litellm/proxy/image_endpoints/test_endpoints.py @@ -1,5 +1,7 @@ import asyncio import copy +import logging +from collections.abc import Iterator, Mapping from types import SimpleNamespace from typing import Any, Dict @@ -10,6 +12,7 @@ from fastapi.testclient import TestClient from starlette.requests import Request from starlette.responses import Response +from litellm._logging import verbose_proxy_logger from litellm.proxy._types import ProxyException, UserAPIKeyAuth from litellm.proxy.auth.user_api_key_auth import user_api_key_auth from litellm.proxy.image_endpoints import endpoints @@ -211,3 +214,117 @@ async def test_a_model_the_router_cannot_serve_answers_an_openai_typed_error(mon await endpoints.image_generation(request=request, fastapi_response=Response(), user_api_key_dict=UserAPIKeyAuth()) assert (raised.value.type, raised.value.param, raised.value.code) == ("invalid_request_error", None, "404") + + +@pytest.fixture +def propagating_proxy_logger() -> Iterator[None]: + verbose_proxy_logger.propagate = True + try: + yield + finally: + verbose_proxy_logger.propagate = False + + +@pytest.mark.asyncio +async def test_failure_log_carries_the_callers_litellm_call_id( + monkeypatch: pytest.MonkeyPatch, caplog: pytest.LogCaptureFixture, propagating_proxy_logger: None +) -> None: + """LIT-7836: the /v1/images/generations error line must carry the litellm_call_id + the client sent, both rendered in the message and as a structured record field.""" + call_id = "images-call-7836" + + async def fake_add_litellm_data_to_request(**kwargs: object) -> object: + return kwargs["data"] + + async def fake_pre_call_hook(*, user_api_key_dict: UserAPIKeyAuth, data: dict[str, object], call_type: str) -> dict[str, object]: + return data + + async def fake_post_call_failure_hook(**_: object) -> None: + return None + + async def failing_route_request(**_: object) -> None: + raise HTTPException(status_code=401, detail={"error": "invalid api key"}) + + monkeypatch.setattr("litellm.proxy.proxy_server.add_litellm_data_to_request", fake_add_litellm_data_to_request) + monkeypatch.setattr("litellm.proxy.proxy_server.general_settings", {}) + monkeypatch.setattr("litellm.proxy.proxy_server.llm_router", None) + monkeypatch.setattr("litellm.proxy.proxy_server.proxy_config", {}) + monkeypatch.setattr( + "litellm.proxy.proxy_server.proxy_logging_obj", + SimpleNamespace(pre_call_hook=fake_pre_call_hook, post_call_failure_hook=fake_post_call_failure_hook), + ) + monkeypatch.setattr("litellm.proxy.proxy_server.user_model", None) + monkeypatch.setattr("litellm.proxy.proxy_server.version", "test-version") + monkeypatch.setattr("litellm.proxy.image_endpoints.endpoints.route_request", failing_route_request) + + body = orjson.dumps({"model": "dall-e-3", "prompt": "a lighthouse at dusk"}) + + async def receive() -> dict[str, object]: + return {"type": "http.request", "body": body, "more_body": False} + + request = Request( + { + "type": "http", + "method": "POST", + "path": "/v1/images/generations", + "headers": [(b"x-litellm-call-id", call_id.encode())], + }, + receive, + ) + + with caplog.at_level(logging.ERROR, logger="LiteLLM Proxy"), pytest.raises(ProxyException) as raised: + await endpoints.image_generation(request=request, fastapi_response=Response(), user_api_key_dict=UserAPIKeyAuth()) + + assert raised.value.headers["x-litellm-call-id"] == call_id + record = next(r for r in caplog.records if "Exception occured" in r.getMessage()) + assert record.litellm_call_id == call_id + assert call_id in record.getMessage() + + +@pytest.mark.asyncio +async def test_failure_before_the_provider_call_bills_the_callers_litellm_call_id( + monkeypatch: pytest.MonkeyPatch, +) -> None: + """LIT-7836: when the request is rejected while it is still being prepared, the + failure hook must see the same litellm_call_id the response header answers with, + otherwise the spend row is stored under a freshly minted id nobody can look up.""" + call_id = "images-early-7836" + hook_request_data: list[Mapping[str, object]] = [] + + async def rejecting_add_litellm_data_to_request(**_: object) -> object: + raise HTTPException(status_code=400, detail={"error": "tag not allowed"}) + + async def fake_post_call_failure_hook(*, request_data: Mapping[str, object], **_: object) -> None: + hook_request_data.append(request_data) + + monkeypatch.setattr("litellm.proxy.proxy_server.add_litellm_data_to_request", rejecting_add_litellm_data_to_request) + monkeypatch.setattr("litellm.proxy.proxy_server.general_settings", {}) + monkeypatch.setattr("litellm.proxy.proxy_server.llm_router", None) + monkeypatch.setattr("litellm.proxy.proxy_server.proxy_config", {}) + monkeypatch.setattr( + "litellm.proxy.proxy_server.proxy_logging_obj", + SimpleNamespace(post_call_failure_hook=fake_post_call_failure_hook), + ) + monkeypatch.setattr("litellm.proxy.proxy_server.user_model", None) + monkeypatch.setattr("litellm.proxy.proxy_server.version", "test-version") + + body = orjson.dumps({"model": "dall-e-3", "prompt": "a lighthouse at dusk", "litellm_call_id": "from-the-body"}) + + async def receive() -> dict[str, object]: + return {"type": "http.request", "body": body, "more_body": False} + + request = Request( + { + "type": "http", + "method": "POST", + "path": "/v1/images/generations", + "headers": [(b"x-litellm-call-id", call_id.encode())], + }, + receive, + ) + + with pytest.raises(ProxyException) as raised: + await endpoints.image_generation(request=request, fastapi_response=Response(), user_api_key_dict=UserAPIKeyAuth()) + + assert raised.value.headers["x-litellm-call-id"] == call_id + assert [data["litellm_call_id"] for data in hook_request_data] == [call_id] diff --git a/tests/test_litellm/proxy/pass_through_endpoints/test_pass_through_endpoints.py b/tests/test_litellm/proxy/pass_through_endpoints/test_pass_through_endpoints.py index d6b9a782f99..d854ee39ff4 100644 --- a/tests/test_litellm/proxy/pass_through_endpoints/test_pass_through_endpoints.py +++ b/tests/test_litellm/proxy/pass_through_endpoints/test_pass_through_endpoints.py @@ -6143,3 +6143,42 @@ async def test_chat_completion_pass_through_endpoint_answers_an_openai_typed_err ) assert (raised.value.type, raised.value.param, raised.value.code) == ("invalid_request_error", None, "400") + + +@pytest.mark.asyncio +async def test_chat_completion_pass_through_endpoint_failure_carries_the_callers_litellm_call_id( + monkeypatch: pytest.MonkeyPatch, + caplog: pytest.LogCaptureFixture, +): + call_id = "lit7836-pass-through-call-id" + proxy_logging = MagicMock() + proxy_logging.pre_call_hook = AsyncMock(side_effect=lambda **kwargs: kwargs["data"]) + proxy_logging.post_call_failure_hook = AsyncMock() + + async def fake_add_litellm_data_to_request(**kwargs: object) -> object: + return kwargs["data"] + + monkeypatch.setattr("litellm.proxy.proxy_server.proxy_logging_obj", proxy_logging) + monkeypatch.setattr("litellm.proxy.proxy_server.add_litellm_data_to_request", fake_add_litellm_data_to_request) + monkeypatch.setattr("litellm.proxy.proxy_server.llm_router", None) + monkeypatch.setattr("litellm.proxy.proxy_server.user_model", None) + monkeypatch.setattr("litellm.proxy.proxy_server.general_settings", {}) + + request = MagicMock(spec=Request) + request.headers = Headers({"x-litellm-call-id": call_id}) + request.body = AsyncMock( + return_value=json.dumps({"model": "unknown-model", "messages": [{"role": "user", "content": "hi"}]}).encode() + ) + + with caplog.at_level(logging.ERROR, logger="LiteLLM Proxy"), pytest.raises(ProxyException) as raised: + await chat_completion_pass_through_endpoint( + fastapi_response=Response(), + request=request, + adapter_id="anthropic", + user_api_key_dict=UserAPIKeyAuth(api_key="sk-test"), + ) + + assert raised.value.headers["x-litellm-call-id"] == call_id + record = next(r for r in caplog.records if "Exception occured" in r.getMessage()) + assert record.litellm_call_id == call_id + assert call_id in record.getMessage() diff --git a/tests/test_litellm/proxy/rerank_endpoints/test_endpoints.py b/tests/test_litellm/proxy/rerank_endpoints/test_endpoints.py index ea858e04e0f..52d12dd1813 100644 --- a/tests/test_litellm/proxy/rerank_endpoints/test_endpoints.py +++ b/tests/test_litellm/proxy/rerank_endpoints/test_endpoints.py @@ -3,6 +3,8 @@ Tests for rerank_endpoints/endpoints.py response headers. """ import json +import logging +from collections.abc import Iterator from unittest.mock import AsyncMock, MagicMock, patch import pytest @@ -10,6 +12,7 @@ from fastapi import HTTPException, Request, Response import litellm.proxy.common_request_processing as common_request_processing_mod import litellm.proxy.proxy_server as proxy_server_mod +from litellm._logging import verbose_proxy_logger from litellm.proxy._types import ProxyException, UserAPIKeyAuth from litellm.proxy.rerank_endpoints.endpoints import rerank from litellm.types.utils import RerankResponse @@ -28,7 +31,7 @@ HIDDEN_PARAMS = { } -def _build_request() -> Request: +def _build_request(headers: tuple[tuple[bytes, bytes], ...] = ()) -> Request: body = json.dumps({"model": "rerank-model", "query": "q", "documents": ["a", "b"]}).encode() async def receive(): @@ -39,7 +42,7 @@ def _build_request() -> Request: "type": "http", "method": "POST", "path": "/rerank", - "headers": [(b"content-type", b"application/json")], + "headers": [(b"content-type", b"application/json"), *headers], "query_string": b"", }, receive=receive, @@ -56,7 +59,7 @@ async def _call_rerank(hidden_params: dict = HIDDEN_PARAMS) -> Response: proxy_logging_obj.update_request_status = AsyncMock() async def fake_add_litellm_data_to_request(**kwargs): - return {**kwargs["data"], "litellm_call_id": "call-123"} + return dict(kwargs["data"]) async def fake_route_request(**kwargs): async def _call(): @@ -72,7 +75,7 @@ async def _call_rerank(hidden_params: dict = HIDDEN_PARAMS) -> Response: patch.object(proxy_server_mod, "version", "1.2.3"), # test-quality-ok: the rerank route reads these proxy_server module globals; no injection seam on the FastAPI handler ): await rerank( - request=_build_request(), + request=_build_request(headers=((b"x-litellm-call-id", b"call-123"),)), fastapi_response=fastapi_response, user_api_key_dict=UserAPIKeyAuth(api_key="sk-test"), ) @@ -121,7 +124,11 @@ async def test_rerank_omits_detailed_timing_headers_when_disabled(): async def _rerank_failure( - failure: Exception, *, raised_before_routing: bool, monkeypatch: pytest.MonkeyPatch + failure: Exception, + *, + raised_before_routing: bool, + monkeypatch: pytest.MonkeyPatch, + headers: tuple[tuple[bytes, bytes], ...] = (), ) -> ProxyException: proxy_logging_obj = MagicMock() proxy_logging_obj.pre_call_hook = AsyncMock( @@ -143,13 +150,45 @@ async def _rerank_failure( with pytest.raises(ProxyException) as raised: await rerank( - request=_build_request(), + request=_build_request(headers), fastapi_response=Response(), user_api_key_dict=UserAPIKeyAuth(api_key="sk-test"), ) return raised.value +@pytest.fixture +def propagating_proxy_logger() -> Iterator[None]: + verbose_proxy_logger.propagate = True + try: + yield + finally: + verbose_proxy_logger.propagate = False + + +@pytest.mark.asyncio +async def test_failure_log_carries_the_callers_litellm_call_id( + monkeypatch: pytest.MonkeyPatch, caplog: pytest.LogCaptureFixture, propagating_proxy_logger: None +) -> None: + """LIT-7836: the /rerank error line must carry the same litellm_call_id the client + sent, both in the rendered message and as a structured log record field.""" + call_id = "rerank-call-7836" + failure = HTTPException(status_code=401, detail={"error": "invalid api key"}) + + with caplog.at_level(logging.ERROR, logger="LiteLLM Proxy"): + raised = await _rerank_failure( + failure, + raised_before_routing=False, + monkeypatch=monkeypatch, + headers=((b"x-litellm-call-id", call_id.encode()),), + ) + + assert raised.headers["x-litellm-call-id"] == call_id + record = next(r for r in caplog.records if "Exception occured" in r.getMessage()) + assert record.litellm_call_id == call_id + assert call_id in record.getMessage() + + @pytest.mark.asyncio async def test_a_model_the_router_cannot_serve_answers_an_openai_typed_error(monkeypatch: pytest.MonkeyPatch): """A bare HTTPException carries no type or param, so the tail used to ship the diff --git a/tests/test_litellm/proxy/test_common_request_processing.py b/tests/test_litellm/proxy/test_common_request_processing.py index 099204cd6c6..a621a97d448 100644 --- a/tests/test_litellm/proxy/test_common_request_processing.py +++ b/tests/test_litellm/proxy/test_common_request_processing.py @@ -8212,7 +8212,7 @@ def test_log_llm_api_exception_traceback_only_for_unexpected_errors(exc, expect_ """Regression for LIT-6043: expected 4xx errors log without formatting a traceback; unexpected errors keep logger.exception behavior.""" from litellm._logging import verbose_proxy_logger - from litellm.proxy.common_request_processing import _log_llm_api_exception + from litellm.proxy.common_request_processing import log_llm_api_exception verbose_proxy_logger.propagate = True try: @@ -8220,7 +8220,7 @@ def test_log_llm_api_exception_traceback_only_for_unexpected_errors(exc, expect_ try: raise exc except Exception as raised: - _log_llm_api_exception(raised, "call-id-for-traceback-test") + log_llm_api_exception(raised, "call-id-for-traceback-test") finally: verbose_proxy_logger.propagate = False @@ -8778,14 +8778,14 @@ class TestErrorLogCarriesCallId: from litellm._logging import verbose_proxy_logger from litellm.proxy.common_request_processing import ( _CLIENT_DISCONNECT_DETAIL, - _log_llm_api_exception, + log_llm_api_exception, ) call_id: Final = str(uuid.uuid4()) verbose_proxy_logger.propagate = True try: with caplog.at_level("INFO", logger="LiteLLM Proxy"): - _log_llm_api_exception( + log_llm_api_exception( HTTPException(status_code=499, detail=_CLIENT_DISCONNECT_DETAIL), call_id, ) diff --git a/tests/test_litellm/proxy/test_proxy_server.py b/tests/test_litellm/proxy/test_proxy_server.py index 19b0e88bea7..41c4956dba6 100644 --- a/tests/test_litellm/proxy/test_proxy_server.py +++ b/tests/test_litellm/proxy/test_proxy_server.py @@ -2,6 +2,7 @@ import asyncio import contextlib import importlib import json +import logging import os import re import socket @@ -19,7 +20,7 @@ import fastapi.routing import httpx import pytest import yaml -from fastapi import FastAPI, Request +from fastapi import FastAPI, HTTPException, Request from fastapi.encoders import jsonable_encoder from fastapi.staticfiles import StaticFiles from fastapi.testclient import TestClient @@ -13003,6 +13004,144 @@ async def test_moderations_response_carries_litellm_call_id_header(): assert fastapi_response.headers["x-litellm-model-id"] == "mod-deployment-1" +@pytest.mark.asyncio +async def test_moderations_failure_log_carries_the_callers_litellm_call_id(caplog): + """LIT-7836: the /v1/moderations error line must carry the litellm_call_id the + client sent, rendered in the message and as a structured log record field.""" + from litellm._logging import verbose_proxy_logger + from litellm.proxy._types import ProxyException + + call_id = "moderations-call-7836" + + async def passthrough_add_litellm_data(data, **kwargs): + return data + + request = MagicMock() + request.headers = {"x-litellm-call-id": call_id} + request.body = AsyncMock(return_value=b'{"input": "hi"}') + fake_logging = MagicMock() + fake_logging.pre_call_hook = AsyncMock(side_effect=lambda user_api_key_dict, data, call_type: data) + fake_logging.post_call_failure_hook = AsyncMock() + + verbose_proxy_logger.propagate = True + try: + with ( + patch.object(proxy_server_module, "add_litellm_data_to_request", new=passthrough_add_litellm_data), # test-quality-ok: the route reads this module global, no injection point + patch.object(proxy_server_module, "route_request", new=AsyncMock(side_effect=Exception("bad key"))), # test-quality-ok: fakes the provider failure so the real route's error log is observable + patch.object(proxy_server_module, "proxy_logging_obj", new=fake_logging), # test-quality-ok: module global, no injection point + caplog.at_level(logging.ERROR, logger="LiteLLM Proxy"), + pytest.raises(ProxyException) as raised, + ): + await proxy_server_module.moderations( + request=request, + fastapi_response=MagicMock(), + user_api_key_dict=UserAPIKeyAuth(api_key="sk-test", spend=0.0), + ) + finally: + verbose_proxy_logger.propagate = False + + assert raised.value.headers["x-litellm-call-id"] == call_id + record = next(r for r in caplog.records if "Exception occured" in r.getMessage()) + assert record.litellm_call_id == call_id + assert call_id in record.getMessage() + + +@pytest.mark.asyncio +async def test_moderations_unparseable_body_bills_the_callers_litellm_call_id(): + """LIT-7836: a body that fails to parse must still hand the failure hook the + litellm_call_id the response header answers with, so the spend row is findable.""" + from litellm.proxy._types import ProxyException + + call_id = "moderations-early-7836" + + request = MagicMock() + request.headers = {"x-litellm-call-id": call_id} + request.body = AsyncMock(return_value=b'{"input": ') + fake_logging = MagicMock() + fake_logging.post_call_failure_hook = AsyncMock() + + with ( + patch.object(proxy_server_module, "proxy_logging_obj", new=fake_logging), # test-quality-ok: module global, no injection point + pytest.raises(ProxyException) as raised, + ): + await proxy_server_module.moderations( + request=request, + fastapi_response=MagicMock(), + user_api_key_dict=UserAPIKeyAuth(api_key="sk-test", spend=0.0), + ) + + assert raised.value.headers["x-litellm-call-id"] == call_id + hook_request_data = fake_logging.post_call_failure_hook.await_args.kwargs["request_data"] + assert hook_request_data["litellm_call_id"] == call_id + + +@pytest.mark.asyncio +async def test_moderations_already_shaped_failure_answers_with_the_callers_litellm_call_id(): + """LIT-7836: a ProxyException raised inside /v1/moderations is re-raised unwrapped but still + answers with the caller's x-litellm-call-id so the client can join it to the error log.""" + call_id = "moderations-call-7836-shaped" + exc = ProxyException(message="budget exceeded", type=ProxyErrorTypes.budget_exceeded, param="key", code=402) + + request = MagicMock() + request.headers = {"x-litellm-call-id": call_id} + request.body = AsyncMock(return_value=b'{"input": "hi"}') + fake_logging = MagicMock() + fake_logging.post_call_failure_hook = AsyncMock() + + with ( + patch.object(proxy_server_module, "add_litellm_data_to_request", new=AsyncMock(side_effect=exc)), # test-quality-ok: the route reads this module global, no injection point + patch.object(proxy_server_module, "proxy_logging_obj", new=fake_logging), # test-quality-ok: module global, no injection point + pytest.raises(ProxyException) as raised, + ): + await proxy_server_module.moderations( + request=request, + fastapi_response=MagicMock(), + user_api_key_dict=UserAPIKeyAuth(api_key="sk-test", spend=0.0), + ) + + assert raised.value is exc + assert raised.value.code == "402" + assert raised.value.headers["x-litellm-call-id"] == call_id + + +@pytest.mark.asyncio +@pytest.mark.parametrize( + "exc", + [ + HTTPException(status_code=401, detail="bad key"), + ProxyException(message="budget exceeded", type=ProxyErrorTypes.budget_exceeded, param="key", code=402), + ], + ids=["http_exception", "proxy_exception"], +) +async def test_audio_speech_already_shaped_failure_answers_with_the_callers_litellm_call_id(exc: Exception): + """LIT-7836: /v1/audio/speech re-raises HTTP and proxy shaped failures unchanged, and they must + still answer with the caller's x-litellm-call-id.""" + call_id = "speech-call-7836-shaped" + + request = MagicMock() + request.headers = {"x-litellm-call-id": call_id} + request.body = AsyncMock(return_value=b'{"model": "tts-1", "input": "hi", "voice": "alloy"}') + fake_logging = MagicMock() + fake_logging.post_call_failure_hook = AsyncMock() + + with ( + patch.object(proxy_server_module, "add_litellm_data_to_request", new=AsyncMock(side_effect=exc)), # test-quality-ok: the route reads this module global, no injection point + patch.object(proxy_server_module, "proxy_logging_obj", new=fake_logging), # test-quality-ok: module global, no injection point + pytest.raises(type(exc)) as raised, + ): + await proxy_server_module.audio_speech( + request=request, + fastapi_response=MagicMock(), + user_api_key_dict=UserAPIKeyAuth(api_key="sk-test", spend=0.0), + ) + + if isinstance(exc, HTTPException): + assert (raised.value.status_code, raised.value.detail) == (401, "bad key") + else: + assert raised.value is exc + assert raised.value.headers["x-litellm-call-id"] == call_id + + @pytest.mark.asyncio async def test_init_agents_in_db_rebuilds_registry_under_agent_reconcile_lock(monkeypatch): from litellm.proxy.agent_endpoints.agent_registry import ( diff --git a/tests/test_litellm/proxy/test_proxy_utils.py b/tests/test_litellm/proxy/test_proxy_utils.py index 94ccc2762c5..df18e5c6093 100644 --- a/tests/test_litellm/proxy/test_proxy_utils.py +++ b/tests/test_litellm/proxy/test_proxy_utils.py @@ -160,6 +160,37 @@ async def test_proxy_only_error_log_keeps_litellm_metadata_in_litellm_params(): assert "litellm_metadata" not in captured["optional_params"] +@pytest.mark.asyncio +async def test_proxy_only_error_log_keeps_the_request_litellm_call_id(monkeypatch: pytest.MonkeyPatch): + """LIT-7836: a route that already stamped the caller's litellm_call_id must + keep it when the failure is a proxy-only error, so the spend-log row and the + error line share one id instead of a fresh uuid minted here.""" + from litellm.litellm_core_utils.litellm_logging import Logging + + call_id: Final = "caller-supplied-7836" + captured: dict[str, object] = {} + + def fake_pre_call(self, *args, **kwargs): + captured["litellm_call_id"] = self.litellm_call_id + + async def _noop_async_failure(self, *args, **kwargs): + return None + + monkeypatch.setattr(Logging, "pre_call", fake_pre_call) + monkeypatch.setattr(Logging, "async_failure_handler", _noop_async_failure) + request_data: Final[dict[str, object]] = {"model": "gpt-4o", "input": "hi", "litellm_call_id": call_id} + + await ProxyLogging(user_api_key_cache=DualCache())._handle_logging_proxy_only_error( + request_data=request_data, + user_api_key_dict=UserAPIKeyAuth(api_key="sk-bad", request_route="/v1/moderations"), + route="/v1/moderations", + original_exception=Exception("bad key"), + ) + + assert request_data["litellm_call_id"] == call_id + assert captured["litellm_call_id"] == call_id + + def test_get_model_group_info_order(): from litellm import Router from litellm.proxy.proxy_server import _get_model_group_info diff --git a/tests/test_litellm/proxy/utils/helpers/test_error_helpers.py b/tests/test_litellm/proxy/utils/helpers/test_error_helpers.py index 117c5aa3081..df399c8b1d2 100644 --- a/tests/test_litellm/proxy/utils/helpers/test_error_helpers.py +++ b/tests/test_litellm/proxy/utils/helpers/test_error_helpers.py @@ -176,6 +176,25 @@ def test_handle_exception_on_proxy_error_path_none_input_wraps_as_500(): } +@pytest.mark.parametrize( + "exc", + [ + HTTPException(status_code=401, detail="bad key"), + ValueError("provider boom"), + ProxyException(message="already wrapped", type=ProxyErrorTypes.budget_exceeded.value, param="key", code=402), + ], + ids=["http_exception", "generic_exception", "already_proxy_exception"], +) +def test_handle_exception_on_proxy_returns_the_litellm_call_id_header(exc: Exception): + result = handle_exception_on_proxy(exc, "call-7836") + + assert result.headers == {"x-litellm-call-id": "call-7836"} + + +def test_handle_exception_on_proxy_sends_no_call_id_header_when_the_request_has_none(): + assert handle_exception_on_proxy(ValueError("provider boom")).headers == {} + + @pytest.mark.asyncio async def test_handle_exception_on_proxy_read_only_transaction_forces_writer_recreate( monkeypatch: pytest.MonkeyPatch,