diff --git a/litellm/proxy/hooks/proxy_track_cost_callback.py b/litellm/proxy/hooks/proxy_track_cost_callback.py index 6801c8521e5..c11b59a809a 100644 --- a/litellm/proxy/hooks/proxy_track_cost_callback.py +++ b/litellm/proxy/hooks/proxy_track_cost_callback.py @@ -38,6 +38,7 @@ from litellm.proxy.db.db_spend_update_writer import ( ) from litellm.proxy.hooks.search_free_tier import apply_search_free_tier from litellm.proxy.litellm_pre_call_utils import LiteLLMProxyRequestSetup, metadata_variable_name_for_route +from litellm.proxy.route_llm_request import ProxyModelNotFoundError from litellm.proxy.spend_tracking.spend_counter_batch import post_call_counter_keys, spend_counter_batch_scope from litellm.proxy.spend_tracking.spend_event import ( ObjectMapping, @@ -60,7 +61,12 @@ from litellm.proxy.spend_tracking.spend_tracking_utils import ( # noqa: F401 # sanitize_error_information_for_spend_logs, should_store_prompts_and_responses_in_spend_logs, ) -from litellm.proxy.utils import BilledFailedAttempt, ProxyUpdateSpend +from litellm.proxy.utils import ( + REJECTED_BEFORE_REQUEST_SETUP, + REJECTED_BEFORE_REQUEST_SETUP_KEY, + BilledFailedAttempt, + ProxyUpdateSpend, +) from litellm.types.router import Deployment from litellm.types.utils import ( CallTypes, @@ -396,6 +402,8 @@ class _ProxyDBLogger(CustomLogger): request_route: Final = user_api_key_dict.request_route if ( ProxyDBLogger._should_track_errors_in_db() is False + or ProxyDBLogger._skips_pre_routing_rejections() + and is_pre_routing_rejection(original_exception, _REQUEST_DATA.validate_python(request_data)) or request_route is not None and not ( RouteChecks.is_llm_api_route(route=request_route) or RouteChecks.is_info_route(route=request_route) @@ -862,16 +870,40 @@ class _ProxyDBLogger(CustomLogger): If users want to disable error tracking, they can set the disable_error_logs flag in the general_settings """ - from litellm.proxy.proxy_server import general_settings - - if general_settings.get("disable_error_logs") is True: + if _general_setting_enabled("disable_error_logs"): return False return + @staticmethod + def _skips_pre_routing_rejections() -> bool: + """``general_settings.disable_pre_routing_error_logs`` keeps requests the proxy rejected before + selecting a deployment out of the spend logs, so a client retrying a bad key or an exhausted + budget cannot flood ``LiteLLM_SpendLogs`` with zero-spend rows.""" + return _general_setting_enabled("disable_pre_routing_error_logs") + + +def _general_setting_enabled(name: str) -> bool: + from litellm.proxy.proxy_server import general_settings + + return name in general_settings and general_settings[name] is True + ProxyDBLogger: Final = _ProxyDBLogger +_REQUEST_DATA: Final = TypeAdapter(dict[str, object]) + + +def is_pre_routing_rejection(exception: Exception, request_data: Mapping[str, object]) -> bool: + """The pipeline sets up the logging object only after auth, body parsing and model resolution succeed, and + before guardrails or routing run. ``ProxyLogging._handle_logging_proxy_only_error`` marks a failure that + arrives without one with the ``REJECTED_BEFORE_REQUEST_SETUP`` sentinel, so that request never had a provider + considered. An unknown model is the one later rejection that still never reached a provider.""" + return request_data.get(REJECTED_BEFORE_REQUEST_SETUP_KEY) is REJECTED_BEFORE_REQUEST_SETUP or isinstance( + exception, ProxyModelNotFoundError + ) + + def _write_spend_metadata_to_kwargs(kwargs: dict, metadata: dict) -> None: patch = {k: v for k, v in metadata.items() if (k.startswith("user_api_key") or k == "tags") and v is not None} if not patch: diff --git a/litellm/proxy/utils.py b/litellm/proxy/utils.py index 8212e7cbe74..ce7e6afde24 100644 --- a/litellm/proxy/utils.py +++ b/litellm/proxy/utils.py @@ -1476,6 +1476,13 @@ def _call_type_for_route(route: str | None) -> str | None: return call_types[0].value if len(operations) == 1 else None +REJECTED_BEFORE_REQUEST_SETUP_KEY: Final = "litellm_rejected_before_request_setup" +REJECTED_BEFORE_REQUEST_SETUP: Final = object() +"""Stored under ``REJECTED_BEFORE_REQUEST_SETUP_KEY`` on ``request_data`` when the failure handler finds no logging +object, meaning the request died (auth, body parsing, model resolution) before the pipeline set one up. A sentinel +object rather than ``True`` because ``request_data`` is the client body: JSON cannot forge this identity, so a +client can neither hide a guardrail block nor force a row by sending the key or a ``litellm_call_id`` itself.""" + _PROXY_ONLY_LLM_API_ERRORS: Final = (HTTPException, ProxyException, GuardrailRaisedException) _LOG_DB_METRICS_CALL_TYPES: Final = frozenset(("get_data", "insert_data", "update_data", "delete_data")) @@ -3888,6 +3895,7 @@ class ProxyLogging: **request_data, ) request_data["litellm_logging_obj"] = litellm_logging_obj # rebind-ok: lifted then popped by the caller + request_data.update({REJECTED_BEFORE_REQUEST_SETUP_KEY: REJECTED_BEFORE_REQUEST_SETUP}) if "metadata" not in request_data: request_data["metadata"] = {} request_data["metadata"].update(user_api_key_logged_metadata) diff --git a/tests/unit/proxy/hooks/test_proxy_track_cost_callback.py b/tests/unit/proxy/hooks/test_proxy_track_cost_callback.py index 76ad1e08e28..79193d37b04 100644 --- a/tests/unit/proxy/hooks/test_proxy_track_cost_callback.py +++ b/tests/unit/proxy/hooks/test_proxy_track_cost_callback.py @@ -1,35 +1,42 @@ import asyncio import json import logging +from collections.abc import Mapping from datetime import datetime, timedelta, timezone from types import SimpleNamespace -from typing import Final +from typing import Final, cast from unittest.mock import AsyncMock, MagicMock, create_autospec, patch import httpx import pytest +from fastapi import HTTPException import litellm from litellm._logging import verbose_proxy_logger from litellm.litellm_core_utils.internal_call_metadata import MODEL_ACCESS_GROUP_METADATA_KEY -from litellm.proxy._types import SpendLogsPayload, UserAPIKeyAuth +from litellm.proxy._types import ProxyException, SpendLogsPayload, UserAPIKeyAuth from litellm.proxy.collector import SpendEventConsumer from litellm.proxy.db.db_lookup_gate import DBLookupDeadlineExceeded from litellm.proxy.db.db_spend_update_writer import DBSpendUpdateWriter from litellm.proxy.db.model_usage_rollup import build_model_usage_transaction from litellm.proxy.db.spend_log_tool_index import response_tool_call_names from litellm.proxy.hooks.proxy_track_cost_callback import ( - _get_budget_reservation_from_metadata, ProxyDBLogger, + _get_budget_reservation_from_metadata, _should_track_cost_callback, _update_database_and_spend_counters, + is_pre_routing_rejection, run_spend_event, ) from litellm.proxy.route_llm_request import ProxyModelNotFoundError -from litellm.proxy.utils import ProxyUpdateSpend from litellm.proxy.spend_tracking.spend_event import SpendEventDecodeError, build_spend_event, decode_spend_event from litellm.proxy.spend_tracking.spend_event_producer import SpendEventProducer, UnixAddress from litellm.proxy.spend_tracking.spend_tracking_utils import get_logging_payload +from litellm.proxy.utils import ( + REJECTED_BEFORE_REQUEST_SETUP, + REJECTED_BEFORE_REQUEST_SETUP_KEY, + ProxyUpdateSpend, +) from litellm.types.router import Deployment, LiteLLM_Params from litellm.types.utils import CallTypes, LiteLLMBatch, ModelResponse, PromptTokensDetailsWrapper, Usage @@ -3559,3 +3566,103 @@ async def test_batch_accounting_does_not_retry_after_a_search_allowance_update(m assert sum(counter.totals.values()) == 5 assert outcome.failed is True assert outcome.retryable_failure is False + + +_ROUTED_REQUEST: Final[Mapping[str, object]] = { + "model": "anthropic-haiku-4-5", + "messages": [{"role": "user", "content": "hi"}], + "proxy_server_request": {"request_id": "req-1"}, + "litellm_call_id": "call-1", +} +_PRE_ROUTING_REQUEST: Final[Mapping[str, object]] = { + **_ROUTED_REQUEST, + REJECTED_BEFORE_REQUEST_SETUP_KEY: REJECTED_BEFORE_REQUEST_SETUP, +} +_SPOOFED_REQUEST: Final[Mapping[str, object]] = {**_ROUTED_REQUEST, REJECTED_BEFORE_REQUEST_SETUP_KEY: True} +_INVALID_REQUEST_400: Final = ProxyException( + message="Violated guardrail policy", type="invalid_request_error", param=None, code=400 +) +_PROVIDER_AUTH_ERROR: Final = litellm.AuthenticationError( + message="bad key", llm_provider="anthropic", model="claude-haiku-4-5" +) + + +@pytest.mark.parametrize( + ("exception", "request_data", "expected"), + [ + (_INVALID_REQUEST_400, _PRE_ROUTING_REQUEST, True), + (litellm.BudgetExceededError(current_cost=1.0, max_budget=0.0), _PRE_ROUTING_REQUEST, True), + (ProxyModelNotFoundError(route="/chat/completions", model_name="4.6"), _ROUTED_REQUEST, True), + (_INVALID_REQUEST_400, _ROUTED_REQUEST, False), + (_INVALID_REQUEST_400, _SPOOFED_REQUEST, False), + (_PROVIDER_AUTH_ERROR, _ROUTED_REQUEST, False), + ( + litellm.RateLimitError(message="slow down", llm_provider="anthropic", model="claude-haiku-4-5"), + _ROUTED_REQUEST, + False, + ), + (HTTPException(status_code=429, detail="Max parallel request limit reached"), _ROUTED_REQUEST, False), + ], + ids=[ + "bad-body", + "budget", + "unknown-model", + "guardrail-block", + "guardrail-block-with-client-spoofed-marker", + "provider-auth", + "provider-429", + "proxy-429", + ], +) +def test_is_pre_routing_rejection_is_decided_by_pipeline_stage_not_exception_type( + exception: Exception, request_data: Mapping[str, object], expected: bool +) -> None: + assert is_pre_routing_rejection(exception, request_data) is expected + + +class _RecordingSpendWriter: + def __init__(self) -> None: + self.rows: list[Mapping[str, object]] = [] # mutable-ok: test double records the spend rows written + + async def update_database(self, **kwargs: object) -> None: + self.rows.append(kwargs) + + +@pytest.mark.asyncio +@pytest.mark.parametrize( + ("flag_enabled", "exception", "request_data", "rows_written"), + [ + (True, _INVALID_REQUEST_400, _PRE_ROUTING_REQUEST, 0), + (True, litellm.BudgetExceededError(current_cost=1.0, max_budget=0.0), _PRE_ROUTING_REQUEST, 0), + (True, ProxyModelNotFoundError(route="/chat/completions", model_name="4.6"), _ROUTED_REQUEST, 0), + (True, _INVALID_REQUEST_400, _ROUTED_REQUEST, 1), + (True, _INVALID_REQUEST_400, _SPOOFED_REQUEST, 1), + (True, _PROVIDER_AUTH_ERROR, _ROUTED_REQUEST, 1), + (False, _INVALID_REQUEST_400, _PRE_ROUTING_REQUEST, 1), + (False, litellm.BudgetExceededError(current_cost=1.0, max_budget=0.0), _PRE_ROUTING_REQUEST, 1), + ], + ids=[ + "flag-bad-body", + "flag-budget", + "flag-unknown-model", + "flag-guardrail-block-kept", + "flag-guardrail-block-with-spoofed-marker-kept", + "flag-provider-error-kept", + "off-bad-body", + "off-budget", + ], +) +async def test_async_post_call_failure_hook_disable_pre_routing_error_logs( + flag_enabled: bool, exception: Exception, request_data: Mapping[str, object], rows_written: int +) -> None: + writer: Final = _RecordingSpendWriter() + user_api_key_dict: Final = UserAPIKeyAuth( + api_key="test_api_key", user_id="u", team_id="t", request_route="/chat/completions" + ) + with patch("litellm.proxy.proxy_server.general_settings", {"disable_pre_routing_error_logs": flag_enabled}): + await ProxyDBLogger(spend_writer=lambda: cast(DBSpendUpdateWriter, writer)).async_post_call_failure_hook( + request_data={**request_data, "metadata": dict[str, object]()}, + original_exception=exception, + user_api_key_dict=user_api_key_dict, + ) + assert len(writer.rows) == rows_written diff --git a/tests/unit/proxy/utils/proxy_logging/test_post_call_failure_hook.py b/tests/unit/proxy/utils/proxy_logging/test_post_call_failure_hook.py index e83efa21dcc..6557f0d1446 100644 --- a/tests/unit/proxy/utils/proxy_logging/test_post_call_failure_hook.py +++ b/tests/unit/proxy/utils/proxy_logging/test_post_call_failure_hook.py @@ -18,7 +18,7 @@ from litellm.constants import PROXY_REJECTED_BEFORE_ROUTING_KEY from litellm.exceptions import GuardrailRaisedException from litellm.integrations.custom_logger import CustomLogger from litellm.proxy._types import ProxyErrorTypes, UserAPIKeyAuth -from litellm.proxy.utils import ProxyLogging +from litellm.proxy.utils import REJECTED_BEFORE_REQUEST_SETUP, REJECTED_BEFORE_REQUEST_SETUP_KEY, ProxyLogging from litellm.types.utils import CachingDetails @@ -194,7 +194,9 @@ async def test_post_call_failure_hook_attributes_single_router_deployment( @pytest.mark.asyncio -async def test_pre_routing_reject_spend_log_keeps_public_model_group(proxy_logging, make_user_api_key_auth, monkeypatch): +async def test_pre_routing_reject_spend_log_keeps_public_model_group( + proxy_logging, make_user_api_key_auth, monkeypatch +): from litellm.proxy import proxy_server from litellm.proxy.spend_tracking.spend_tracking_utils import get_logging_payload @@ -1001,7 +1003,9 @@ async def test_post_call_failure_hook_guardrail_block_fires_failure_callback( self, kwargs: dict[str, object], response_obj: object, start_time: datetime, end_time: datetime ) -> None: standard_logging_object = kwargs.get("standard_logging_object") - recorded.append(standard_logging_object.get("status") if isinstance(standard_logging_object, dict) else None) + recorded.append( + standard_logging_object.get("status") if isinstance(standard_logging_object, dict) else None + ) monkeypatch.setattr(litellm, "_async_failure_callback", [_StatusRecorder()]) logging_obj = LiteLLMLoggingObj( @@ -1029,3 +1033,52 @@ async def test_post_call_failure_hook_guardrail_block_fires_failure_callback( await asyncio.sleep(0) await asyncio.sleep(0) assert recorded == ["failure"] + + +@pytest.mark.asyncio +async def test_handle_logging_proxy_only_path_flags_requests_that_died_before_request_setup( + proxy_logging, make_user_api_key_auth +): + """A reject before the pipeline set up logging (bad key, bad body) reaches the failure hook with no logging + object. The handler mints a ``litellm_call_id`` so error logs can carry it, and marks the request with a + server-owned sentinel so spend tracking can tell it apart from a guardrail block, which arrives with the + pipeline's logging object. ``request_data`` is the client body, so a client-sent call id or marker value must + not change either outcome.""" + rejected_before_setup: dict[str, object] = { + "model": "m", + "messages": [{"role": "user", "content": "x"}], + "metadata": {}, + "litellm_call_id": "client-supplied", + } + await proxy_logging._handle_logging_proxy_only_error( + request_data=rejected_before_setup, + user_api_key_dict=make_user_api_key_auth(), + route="/chat/completions", + original_exception=HTTPException(status_code=401, detail="bad key"), + ) + + logging_obj = MagicMock() + logging_obj.call_type = "acompletion" + logging_obj.model_call_details = {} + logging_obj.async_failure_handler = AsyncMock() + blocked_by_guardrail: dict[str, object] = { + "litellm_logging_obj": logging_obj, + "litellm_call_id": "call-1", + "model": "m", + "messages": [{"role": "user", "content": "x"}], + "metadata": {}, + REJECTED_BEFORE_REQUEST_SETUP_KEY: True, + } + await proxy_logging._handle_logging_proxy_only_error( + request_data=blocked_by_guardrail, + user_api_key_dict=make_user_api_key_auth(), + route="/chat/completions", + original_exception=HTTPException(status_code=400, detail="blocked"), + ) + + assert ( + rejected_before_setup.get(REJECTED_BEFORE_REQUEST_SETUP_KEY) is REJECTED_BEFORE_REQUEST_SETUP, + rejected_before_setup["litellm_call_id"], + blocked_by_guardrail.get(REJECTED_BEFORE_REQUEST_SETUP_KEY) is REJECTED_BEFORE_REQUEST_SETUP, + blocked_by_guardrail["litellm_call_id"], + ) == (True, "client-supplied", False, "call-1")