Merge 1dfa9d5382 into fca3d4f513

litellm/constants.py

@@ -187,9 +187,12 @@ REDACTED_TOOL_CALL_ARGUMENTS_PLACEHOLDER: Final = "{}"
 MAX_STRING_LENGTH_STDOUT_LOG: Final = get_env_int("MAX_STRING_LENGTH_STDOUT_LOG", 4096)
 MAX_BASE64_LENGTH_STDOUT_LOG: Final = get_env_int("MAX_BASE64_LENGTH_STDOUT_LOG", 4096)
 
+
 # When true, adds detailed per-phase timing breakdown headers to responses.
 # Headers: x-litellm-timing-{pre-processing,llm-api,post-processing,message-copy}-ms
-LITELLM_DETAILED_TIMING: Final = os.getenv("LITELLM_DETAILED_TIMING", "false").lower() == "true"
+def is_detailed_timing_enabled() -> bool:
+    return os.getenv("LITELLM_DETAILED_TIMING", "false").lower() == "true"
+
 
 # Model cost map validation constants
 MODEL_COST_MAP_MIN_MODEL_COUNT: Final = get_env_int(

litellm/litellm_core_utils/llm_response_utils/response_metadata.py

@@ -6,7 +6,7 @@ from typing import Final
 import httpx
 from pydantic import TypeAdapter, ValidationError
 
-from litellm.constants import LITELLM_DETAILED_TIMING
+from litellm.constants import is_detailed_timing_enabled
 from litellm.litellm_core_utils.core_helpers import get_litellm_metadata_from_kwargs, process_response_headers
 from litellm.litellm_core_utils.llm_response_utils.get_api_base import get_api_base
 from litellm.litellm_core_utils.logging_utils import LiteLLMLoggingObject
@@ -243,7 +243,7 @@ class ResponseMetadata:
         # 3. Detailed per-phase timing (opt-in via env var)
         #########################################################
         llm_api_duration_ms: Final[float | None] = logging_obj.model_call_details.get("llm_api_duration_ms")
-        if LITELLM_DETAILED_TIMING and llm_api_duration_ms is not None:
+        if is_detailed_timing_enabled() and llm_api_duration_ms is not None:
             detailed: Final[dict[str, float]] = {
                 "timing_llm_api_ms": round(llm_api_duration_ms, 4),
             }

litellm/proxy/common_request_processing.py

@@ -42,7 +42,6 @@ from litellm.constants import (
     DD_TRACER_STREAMING_CHUNK_YIELD_RESOURCE,
     DEFAULT_MAX_RECURSE_DEPTH,
     LITELLM_CLIENT_DISCONNECT_DETAIL,
-    LITELLM_DETAILED_TIMING,
     LITELLM_HTTP_STATUS_CLIENT_DISCONNECTED,
     MAX_LITELLM_CALL_ID_LENGTH,
     MAX_PAYLOAD_SIZE_FOR_DEBUG_LOG,
@@ -51,6 +50,7 @@ from litellm.constants import (
     STREAM_SSE_DATA_PREFIX,
     STREAM_SSE_KEEPALIVE_PING_BYTES,
     UNSAFE_PROXY_RESPONSE_HEADERS,
+    is_detailed_timing_enabled,
 )
 from litellm.integrations.custom_guardrail import CustomGuardrail
 from litellm.integrations.otel.runtime import phase_event
@@ -2302,7 +2302,7 @@ class ProxyBaseLLMRequestProcessing:
                     "x-litellm-timing-post-processing-ms": str(hidden_params.get("timing_post_processing_ms", None)),
                     "x-litellm-timing-message-copy-ms": str(hidden_params.get("timing_message_copy_ms", None)),
                 }
-                if LITELLM_DETAILED_TIMING
+                if is_detailed_timing_enabled()
                 else {}
             ),
             "x-litellm-fastest_response_batch_completion": (

tests/unit/litellm_core_utils/llm_response_utils/test_response_metadata.py

@@ -15,8 +15,6 @@ from unittest.mock import MagicMock
 import pytest
 
 import litellm
-import litellm.litellm_core_utils.llm_response_utils.response_metadata as response_metadata_mod
-import litellm.proxy.common_request_processing as common_request_processing_mod
 from litellm.cost_calculator import select_model_name_for_cost_calc
 from litellm.litellm_core_utils.litellm_logging import Logging
 from litellm.litellm_core_utils.llm_response_utils.response_metadata import (
@@ -459,9 +457,9 @@ class TestDetailedTiming:
         logging_obj.message_copy_duration_ms = message_copy_duration_ms
         return logging_obj
 
-    def test_detailed_timing_headers_present_when_enabled(self, monkeypatch):
+    def test_detailed_timing_headers_present_when_enabled(self, monkeypatch: pytest.MonkeyPatch) -> None:
         """When LITELLM_DETAILED_TIMING is true, detailed timing keys appear in hidden_params."""
-        monkeypatch.setattr(response_metadata_mod, "LITELLM_DETAILED_TIMING", True)
+        monkeypatch.setenv("LITELLM_DETAILED_TIMING", "true")
 
         result = ModelResponse()
         start = datetime.datetime(2025, 1, 1, 0, 0, 0)
@@ -485,8 +483,10 @@ class TestDetailedTiming:
         assert hidden.get("timing_post_processing_ms") == 10.0  # 530 - 20 - 500
 
     @pytest.mark.skipif(not hasattr(time, "tzset"), reason="switching the process timezone needs time.tzset()")
-    def test_detailed_timing_pre_processing_uses_receive_anchor(self, monkeypatch, process_timezone: str):
-        monkeypatch.setattr(response_metadata_mod, "LITELLM_DETAILED_TIMING", True)
+    def test_detailed_timing_pre_processing_uses_receive_anchor(
+        self, monkeypatch: pytest.MonkeyPatch, process_timezone: str
+    ) -> None:
+        monkeypatch.setenv("LITELLM_DETAILED_TIMING", "true")
 
         result = ModelResponse()
         received_at = datetime.datetime(2025, 1, 1, tzinfo=datetime.timezone.utc)
@@ -507,9 +507,9 @@ class TestDetailedTiming:
         assert hidden.get("timing_pre_processing_ms") == pytest.approx(200.0)
         assert hidden.get("timing_post_processing_ms") == pytest.approx(30.0)
 
-    def test_detailed_timing_absent_when_disabled(self, monkeypatch):
+    def test_detailed_timing_absent_when_disabled(self, monkeypatch: pytest.MonkeyPatch) -> None:
         """When LITELLM_DETAILED_TIMING is false, no detailed timing keys."""
-        monkeypatch.setattr(response_metadata_mod, "LITELLM_DETAILED_TIMING", False)
+        monkeypatch.setenv("LITELLM_DETAILED_TIMING", "false")
 
         result = ModelResponse()
         start = datetime.datetime(2025, 1, 1, 0, 0, 0)
@@ -524,9 +524,9 @@ class TestDetailedTiming:
         assert hidden.get("timing_llm_api_ms") is None
         assert hidden.get("timing_pre_processing_ms") is None
 
-    def test_detailed_timing_headers_in_custom_headers(self, monkeypatch):
+    def test_detailed_timing_headers_in_custom_headers(self, monkeypatch: pytest.MonkeyPatch) -> None:
         """When LITELLM_DETAILED_TIMING is true, headers flow to get_custom_headers."""
-        monkeypatch.setattr(common_request_processing_mod, "LITELLM_DETAILED_TIMING", True)
+        monkeypatch.setenv("LITELLM_DETAILED_TIMING", "true")
 
         user_api_key_dict = UserAPIKeyAuth(api_key="sk-test")
         hidden_params = {
@@ -547,9 +547,9 @@ class TestDetailedTiming:
         assert headers["x-litellm-timing-post-processing-ms"] == "10.0"
         assert headers["x-litellm-timing-message-copy-ms"] == "2.5"
 
-    def test_detailed_timing_headers_absent_when_disabled(self, monkeypatch):
+    def test_detailed_timing_headers_absent_when_disabled(self, monkeypatch: pytest.MonkeyPatch) -> None:
         """When LITELLM_DETAILED_TIMING is false, no timing headers emitted."""
-        monkeypatch.setattr(common_request_processing_mod, "LITELLM_DETAILED_TIMING", False)
+        monkeypatch.setenv("LITELLM_DETAILED_TIMING", "false")
 
         user_api_key_dict = UserAPIKeyAuth(api_key="sk-test")
         hidden_params = {

tests/unit/proxy/proxy_server/test_proxy_config.py

@@ -35,7 +35,8 @@ from pydantic import JsonValue, TypeAdapter, ValidationError
 import litellm
 from litellm._logging import turn_on_json
 from litellm.llms.custom_httpx.http_handler import HTTPHandler
-from litellm.proxy._types import CommonProxyErrors, ConfigGeneralSettings
+from litellm.proxy._types import CommonProxyErrors, ConfigGeneralSettings, UserAPIKeyAuth
+from litellm.proxy.common_request_processing import ProxyBaseLLMRequestProcessing
 from litellm.proxy.common_utils.encrypt_decrypt_utils import encrypt_value_helper
 from litellm.proxy.config_resolvers.settings_store import SettingsStore
 from litellm.router_api import ApplyResult, RouterSettings
@@ -2512,6 +2513,29 @@ def test_ProxyConfig__load_environment_variables_sets_env(monkeypatch):
     assert result == {"TEST_LOAD_ENV_X": "hello", "set": True, "len": 1}
 
 
+def test_ProxyConfig__load_environment_variables_enables_detailed_timing(
+    monkeypatch: pytest.MonkeyPatch,
+) -> None:
+    monkeypatch.setenv("LITELLM_DETAILED_TIMING", "false")
+    ProxyConfig()._load_environment_variables({"environment_variables": {"LITELLM_DETAILED_TIMING": "true"}})
+
+    headers: Final = ProxyBaseLLMRequestProcessing.get_custom_headers(
+        user_api_key_dict=UserAPIKeyAuth(api_key="sk-test"),
+        hidden_params={
+            "_response_ms": 530.0,
+            "timing_llm_api_ms": 500.0,
+            "timing_pre_processing_ms": 20.0,
+            "timing_post_processing_ms": 10.0,
+            "timing_message_copy_ms": 2.5,
+        },
+    )
+
+    assert headers["x-litellm-timing-llm-api-ms"] == "500.0"
+    assert headers["x-litellm-timing-pre-processing-ms"] == "20.0"
+    assert headers["x-litellm-timing-post-processing-ms"] == "10.0"
+    assert headers["x-litellm-timing-message-copy-ms"] == "2.5"
+
+
 def test_ProxyConfig__load_environment_variables_warns_when_the_config_replaces_a_process_value(
     monkeypatch: pytest.MonkeyPatch, caplog: pytest.LogCaptureFixture
 ):

tests/unit/proxy/rerank_endpoints/test_endpoints.py

@@ -13,7 +13,6 @@ import respx
 from fastapi import FastAPI, HTTPException, Request, Response
 from fastapi.testclient import TestClient
 
-import litellm.proxy.common_request_processing as common_request_processing_mod
 import litellm.proxy.proxy_server as proxy_server_mod
 from litellm._logging import verbose_proxy_logger
 from litellm.proxy._types import ProxyException, UserAPIKeyAuth
@@ -99,10 +98,10 @@ async def test_rerank_emits_latency_and_cost_headers():
 
 
 @pytest.mark.asyncio
-async def test_rerank_emits_detailed_timing_headers_when_enabled():
+async def test_rerank_emits_detailed_timing_headers_when_enabled(monkeypatch: pytest.MonkeyPatch) -> None:
     """LITELLM_DETAILED_TIMING must also work on /rerank, not just /chat/completions."""
-    with patch.object(common_request_processing_mod, "LITELLM_DETAILED_TIMING", True):  # test-quality-ok: LITELLM_DETAILED_TIMING is a module constant; toggling it is the behavior under test
-        fastapi_response = await _call_rerank()
+    monkeypatch.setenv("LITELLM_DETAILED_TIMING", "true")
+    fastapi_response = await _call_rerank()
 
     assert fastapi_response.headers["x-litellm-timing-llm-api-ms"] == "1488.0"
     assert fastapi_response.headers["x-litellm-timing-pre-processing-ms"] == "10.0"
@@ -119,9 +118,9 @@ async def test_rerank_emits_zero_response_cost_header():
 
 
 @pytest.mark.asyncio
-async def test_rerank_omits_detailed_timing_headers_when_disabled():
-    with patch.object(common_request_processing_mod, "LITELLM_DETAILED_TIMING", False):  # test-quality-ok: LITELLM_DETAILED_TIMING is a module constant; toggling it is the behavior under test
-        fastapi_response = await _call_rerank()
+async def test_rerank_omits_detailed_timing_headers_when_disabled(monkeypatch: pytest.MonkeyPatch) -> None:
+    monkeypatch.setenv("LITELLM_DETAILED_TIMING", "false")
+    fastapi_response = await _call_rerank()
 
     assert "x-litellm-timing-llm-api-ms" not in fastapi_response.headers