fix(proxy): keep allowlisted metadata in proxy-only failure logs

Backport of #50 to rc/1.105.0.
Cherry-picked from 9722ca937e (main).
This commit is contained in:
mateo-berri 2026-10-08 07:26:14 -07:00 • committed by yucheng
parent 97474e4ae7
commit 116dd0504c
5 changed files with 329 additions and 32 deletions

View file

@ -6478,19 +6478,17 @@ class StandardLoggingPayloadSetup:
litellm_metadata: Final = cast( # cast-ok: request metadata is caller-provided
Mapping[str, object], litellm_params.get("litellm_metadata") or {}
)
if metadata.get("tags", []):
request_tags = cast(list[str], metadata.get("tags", [])).copy() # cast-ok: tags are caller-provided
elif litellm_metadata.get("tags", []):
request_tags = cast(list[str], litellm_metadata.get("tags", [])).copy() # cast-ok: tags are caller-provided
else:
request_tags = []
request_tags: Final = next(
(
cast(list[str], tags) # cast-ok: tags are caller-provided
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 ())]
_get_request_tags = get_request_tags

View file

@ -1237,7 +1237,8 @@ def _stamp_deployment_attribution(
callbacks key off it and must not count a proxy-side reject against the deployment. A failure
after the provider handoff keeps the metadata the router stamped; a request that never reached a
provider is flagged ``PROXY_REJECTED_BEFORE_ROUTING_KEY`` (deployment metrics key off it) whatever
its metadata says, since ``metadata.model_info`` can be caller supplied."""
its metadata says, since ``metadata.model_info`` can be caller supplied. Its ``deployment`` and
``model_group`` always come from the router config, never from the caller's metadata."""
attribution: Final = _deployment_attribution_for_model_group(model_group, team_id)
if "custom_llm_provider" in attribution:
litellm_params["custom_llm_provider"] = attribution["custom_llm_provider"]
@ -1252,9 +1253,13 @@ def _stamp_deployment_attribution(
if not isinstance(metadata, dict):
return attribution
metadata.setdefault("model_info", attribution["model_info"])
metadata.setdefault("deployment", attribution["deployment"])
if isinstance(model_group, str):
metadata.setdefault("model_group", model_group)
routing: Final = MappingProxyType(
{"deployment": attribution["deployment"], **({"model_group": model_group} if model_group else {})}
)
metadata.update(routing)
litellm_metadata: Final = litellm_params.get("litellm_metadata")
if isinstance(litellm_metadata, dict):
litellm_metadata.update(routing)
return attribution
@ -1333,8 +1338,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
@ -3614,6 +3661,7 @@ class ProxyLogging:
user_api_key_dict=user_api_key_dict,
route=route,
original_exception=original_exception,
error_type=error_type,
)
request_data.update(
@ -3702,6 +3750,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`
@ -3709,19 +3758,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:
@ -3734,14 +3786,32 @@ 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"
},
}
attribution: Final = _stamp_deployment_attribution(
_litellm_params,
litellm_params,
request_data.get("model"),
user_api_key_dict.team_id,
dispatched=_reached_deployment(litellm_logging_obj),
@ -3751,7 +3821,7 @@ class ProxyLogging:
model=request_data.get("model", ""),
user=request_data.get("user", ""),
optional_params=_optional_params,
litellm_params=_litellm_params,
litellm_params=litellm_params,
**(
{"custom_llm_provider": attribution["custom_llm_provider"]}
if "custom_llm_provider" in attribution

View file

@ -3140,6 +3140,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.

View file

@ -117,11 +117,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"},
}
@ -137,6 +184,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

View file

@ -357,6 +357,103 @@ async def test_post_call_failure_hook_flags_pre_routing_reject_despite_caller_mo
assert kwargs["litellm_params"]["custom_llm_provider"] == "openai"
@pytest.mark.asyncio
@pytest.mark.parametrize("metadata_field", ["metadata", "litellm_metadata"])
async def test_pre_routing_reject_logs_the_configured_deployment_over_caller_metadata(
proxy_logging, make_user_api_key_auth, monkeypatch, metadata_field: str
):
from litellm.proxy import proxy_server
from litellm.proxy.spend_tracking.spend_tracking_utils import get_logging_payload
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(
proxy_server,
"llm_router",
litellm.Router(
model_list=[
{
"model_name": "internal-model",
"litellm_params": {"model": "openai/gpt-4.1", "api_key": "sk-test"},
}
]
),
)
monkeypatch.setattr(litellm, "callbacks", [_RecordingLogger()])
proxy_logging.alert_types = []
request_data: Final[dict[str, object]] = {
"model": "internal-model",
"messages": [{"role": "user", "content": "hi"}],
"litellm_call_id": "caller-routing-metadata",
metadata_field: {"deployment": "openai/caller-chosen", "model_group": "caller-group"},
}
logging_obj, _ = litellm.utils.function_setup(
original_function="acompletion", rules_obj=litellm.utils.Rules(), start_time=datetime.now(), **request_data
)
await proxy_logging.post_call_failure_hook(
request_data={**request_data, "litellm_logging_obj": logging_obj},
original_exception=HTTPException(status_code=400, detail="Content blocked"),
user_api_key_dict=make_user_api_key_auth(request_route="/chat/completions"),
route="/chat/completions",
)
assert len(recorded) == 1
now: Final = datetime.now()
payload: Final = get_logging_payload(
kwargs={**recorded[0], "completion_start_time": now}, response_obj=None, start_time=now, end_time=now
)
standard_logging_object: Final = recorded[0]["standard_logging_object"]
assert {
"logged_model": standard_logging_object["model"],
"logged_model_group": standard_logging_object["model_group"],
"spend_model": payload["model"],
"spend_model_group": payload["model_group"],
} == {
"logged_model": "openai/gpt-4.1",
"logged_model_group": "internal-model",
"spend_model": "openai/gpt-4.1",
"spend_model_group": "internal-model",
}
@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]
):
from litellm.proxy import proxy_server
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(proxy_server, "llm_router", None)
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_post_call_failure_hook_attribution_does_not_count_against_the_deployment(
proxy_logging, make_user_api_key_auth, monkeypatch
@ -529,9 +626,8 @@ async def test_post_call_failure_hook_omits_provider_when_a_deployment_does_not_
async def test_handle_logging_proxy_only_path_attributes_with_read_only_metadata(
proxy_logging, make_user_api_key_auth, monkeypatch
):
"""With a logging object already on the request, a read-only metadata mapping
must not crash the stamp, the failure handler still receives the provider
attribution, and the request's metadata is not copied into the update."""
"""With a logging object already on the request, allowlisted metadata is kept,
a read-only mapping must not crash the stamp, and the failure handler receives provider attribution."""
from litellm.proxy import proxy_server
monkeypatch.setattr(
@ -550,16 +646,26 @@ async def test_handle_logging_proxy_only_path_attributes_with_read_only_metadata
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": "internal-model",
"messages": [{"role": "user", "content": "hi"}],
"metadata": MappingProxyType({"user_api_key_alias": "frozen"}),
"metadata": MappingProxyType(
{"tags": ["checkout"], "standard_logging_guardrail_information": guardrail_info}
),
},
user_api_key_dict=make_user_api_key_auth(request_route="/chat/completions"),
user_api_key_dict=make_user_api_key_auth(request_route="/chat/completions", key_alias="frozen"),
route="/chat/completions",
original_exception=HTTPException(status_code=403, detail="blocked"),
)
@ -568,7 +674,11 @@ async def test_handle_logging_proxy_only_path_attributes_with_read_only_metadata
update_kwargs = logging_obj.update_environment_variables.call_args.kwargs
assert update_kwargs["custom_llm_provider"] == "openai"
assert update_kwargs["litellm_params"]["custom_llm_provider"] == "openai"
assert "user_api_key_alias" not in update_kwargs["litellm_params"]["metadata"]
assert {
key: update_kwargs["litellm_params"]["metadata"][key] for key in ("preexisting", "user_api_key_alias")
} == {"preexisting": "logged", "user_api_key_alias": "frozen"}
assert update_kwargs["litellm_params"]["metadata"]["tags"] == ["checkout"]
assert update_kwargs["litellm_params"]["metadata"]["standard_logging_guardrail_information"] == guardrail_info
@pytest.mark.asyncio