From 7ae46f27687f8d927c4fc16d796af68eb8bda273 Mon Sep 17 00:00:00 2001 From: Kerry Lu Date: Tue, 20 Oct 2026 22:37:21 -0700 Subject: [PATCH] fix(timing): carry litellm_received_at across to a planted litellm_metadata bucket so the overhead header stays anchored at receive time (#47790) A guardrail hook plants a litellm_metadata key on a chat completions request after the proxy stamped litellm_received_at into metadata. get_litellm_metadata_from_kwargs prefers that key when both exist and only copied the user_api_key_* fields across, so the response timing headers lost their receive anchor and x-litellm-overhead-duration-ms reported 2 ms on /v1/chat/completions against 58 ms on /v1/responses for the same proxy work. The receive stamp now rides along with the user_api_key_* fields. Co-authored-by: devin-ai-integration[bot] <158243242+devin-ai-integration[bot]@users.noreply.github.com> --- litellm/litellm_core_utils/core_helpers.py | 7 +++- .../litellm_core_utils/test_core_helpers.py | 38 ++++++++++++++++++- 2 files changed, 41 insertions(+), 4 deletions(-) diff --git a/litellm/litellm_core_utils/core_helpers.py b/litellm/litellm_core_utils/core_helpers.py index b7c6f805233..1d61ef8519a 100644 --- a/litellm/litellm_core_utils/core_helpers.py +++ b/litellm/litellm_core_utils/core_helpers.py @@ -329,11 +329,14 @@ def add_missing_spend_metadata_to_litellm_metadata(litellm_metadata: dict, metad Helper to get litellm metadata for spend tracking PATCH for issue where both `litellm_metadata` and `metadata` are present in the kwargs - and user_api_key values are in 'metadata'. + and user_api_key values are in 'metadata'. The proxy receive stamp rides along for the same + reason: a guardrail hook can plant `litellm_metadata` on a chat request after the proxy stamped + `metadata`, and the response timing headers anchor on that stamp. """ potential_spend_tracking_metadata_substring: Final = "user_api_key" for key, value in dict(metadata).items(): - if potential_spend_tracking_metadata_substring in key: + carry_receive_stamp = key == "litellm_received_at" and key not in litellm_metadata + if potential_spend_tracking_metadata_substring in key or carry_receive_stamp: litellm_metadata[key] = value return litellm_metadata diff --git a/tests/unit/litellm_core_utils/test_core_helpers.py b/tests/unit/litellm_core_utils/test_core_helpers.py index 6459aa98e70..d66c37ba8c2 100644 --- a/tests/unit/litellm_core_utils/test_core_helpers.py +++ b/tests/unit/litellm_core_utils/test_core_helpers.py @@ -1,5 +1,6 @@ """Tests for litellm_core_utils.core_helpers module.""" +import datetime import json import logging import threading @@ -18,13 +19,13 @@ from litellm.litellm_core_utils.core_helpers import ( drop_params_env_flag, drop_params_flag, get_litellm_metadata_from_kwargs, - get_parent_otel_span_from_kwargs, get_or_create_metadata_bucket, + get_parent_otel_span_from_kwargs, get_provider_response_headers_from_hidden_params, map_finish_reason, normalize_drop_params, - process_response_headers, preserve_upstream_non_openai_attributes, + process_response_headers, reconstruct_model_name, redact_nested_match_and_regex_keys, set_provider_response_headers_in_hidden_params, @@ -685,3 +686,36 @@ def test_spend_metadata_merge_reads_request_metadata_that_is_a_read_only_mapping ) assert merged == {"user_api_key_hash": "hash", "model_group": "claude"} + + +class TestReceiveStampSurvivesASecondMetadataBucket: + """A guardrail hook can plant ``litellm_metadata`` on a chat request after the proxy stamped + ``litellm_received_at`` into ``metadata``. The resolved bucket must still carry the stamp, or + ``x-litellm-overhead-duration-ms`` starts at the router call and hides every pre-call cost.""" + + def test_receive_stamp_is_carried_into_litellm_metadata(self): + received_at = datetime.datetime(2026, 10, 21, 5, 0, tzinfo=datetime.timezone.utc) + kwargs = { + "litellm_params": { + "metadata": {"litellm_received_at": received_at, "user_api_key_user_id": "user-1"}, + "litellm_metadata": {"applied_guardrails": ["perf-pre"]}, + } + } + + resolved = get_litellm_metadata_from_kwargs(kwargs) + + assert resolved is kwargs["litellm_params"]["litellm_metadata"] + assert resolved["litellm_received_at"] is received_at + assert resolved["user_api_key_user_id"] == "user-1" + + def test_litellm_metadata_keeps_its_own_receive_stamp(self): + own = datetime.datetime(2026, 10, 21, 5, 0, tzinfo=datetime.timezone.utc) + other = datetime.datetime(2026, 10, 21, 5, 1, tzinfo=datetime.timezone.utc) + kwargs = { + "litellm_params": { + "metadata": {"litellm_received_at": other}, + "litellm_metadata": {"litellm_received_at": own}, + } + } + + assert get_litellm_metadata_from_kwargs(kwargs)["litellm_received_at"] is own