From a1560936f794a8bcd394ea02cfa0c8f9ab01ab10 Mon Sep 17 00:00:00 2001 From: kerry Date: Sat, 19 Sep 2026 01:06:53 +0000 Subject: [PATCH] fix(timing): use epoch math for detailed pre-processing and drop client-supplied timing windows Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com> --- .../llm_response_utils/response_metadata.py | 2 +- litellm/proxy/litellm_pre_call_utils.py | 1 + .../test_response_metadata.py | 7 +++-- .../proxy/test_litellm_pre_call_utils.py | 30 +++++++++++++++++++ 4 files changed, 36 insertions(+), 4 deletions(-) diff --git a/litellm/litellm_core_utils/llm_response_utils/response_metadata.py b/litellm/litellm_core_utils/llm_response_utils/response_metadata.py index cc0d10ee7a6..93701b3c1e7 100644 --- a/litellm/litellm_core_utils/llm_response_utils/response_metadata.py +++ b/litellm/litellm_core_utils/llm_response_utils/response_metadata.py @@ -205,7 +205,7 @@ class ResponseMetadata: api_call_start: Final[datetime.datetime | None] = logging_obj.model_call_details.get("api_call_start_time") if api_call_start is not None and start_time is not None: anchor: Final = _timing_window_start(start_time, logging_obj)[0] - pre_ms: Final = (api_call_start - anchor).total_seconds() * 1000 + pre_ms: Final = (api_call_start.timestamp() - anchor.timestamp()) * 1000 detailed["timing_pre_processing_ms"] = round(pre_ms, 4) # post-processing = total - pre - llm_api diff --git a/litellm/proxy/litellm_pre_call_utils.py b/litellm/proxy/litellm_pre_call_utils.py index b03f1e4348c..9a973755894 100644 --- a/litellm/proxy/litellm_pre_call_utils.py +++ b/litellm/proxy/litellm_pre_call_utils.py @@ -2367,6 +2367,7 @@ async def add_litellm_data_to_request( # OTel layer can compute pre-request latency, including on the failure # path after the logging object is popped. data[_metadata_variable_name]["litellm_received_at"] = getattr(request.state, "litellm_received_at", None) + data[_metadata_variable_name]["llm_api_timing_windows"] = () # OTEL Controls / Tracing # Add the OTEL Parent Trace before sending it LiteLLM diff --git a/tests/test_litellm/litellm_core_utils/llm_response_utils/test_response_metadata.py b/tests/test_litellm/litellm_core_utils/llm_response_utils/test_response_metadata.py index 97c154db783..3379879a8a6 100644 --- a/tests/test_litellm/litellm_core_utils/llm_response_utils/test_response_metadata.py +++ b/tests/test_litellm/litellm_core_utils/llm_response_utils/test_response_metadata.py @@ -474,12 +474,13 @@ class TestDetailedTiming: monkeypatch.setattr(response_metadata_mod, "LITELLM_DETAILED_TIMING", True) result = ModelResponse() - start = datetime.datetime(2025, 1, 1, 0, 0, 0) - received_at = start - datetime.timedelta(milliseconds=200) + received_at = datetime.datetime.now(datetime.timezone.utc) + start = received_at + datetime.timedelta(milliseconds=200) + api_call_start = start.replace(tzinfo=None) end = start + datetime.timedelta(milliseconds=530) logging_obj = self._make_logging_obj( llm_api_duration_ms=500.0, - api_call_start_time=start, + api_call_start_time=api_call_start, ) logging_obj.model_call_details["litellm_params"] = {"metadata": {"litellm_received_at": received_at}} diff --git a/tests/test_litellm/proxy/test_litellm_pre_call_utils.py b/tests/test_litellm/proxy/test_litellm_pre_call_utils.py index f4490519554..88d38d74f49 100644 --- a/tests/test_litellm/proxy/test_litellm_pre_call_utils.py +++ b/tests/test_litellm/proxy/test_litellm_pre_call_utils.py @@ -333,6 +333,36 @@ async def test_arrival_time_prefers_litellm_received_at_over_time_time(): assert updated_data["proxy_server_request"]["arrival_time"] == received_at.timestamp() +@pytest.mark.asyncio +async def test_proxy_clears_client_supplied_timing_windows(): + request_mock = MagicMock(spec=Request) + request_mock.url = MagicMock() + request_mock.url.path = "/v1/chat/completions" + request_mock.url.__str__.return_value = "http://localhost/v1/chat/completions" + request_mock.method = "POST" + request_mock.query_params = {} + request_mock.headers = {"Content-Type": "application/json"} + request_mock.client = MagicMock() + request_mock.client.host = "127.0.0.1" + request_mock.state = SimpleNamespace(litellm_received_at=datetime.now(timezone.utc)) + + user_api_key_dict = UserAPIKeyAuth(api_key="hashed-key", metadata={}, team_metadata={}) + + updated_data = await add_litellm_data_to_request( + data={ + "model": "gpt-3.5-turbo", + "metadata": {"llm_api_timing_windows": ((0.0, 1.0),)}, + }, + request=request_mock, + user_api_key_dict=user_api_key_dict, + proxy_config=MagicMock(), + general_settings={}, + version="test-version", + ) + + assert updated_data["metadata"]["llm_api_timing_windows"] == () + + @pytest.mark.asyncio async def test_arrival_time_falls_back_to_time_time_without_litellm_received_at(): """Callers that never went through user_api_key_auth (no stamp on request.state)