From 810e5b5c53afe1912bb037d6be698b110ccd5b39 Mon Sep 17 00:00:00 2001 From: mateo-berri <277851410+mateo-berri@users.noreply.github.com> Date: Thu, 8 Oct 2026 07:40:00 -0700 Subject: [PATCH] fix(proxy): keep allowlisted metadata in proxy-only failure logs Backport of #50 to stable/1.103.x. Cherry-picked from 9722ca937e (main). This line predates the router deployment attribution on proxy-only failures, so that part of the change has no counterpart here; the logger's existing metadata is still merged under the allowlisted fields. --- litellm/litellm_core_utils/litellm_logging.py | 16 +-- litellm/proxy/utils.py | 81 +++++++++++-- .../test_litellm_logging.py | 15 +++ tests/test_litellm/proxy/test_proxy_utils.py | 108 +++++++++++++++++- .../test_post_call_failure_hook.py | 74 ++++++++++++ 5 files changed, 273 insertions(+), 21 deletions(-) diff --git a/litellm/litellm_core_utils/litellm_logging.py b/litellm/litellm_core_utils/litellm_logging.py index 3ea51169af0..b56077e7f69 100644 --- a/litellm/litellm_core_utils/litellm_logging.py +++ b/litellm/litellm_core_utils/litellm_logging.py @@ -6132,19 +6132,13 @@ class StandardLoggingPayloadSetup: # check for 'tags' in both 'metadata' and 'litellm_metadata' metadata: Final = litellm_params.get("metadata") or {} litellm_metadata: Final = litellm_params.get("litellm_metadata") or {} - if metadata.get("tags", []): - request_tags = metadata.get("tags", []).copy() - elif litellm_metadata.get("tags", []): - request_tags = litellm_metadata.get("tags", []).copy() - else: - request_tags = [] + request_tags: Final = next( + (tags for tags in (metadata.get("tags"), litellm_metadata.get("tags")) if isinstance(tags, list) and tags), + [], + ) user_agent_tags: Final = StandardLoggingPayloadSetup._get_user_agent_tags(proxy_server_request) additional_header_tags: Final = StandardLoggingPayloadSetup._get_extra_header_tags(proxy_server_request) - if user_agent_tags is not None: - request_tags.extend(user_agent_tags) - if additional_header_tags is not None: - request_tags.extend(additional_header_tags) - return request_tags + return [*request_tags, *(user_agent_tags or ()), *(additional_header_tags or ())] def _get_status_fields( diff --git a/litellm/proxy/utils.py b/litellm/proxy/utils.py index bded7a678f7..51a20234c34 100644 --- a/litellm/proxy/utils.py +++ b/litellm/proxy/utils.py @@ -1199,8 +1199,50 @@ _PROXY_ONLY_ERROR_LOGGED_FIELDS: Final = frozenset( ) -def _proxy_only_error_log_fields(request_data: Mapping[str, _T]) -> Mapping[str, _T]: - return MappingProxyType({k: v for k, v in request_data.items() if k in _PROXY_ONLY_ERROR_LOGGED_FIELDS}) +def _as_str_mapping(value: object) -> Mapping[str, object]: + if not isinstance(value, Mapping): + return MappingProxyType({}) + return cast( # cast-ok: the runtime Mapping check validates the container shape + Mapping[str, object], value + ) + + +def _proxy_only_error_logged_metadata_keys(*, authenticated: bool, past_pre_call: bool) -> frozenset[str]: + return frozenset( + key + for key, logged in (("tags", authenticated), ("standard_logging_guardrail_information", past_pre_call)) + if logged + ) + + +def _is_logged_metadata_value(key: str, value: object) -> bool: + return key != "tags" or (isinstance(value, list) and all(isinstance(item, str) for item in value)) + + +def _proxy_only_error_log_metadata(value: object, logged_keys: frozenset[str]) -> dict[str, object] | None: + if not isinstance(value, Mapping): + return None + metadata: Final = _as_str_mapping(value) + return { + key: value for key, value in metadata.items() if key in logged_keys and _is_logged_metadata_value(key, value) + } + + +def _proxy_only_error_log_fields( + request_data: Mapping[str, object], logged_metadata_keys: frozenset[str] +) -> Mapping[str, object]: + metadata_fields: Final = { + key: filtered_metadata + for key in ("metadata", "litellm_metadata") + if (filtered_metadata := _proxy_only_error_log_metadata(request_data.get(key), logged_metadata_keys)) + is not None + } + return MappingProxyType( + { + **{key: value for key, value in request_data.items() if key in _PROXY_ONLY_ERROR_LOGGED_FIELDS}, + **metadata_fields, + } + ) _EXCEPTION_CHAIN_MAX_DEPTH: Final = 16 @@ -3364,6 +3406,7 @@ class ProxyLogging: user_api_key_dict=user_api_key_dict, route=route, original_exception=original_exception, + error_type=error_type, ) request_data.update( @@ -3452,6 +3495,7 @@ class ProxyLogging: user_api_key_dict: UserAPIKeyAuth, route: str | None = None, original_exception: Exception | None = None, + error_type: ProxyErrorTypes | None = None, ): """ Handle logging for proxy only errors by calling `litellm_logging_obj.async_failure_handler` @@ -3459,19 +3503,22 @@ class ProxyLogging: Is triggered when self._is_proxy_only_error() returns True """ litellm_logging_obj: Logging | None = request_data.get("litellm_logging_obj", None) + logged_metadata_keys: Final = _proxy_only_error_logged_metadata_keys( + authenticated=error_type != ProxyErrorTypes.auth_error, past_pre_call=litellm_logging_obj is not None + ) + user_api_key_logged_metadata: Final = LiteLLMProxyRequestSetup.get_sanitized_user_information_from_key( + user_api_key_dict=user_api_key_dict + ) if litellm_logging_obj is None: from litellm._uuid import uuid 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 - ) litellm_logging_obj, data = litellm.utils.function_setup( original_function=route or "IGNORE_THIS", rules_obj=litellm.utils.Rules(), start_time=datetime.now(), - **_proxy_only_error_log_fields(request_data), + **_proxy_only_error_log_fields(request_data, logged_metadata_keys), ) request_data["litellm_logging_obj"] = litellm_logging_obj # rebind-ok: lifted then popped by the caller if "metadata" not in request_data: @@ -3484,17 +3531,35 @@ class ProxyLogging: _litellm_params: Final = {} litellm_param_keys: Final = LoggedLiteLLMParams.__annotations__.keys() - for k, v in _proxy_only_error_log_fields(request_data).items(): + for k, v in _proxy_only_error_log_fields(request_data, logged_metadata_keys).items(): if k in litellm_param_keys: _litellm_params[k] = v elif k not in ("model", "user", "litellm_logging_obj"): _optional_params[k] = v + existing: Final = _as_str_mapping(litellm_logging_obj.litellm_params) + litellm_params: Final = { + **_litellm_params, + "metadata": { + **_as_str_mapping(existing.get("metadata")), + **_as_str_mapping(_litellm_params.get("metadata")), + **user_api_key_logged_metadata, + }, + **{ + key: { + **_as_str_mapping(existing.get(key)), + **_as_str_mapping(value), + } + for key, value in _litellm_params.items() + if key == "litellm_metadata" + }, + } + litellm_logging_obj.update_environment_variables( model=request_data.get("model", ""), user=request_data.get("user", ""), optional_params=_optional_params, - litellm_params=_litellm_params, + litellm_params=litellm_params, ) input: list | str | dict = "" diff --git a/tests/test_litellm/litellm_core_utils/test_litellm_logging.py b/tests/test_litellm/litellm_core_utils/test_litellm_logging.py index 78b24b565f4..164b0ce8866 100644 --- a/tests/test_litellm/litellm_core_utils/test_litellm_logging.py +++ b/tests/test_litellm/litellm_core_utils/test_litellm_logging.py @@ -2039,6 +2039,21 @@ def test_get_request_tags_from_metadata_and_litellm_metadata(): assert "User-Agent: litellm/1.0.0" in tags +@pytest.mark.parametrize("unusable_metadata_tags", [123, "tag", {"tag": True}, []]) +def test_get_request_tags_falls_back_to_litellm_metadata_when_metadata_tags_are_unusable(unusable_metadata_tags): + from litellm.litellm_core_utils.litellm_logging import StandardLoggingPayloadSetup + + tags = StandardLoggingPayloadSetup._get_request_tags( + litellm_params={ + "metadata": {"tags": unusable_metadata_tags}, + "litellm_metadata": {"tags": ["litellm-metadata-tag"]}, + }, + proxy_server_request={}, + ) + + assert tags == ["litellm-metadata-tag"] + + def test_get_request_tags_does_not_mutate_original_tags(): """ Test that _get_request_tags does not mutate the original tags list in metadata. diff --git a/tests/test_litellm/proxy/test_proxy_utils.py b/tests/test_litellm/proxy/test_proxy_utils.py index 46d46549335..359c7aeda26 100644 --- a/tests/test_litellm/proxy/test_proxy_utils.py +++ b/tests/test_litellm/proxy/test_proxy_utils.py @@ -115,11 +115,58 @@ async def test_proxy_only_error_log_marks_no_upstream_llm_call(): @pytest.mark.asyncio @pytest.mark.parametrize("metadata_field", ["metadata", "litellm_metadata"]) -async def test_proxy_only_error_log_drops_caller_logging_fields_and_metadata(metadata_field: str): +async def test_proxy_only_error_log_drops_caller_guardrail_information_without_logging_object( + metadata_field: str, + monkeypatch: pytest.MonkeyPatch, +) -> None: + monkeypatch.setattr(litellm, "callbacks", []) + monkeypatch.setattr(litellm, "input_callback", []) + monkeypatch.setattr(litellm, "failure_callback", []) + monkeypatch.setattr(litellm, "_async_failure_callback", []) + guardrail_info: Final = [ + { + "guardrail_name": "caller-guardrail", + "guardrail_status": "guardrail_intervened", + "guardrail_cost": 123.45, + } + ] request_data: Final[dict[str, object]] = { "model": "gpt-4o", "messages": [{"role": "user", "content": "hi"}], - metadata_field: {"langsmith_base_url": "https://caller.invalid", "langsmith_api_key": "caller-key"}, + metadata_field: {"tags": ["t"], "standard_logging_guardrail_information": guardrail_info}, + } + + await ProxyLogging(user_api_key_cache=DualCache())._handle_logging_proxy_only_error( + request_data=request_data, + user_api_key_dict=UserAPIKeyAuth(api_key="sk-rejected", team_id="team-a", request_route="/v1/chat/completions"), + route="/v1/chat/completions", + original_exception=HTTPException(status_code=400, detail="blocked"), + ) + + details: Final = request_data["litellm_logging_obj"].model_call_details + assert details["standard_logging_object"] is not None + assert details["litellm_params"][metadata_field]["tags"] == ["t"] + assert "standard_logging_guardrail_information" not in details["litellm_params"][metadata_field] + assert "guardrail_cost" not in str(details["standard_logging_object"]) + assert "litellm_metadata" not in details["optional_params"] + + +@pytest.mark.asyncio +@pytest.mark.parametrize("metadata_field", ["metadata", "litellm_metadata"]) +async def test_proxy_only_error_log_keeps_tags_and_drops_caller_logging_fields( + metadata_field: str, +) -> None: + request_data: Final[dict[str, object]] = { + "model": "gpt-4o", + "messages": [{"role": "user", "content": "hi"}], + metadata_field: { + "langsmith_base_url": "https://caller.invalid", + "langsmith_api_key": "caller-key", + "tags": ["t"], + "user_api_key_team_id": "caller-team", + "user_api_key_hash": "caller-hash", + "user_api_key_auth_metadata": {"caller": "metadata"}, + }, "langsmith_base_url": "https://caller.invalid", "standard_callback_dynamic_params": {"gcs_path_service_account": "/caller/sa.json"}, } @@ -135,6 +182,63 @@ async def test_proxy_only_error_log_drops_caller_logging_fields_and_metadata(met assert "caller" not in str(details["standard_callback_dynamic_params"]) assert "langsmith_base_url" not in details assert "caller" not in str(details["litellm_params"]) + assert details["litellm_params"][metadata_field]["tags"] == ["t"] + assert details["litellm_params"]["metadata"]["user_api_key_team_id"] == "team-a" + + +@pytest.mark.asyncio +@pytest.mark.parametrize("metadata_field", ["metadata", "litellm_metadata"]) +async def test_proxy_only_error_log_drops_malformed_metadata_tags(metadata_field: str) -> None: + guardrail_info: Final = [{"guardrail_name": "g", "guardrail_status": "guardrail_intervened"}] + request_data: Final[dict[str, object]] = { + "model": "gpt-4o", + "messages": [{"role": "user", "content": "hi"}], + metadata_field: {"tags": 123, "standard_logging_guardrail_information": guardrail_info}, + } + + await ProxyLogging(user_api_key_cache=DualCache())._handle_logging_proxy_only_error( + request_data=request_data, + user_api_key_dict=UserAPIKeyAuth(api_key="sk-rejected", team_id="team-a", request_route="/v1/chat/completions"), + route="/v1/chat/completions", + original_exception=Exception("bad key"), + ) + + details: Final = request_data["litellm_logging_obj"].model_call_details + assert details["standard_logging_object"] is not None + assert "tags" not in details["litellm_params"][metadata_field] + assert "standard_logging_guardrail_information" not in details["litellm_params"][metadata_field] + + +@pytest.mark.asyncio +@pytest.mark.parametrize("metadata_field", ["metadata", "litellm_metadata"]) +async def test_proxy_only_error_log_builds_payload_when_logging_object_has_malformed_tags( + metadata_field: str, +) -> None: + request_data: Final[dict[str, object]] = { + "model": "gpt-4o", + "messages": [{"role": "user", "content": "hi"}], + "litellm_call_id": "malformed-tags-call", + metadata_field: {"tags": 123}, + } + logging_obj, _ = litellm.utils.function_setup( + original_function="acompletion", + rules_obj=litellm.utils.Rules(), + start_time=real_datetime.datetime.now(), + **request_data, + ) + + await ProxyLogging(user_api_key_cache=DualCache())._handle_logging_proxy_only_error( + request_data={**request_data, "litellm_logging_obj": logging_obj}, + user_api_key_dict=UserAPIKeyAuth(api_key="sk-blocked", team_id="team-a", request_route="/v1/chat/completions"), + route="/v1/chat/completions", + original_exception=HTTPException(status_code=400, detail="Content blocked"), + ) + + standard_logging_object: Final = logging_obj.model_call_details["standard_logging_object"] + assert standard_logging_object is not None + assert standard_logging_object["model"] == request_data["model"] + assert standard_logging_object["metadata"]["user_api_key_team_id"] == "team-a" + assert 123 not in standard_logging_object["request_tags"] @pytest.mark.asyncio diff --git a/tests/test_litellm/proxy/utils/proxy_logging/test_post_call_failure_hook.py b/tests/test_litellm/proxy/utils/proxy_logging/test_post_call_failure_hook.py index a4bb7d63548..3a54312ca8e 100644 --- a/tests/test_litellm/proxy/utils/proxy_logging/test_post_call_failure_hook.py +++ b/tests/test_litellm/proxy/utils/proxy_logging/test_post_call_failure_hook.py @@ -262,6 +262,80 @@ async def test_handle_logging_proxy_only_path_no_logging_obj_creates_one( fake_logging_obj.async_failure_handler.assert_called_once() +@pytest.mark.asyncio +async def test_handle_logging_proxy_only_path_merges_allowlisted_metadata(proxy_logging, make_user_api_key_auth): + logging_obj = MagicMock() + logging_obj.call_type = "acompletion" + logging_obj.model_call_details = {} + logging_obj.litellm_params = {"metadata": {"preexisting": "logged"}} + logging_obj.async_failure_handler = AsyncMock() + guardrail_info: Final = [ + { + "guardrail_name": "local-block", + "guardrail_status": "guardrail_intervened", + "guardrail_cost": 0.25, + } + ] + + await proxy_logging._handle_logging_proxy_only_error( + request_data={ + "litellm_logging_obj": logging_obj, + "model": "m", + "messages": [{"role": "user", "content": "hi"}], + "metadata": { + "tags": ["checkout"], + "standard_logging_guardrail_information": guardrail_info, + "spend_logs_metadata": {"caller": "dropped"}, + }, + }, + user_api_key_dict=make_user_api_key_auth(key_alias="frozen"), + route="/chat/completions", + original_exception=HTTPException(status_code=403, detail="blocked"), + ) + + metadata: Final = logging_obj.update_environment_variables.call_args.kwargs["litellm_params"]["metadata"] + assert { + key: metadata.get(key) + for key in ("preexisting", "user_api_key_alias", "tags", "standard_logging_guardrail_information") + } == { + "preexisting": "logged", + "user_api_key_alias": "frozen", + "tags": ["checkout"], + "standard_logging_guardrail_information": guardrail_info, + } + assert "spend_logs_metadata" not in metadata + + +@pytest.mark.asyncio +@pytest.mark.parametrize(("error_type", "logged_tags"), [(ProxyErrorTypes.auth_error, []), (None, ["checkout"])]) +async def test_proxy_only_failure_log_keeps_caller_tags_only_after_auth( + proxy_logging, monkeypatch, error_type: ProxyErrorTypes | None, logged_tags: list[str] +): + recorded: list[dict] = [] + + class _RecordingLogger(CustomLogger): + async def async_log_failure_event(self, kwargs, response_obj, start_time, end_time): + recorded.append(kwargs) + + monkeypatch.setattr(litellm, "callbacks", [_RecordingLogger()]) + proxy_logging.alert_types = [] + + await proxy_logging.post_call_failure_hook( + request_data={ + "model": "internal-model", + "messages": [{"role": "user", "content": "hi"}], + "metadata": {"tags": ["checkout"]}, + }, + original_exception=HTTPException(status_code=401, detail="Invalid proxy server token passed"), + user_api_key_dict=UserAPIKeyAuth(request_route="/chat/completions"), + error_type=error_type, + route="/chat/completions", + ) + + assert len(recorded) == 1 + assert recorded[0]["standard_logging_object"]["request_tags"] == logged_tags + + @pytest.mark.asyncio async def test_handle_logging_proxy_only_path_propagates_async_failure_raises(proxy_logging, make_user_api_key_auth): logging_obj = MagicMock()