Merge remote-tracking branch 'origin/litellm_internal_staging' into litellm_fix_realtime_cached_audio_billing

litellm/litellm_core_utils/litellm_logging.py

@@ -547,6 +547,9 @@ class Logging(LiteLLMLoggingBaseClass):
 
         # Init Caching related details
         self.caching_details: CachingDetails | None = None
+        # Timing for results that cannot carry ``_hidden_params`` (plain-dict /v1/messages
+        # responses and the bridge stream wrappers); see ``update_response_metadata``.
+        self.response_timing_metrics: Mapping[str, float] = {}  # mutable-ok: kept deep-copyable
 
         # Passthrough endpoint guardrails config for field targeting
         self.passthrough_guardrails_config: dict[str, Any] | None = None
@@ -566,6 +569,10 @@ class Logging(LiteLLMLoggingBaseClass):
         self._defer_async_logging: bool = False
         self._enqueue_deferred_logging: Callable[[], None] | None = None
 
+    def set_response_timing_metrics(self, timing_metrics: Mapping[str, float]) -> None:
+        """Keep ``_response_ms`` / ``litellm_overhead_time_ms`` for a result that has no ``_hidden_params``."""
+        self.response_timing_metrics = dict(timing_metrics)  # mutable-ok: kept deep-copyable
+
     def process_dynamic_callbacks(self):
         """
         Initializes CustomLogger compatible callbacks in self.dynamic_* callbacks
@@ -6005,6 +6012,13 @@ def get_standard_logging_object_payload(
         clean_hidden_params: Final = StandardLoggingPayloadSetup.get_hidden_params(hidden_params)
         if clean_hidden_params["response_cost"] is None and raw_response_cost is not None:
             clean_hidden_params["response_cost"] = llm_response_cost
+        if clean_hidden_params["litellm_overhead_time_ms"] is None and status == "success":
+            # /v1/messages dict results and the bridge stream wrappers keep it on the logging object;
+            # failure payloads stay None like every response type that carries its own _hidden_params
+            timing_metrics: Final = (
+                getattr(logging_obj, "response_timing_metrics", None) or {}  # mutable-ok: empty fallback
+            )
+            clean_hidden_params["litellm_overhead_time_ms"] = timing_metrics.get("litellm_overhead_time_ms")
 
         model_cost_information: Final = StandardLoggingPayloadSetup.get_model_cost_information(
             base_model=base_model,

litellm/litellm_core_utils/llm_response_utils/response_metadata.py

@@ -1,4 +1,5 @@
 import datetime
+from collections.abc import Mapping
 from typing import Any, Final
 
 from litellm.constants import LITELLM_DETAILED_TIMING
@@ -13,6 +14,39 @@ from litellm.types.utils import (
 )
 
 
+def response_timing_metrics(
+    start_time: datetime.datetime,
+    end_time: datetime.datetime,
+    logging_obj: LiteLLMLoggingObject,
+    include_overhead: bool = True,
+) -> Mapping[str, float]:
+    """``_response_ms`` for the whole call, plus ``litellm_overhead_time_ms`` when it can be derived.
+
+    On a cache hit the overhead is the total minus the cache read; otherwise it is the total minus
+    the provider call (``llm_api_duration_ms``). It is omitted when neither duration was recorded,
+    and when ``include_overhead`` is False because the two durations cover different windows.
+    """
+    total_response_time_ms: Final = (end_time - start_time).total_seconds() * 1000
+    if not include_overhead:
+        return {"_response_ms": total_response_time_ms}  # mutable-ok: read-only timing result
+    caching_details: Final = logging_obj.caching_details
+    cache_duration_ms: Final = (
+        caching_details.get("cache_duration_ms")
+        if caching_details is not None and caching_details.get("cache_hit") is True
+        else None
+    )
+    llm_api_duration_ms: Final = logging_obj.model_call_details.get("llm_api_duration_ms")
+    if cache_duration_ms is not None:
+        overhead_ms: float | None = total_response_time_ms - cache_duration_ms
+    elif llm_api_duration_ms is not None:
+        overhead_ms = round(total_response_time_ms - llm_api_duration_ms, 4)
+    else:
+        overhead_ms = None
+    if overhead_ms is None:
+        return {"_response_ms": total_response_time_ms}
+    return {"_response_ms": total_response_time_ms, "litellm_overhead_time_ms": overhead_ms}
+
+
 class ResponseMetadata:
     """
     Handles setting and managing `_hidden_params`, `response_time_ms`, and `litellm_overhead_time_ms` for LiteLLM responses
@@ -52,7 +86,7 @@ class ResponseMetadata:
         }
         self._update_hidden_params(new_params)
 
-    def _update_hidden_params(self, new_params: dict) -> None:
+    def _update_hidden_params(self, new_params: Mapping[str, object]) -> None:
         """
         Update hidden params - handles when self._hidden_params is a dict or HiddenParams object
         """
@@ -76,37 +110,24 @@ class ResponseMetadata:
         start_time: datetime.datetime,
         end_time: datetime.datetime,
         logging_obj: LiteLLMLoggingObject,
+        include_overhead: bool = True,
     ) -> None:
         """Set response timing metrics"""
-        total_response_time_ms: Final = (end_time - start_time).total_seconds() * 1000
+        timing_metrics: Final = response_timing_metrics(start_time, end_time, logging_obj, include_overhead)
+        total_response_time_ms: Final = timing_metrics["_response_ms"]
 
         # Set total response time if supported
         if self.supports_response_time:
             self.result._response_ms = total_response_time_ms
 
         #########################################################
-        # 1. Add _response_ms total duration
+        # 1. Add _response_ms total duration and the LiteLLM overhead within it
+        #    (total minus the cache read on a cache hit, else total minus the provider call)
         #########################################################
-        self._update_hidden_params(
-            {
-                "_response_ms": total_response_time_ms,
-            }
-        )
+        self._update_hidden_params(timing_metrics)
 
         #########################################################
-        # 2. Add LiteLLM overhead duration
-        #########################################################
-        llm_api_duration_ms: Final = logging_obj.model_call_details.get("llm_api_duration_ms")
-        if llm_api_duration_ms is not None:
-            overhead_ms = round(total_response_time_ms - llm_api_duration_ms, 4)
-            self._update_hidden_params(
-                {
-                    "litellm_overhead_time_ms": overhead_ms,
-                }
-            )
-
-        #########################################################
-        # 3. Add callback processing duration
+        # 2. Add callback processing duration
         #########################################################
         callback_duration_ms: Final = getattr(logging_obj, "callback_duration_ms", None)
         if callback_duration_ms is not None:
@@ -117,24 +138,9 @@ class ResponseMetadata:
             )
 
         #########################################################
-        # 4. Add duration for reading from cache
-        # In this case overhead from litellm is the difference between the cache read duration and the total response time
-        #########################################################
-        if (
-            logging_obj.caching_details is not None
-            and logging_obj.caching_details.get("cache_hit") is True
-            and (cache_duration_ms := logging_obj.caching_details.get("cache_duration_ms")) is not None
-        ):
-            overhead_ms = total_response_time_ms - cache_duration_ms
-            self._update_hidden_params(
-                {
-                    "litellm_overhead_time_ms": overhead_ms,
-                }
-            )
-
-        #########################################################
-        # 5. Detailed per-phase timing (opt-in via env var)
+        # 3. Detailed per-phase timing (opt-in via env var)
         #########################################################
+        llm_api_duration_ms: Final = logging_obj.model_call_details.get("llm_api_duration_ms")
         if LITELLM_DETAILED_TIMING and llm_api_duration_ms is not None:
             detailed: Final[dict] = {
                 "timing_llm_api_ms": round(llm_api_duration_ms, 4),
@@ -170,6 +176,7 @@ def update_response_metadata(
     kwargs: dict,
     start_time: datetime.datetime,
     end_time: datetime.datetime,
+    include_overhead: bool = True,
 ) -> None:
     """
     Updates response metadata including hidden params and timing metrics
@@ -177,11 +184,22 @@ def update_response_metadata(
         - response._hidden_params
         - response._hidden_params["litellm_overhead_time_ms"]
         - response.response_time_ms
+    A result that cannot hold ``_hidden_params`` gets its timing on ``logging_obj`` instead.
+    Callers whose ``end_time`` covers more than the recorded provider call (a stream read to
+    completion) pass ``include_overhead=False``, since the overhead cannot be derived there.
     """
-    if result is None or not hasattr(result, "_hidden_params"):
+    if result is None:
+        return
+    if not hasattr(result, "_hidden_params"):
+        # /v1/messages returns a plain dict and the Anthropic / Responses bridge stream wrappers
+        # cannot hold ``_hidden_params``: keep only the timing on the logging object (no cost
+        # recompute) so the proxy headers and the standard logging payload can still read it.
+        logging_obj.set_response_timing_metrics(
+            response_timing_metrics(start_time, end_time, logging_obj, include_overhead)
+        )
         return
 
     metadata: Final = ResponseMetadata(result)
     metadata.set_hidden_params(logging_obj, model, kwargs)
-    metadata.set_timing_metrics(start_time, end_time, logging_obj)
+    metadata.set_timing_metrics(start_time, end_time, logging_obj, include_overhead)
     metadata.apply()

litellm/llms/custom_httpx/llm_http_handler.py

@@ -2872,6 +2872,7 @@ class BaseLLMHTTPHandler:
                     headers=headers,
                     timeout=timeout or float(response_api_optional_request_params.get("timeout", 0)),
                     stream=stream,
+                    logging_obj=logging_obj,
                     **body_kwargs,
                 )
 
@@ -2903,6 +2904,7 @@ class BaseLLMHTTPHandler:
                     url=api_base,
                     headers=headers,
                     timeout=timeout or float(response_api_optional_request_params.get("timeout", 0)),
+                    logging_obj=logging_obj,
                     **body_kwargs,
                 )
 

litellm/proxy/common_request_processing.py

@@ -1475,6 +1475,22 @@ async def _await_llm_call_cancelling_on_disconnect(
         monitor.cancel()
 
 
+def _timing_values(
+    *,
+    hidden_params: Mapping[str, object],
+    logging_obj: LiteLLMLoggingObj | None,
+    use_logging_obj: bool,
+) -> Mapping[str, object]:
+    """Both timing values from one source, so the two headers always describe the same window.
+
+    /v1/messages returns a plain dict and the Anthropic / Responses bridge stream wrappers carry no
+    ``_hidden_params``, so ``update_response_metadata`` leaves their timing on the logging object.
+    """
+    if hidden_params.get("_response_ms") is not None or not use_logging_obj or logging_obj is None:
+        return hidden_params
+    return getattr(logging_obj, "response_timing_metrics", None) or {}  # mutable-ok: empty fallback
+
+
 class ProxyBaseLLMRequestProcessing:
     def __init__(self, data: dict):
         self.data = data
@@ -1495,10 +1511,16 @@ class ProxyBaseLLMRequestProcessing:
         request_data: dict | None = {},
         timeout: float | httpx.Timeout | None = None,
         litellm_logging_obj: LiteLLMLoggingObj | None = None,
+        read_timing_from_logging_obj: bool = True,
         **kwargs,
     ) -> dict:
         exclude_values: Final = {"", None, "None"}
         hidden_params = hidden_params or {}
+        timing_values: Final = _timing_values(
+            hidden_params=hidden_params,
+            logging_obj=litellm_logging_obj,
+            use_logging_obj=read_timing_from_logging_obj,
+        )
 
         cost_breakdown: Final = _get_cost_breakdown_from_logging_obj(
             litellm_logging_obj=litellm_logging_obj, response_cost=response_cost
@@ -1566,8 +1588,8 @@ class ProxyBaseLLMRequestProcessing:
             "x-litellm-key-rpm-limit": str(user_api_key_dict.rpm_limit),
             "x-litellm-key-max-budget": str(user_api_key_dict.max_budget),
             "x-litellm-key-spend": str(updated_spend),
-            "x-litellm-response-duration-ms": str(hidden_params.get("_response_ms", None)),
-            "x-litellm-overhead-duration-ms": str(hidden_params.get("litellm_overhead_time_ms", None)),
+            "x-litellm-response-duration-ms": str(timing_values.get("_response_ms")),
+            "x-litellm-overhead-duration-ms": str(timing_values.get("litellm_overhead_time_ms")),
             "x-litellm-callback-duration-ms": str(hidden_params.get("callback_duration_ms", None)),
             **(
                 {
@@ -3224,6 +3246,8 @@ class ProxyBaseLLMRequestProcessing:
             request_data=self.data,
             timeout=timeout,
             litellm_logging_obj=_litellm_logging_obj,
+            # a failed request reports no timing, matching /v1/chat/completions
+            read_timing_from_logging_obj=False,
         )
         # Extract headers from exception - check both e.headers and e.response.headers
         headers = getattr(e, "headers", None) or {}

litellm/responses/streaming_iterator.py

@@ -681,6 +681,8 @@ class BaseResponsesAPIStreamingIterator:
                 kwargs=request_payload,
                 start_time=self.start_time,
                 end_time=end_time,
+                # the provider call was timed to first byte, so the whole stream minus it is not overhead
+                include_overhead=False,
             )
         except Exception:
             # Non-blocking

tests/test_litellm/litellm_core_utils/llm_response_utils/test_response_metadata.py

@@ -5,6 +5,7 @@ Covers the callback_duration_ms timing metric that flows from the Logging object
 through _hidden_params to the x-litellm-callback-duration-ms response header.
 """
 
+import asyncio
 import datetime
 from unittest.mock import MagicMock
 
@@ -13,6 +14,7 @@ import litellm.proxy.common_request_processing as common_request_processing_mod
 from litellm.litellm_core_utils.litellm_logging import Logging
 from litellm.litellm_core_utils.llm_response_utils.response_metadata import (
     ResponseMetadata,
+    response_timing_metrics,
     update_response_metadata,
 )
 from litellm.proxy._types import UserAPIKeyAuth
@@ -124,6 +126,158 @@ class TestDictResultsSkipMetadataUpdate:
         logging_obj._response_cost_calculator.assert_not_called()
         assert "_hidden_params" not in anthropic_response
 
+    def test_update_response_metadata_keeps_timing_on_logging_obj_for_dict_results(self):
+        """LIT-5466: the /v1/messages dict cannot carry _hidden_params, so its timing
+        (the input to x-litellm-overhead-duration-ms and the SLP litellm_overhead_time_ms)
+        lands on the logging object instead - still without recomputing cost."""
+        anthropic_response = {"id": "msg_123", "type": "message", "role": "assistant", "content": []}
+        logging_obj = MagicMock()
+        logging_obj.model_call_details = {"llm_api_duration_ms": 900.0}
+        logging_obj.caching_details = None
+
+        update_response_metadata(
+            result=anthropic_response,
+            logging_obj=logging_obj,
+            model="openai/gpt-4o-mini",
+            kwargs={},
+            start_time=datetime.datetime(2025, 1, 1, 0, 0, 0),
+            end_time=datetime.datetime(2025, 1, 1, 0, 0, 1),
+        )
+
+        logging_obj.set_response_timing_metrics.assert_called_once_with(
+            {"_response_ms": 1000.0, "litellm_overhead_time_ms": 100.0}
+        )
+        logging_obj._response_cost_calculator.assert_not_called()
+        assert "_hidden_params" not in anthropic_response
+
+    def test_update_response_metadata_keeps_timing_for_stream_wrapper_without_hidden_params(self):
+        """The /v1/messages bridge streams a bare async generator, which cannot hold
+        _hidden_params either; when the provider duration is unknown only the total is kept."""
+
+        async def sse_stream():
+            yield b"event: message_start\n\n"
+
+        logging_obj = MagicMock()
+        logging_obj.model_call_details = {}
+        logging_obj.caching_details = None
+
+        async def drive():
+            stream = sse_stream()
+            try:
+                update_response_metadata(
+                    result=stream,
+                    logging_obj=logging_obj,
+                    model="openai/gpt-4o-mini",
+                    kwargs={},
+                    start_time=datetime.datetime(2025, 1, 1, 0, 0, 0),
+                    end_time=datetime.datetime(2025, 1, 1, 0, 0, 0, 250000),
+                )
+            finally:
+                await stream.aclose()
+
+        asyncio.run(drive())
+
+        logging_obj.set_response_timing_metrics.assert_called_once_with({"_response_ms": 250.0})
+        logging_obj._response_cost_calculator.assert_not_called()
+
+    def test_update_response_metadata_leaves_logging_obj_alone_for_objects_with_hidden_params(self):
+        """ModelResponse keeps carrying its own timing; the logging-object carrier is not written."""
+        result = ModelResponse()
+        logging_obj = MagicMock()
+        logging_obj.model_call_details = {"llm_api_duration_ms": 900.0}
+        logging_obj.caching_details = None
+        logging_obj._response_cost_calculator = MagicMock(return_value=0.001)
+        logging_obj.litellm_call_id = "test-call-id"
+
+        update_response_metadata(
+            result=result,
+            logging_obj=logging_obj,
+            model="gpt-4",
+            kwargs={},
+            start_time=datetime.datetime(2025, 1, 1, 0, 0, 0),
+            end_time=datetime.datetime(2025, 1, 1, 0, 0, 1),
+        )
+
+        logging_obj.set_response_timing_metrics.assert_not_called()
+        assert result._hidden_params["litellm_overhead_time_ms"] == 100.0
+
+    def test_update_response_metadata_omits_overhead_for_completed_stream(self):
+        """LIT-5466: the Responses streaming iterator finishes the whole stream before updating
+        metadata, and the provider call it recorded stopped at the first byte."""
+        result = ModelResponse()
+        logging_obj = MagicMock()
+        logging_obj.model_call_details = {"llm_api_duration_ms": 200.0}
+        logging_obj.caching_details = None
+        logging_obj._response_cost_calculator = MagicMock(return_value=0.001)
+        logging_obj.litellm_call_id = "test-call-id"
+
+        update_response_metadata(
+            result=result,
+            logging_obj=logging_obj,
+            model="gpt-4",
+            kwargs={},
+            start_time=datetime.datetime(2025, 1, 1, 0, 0, 0),
+            end_time=datetime.datetime(2025, 1, 1, 0, 0, 1),
+            include_overhead=False,
+        )
+
+        assert result._hidden_params["_response_ms"] == 1000.0
+        assert "litellm_overhead_time_ms" not in result._hidden_params
+
+
+class TestResponseTimingMetrics:
+    """response_timing_metrics() is the single source of _response_ms / litellm_overhead_time_ms."""
+
+    START = datetime.datetime(2025, 1, 1, 0, 0, 0)
+    END = datetime.datetime(2025, 1, 1, 0, 0, 1)
+
+    def _make_logging_obj(self, llm_api_duration_ms=None, caching_details=None):
+        logging_obj = MagicMock()
+        logging_obj.model_call_details = {}
+        if llm_api_duration_ms is not None:
+            logging_obj.model_call_details["llm_api_duration_ms"] = llm_api_duration_ms
+        logging_obj.caching_details = caching_details
+        return logging_obj
+
+    def test_overhead_is_total_minus_provider_call(self):
+        logging_obj = self._make_logging_obj(llm_api_duration_ms=900.0)
+        assert response_timing_metrics(self.START, self.END, logging_obj) == {
+            "_response_ms": 1000.0,
+            "litellm_overhead_time_ms": 100.0,
+        }
+
+    def test_overhead_omitted_when_no_provider_or_cache_duration_recorded(self):
+        logging_obj = self._make_logging_obj()
+        assert response_timing_metrics(self.START, self.END, logging_obj) == {"_response_ms": 1000.0}
+
+    def test_cache_hit_overhead_is_total_minus_cache_read(self):
+        logging_obj = self._make_logging_obj(
+            llm_api_duration_ms=900.0, caching_details={"cache_hit": True, "cache_duration_ms": 250.0}
+        )
+        assert response_timing_metrics(self.START, self.END, logging_obj) == {
+            "_response_ms": 1000.0,
+            "litellm_overhead_time_ms": 750.0,
+        }
+
+    def test_cache_miss_ignores_cache_duration(self):
+        logging_obj = self._make_logging_obj(caching_details={"cache_hit": False, "cache_duration_ms": 250.0})
+        assert response_timing_metrics(self.START, self.END, logging_obj) == {"_response_ms": 1000.0}
+
+    def test_cache_hit_without_recorded_cache_duration_falls_back_to_provider_call(self):
+        logging_obj = self._make_logging_obj(llm_api_duration_ms=900.0, caching_details={"cache_hit": True})
+        assert response_timing_metrics(self.START, self.END, logging_obj) == {
+            "_response_ms": 1000.0,
+            "litellm_overhead_time_ms": 100.0,
+        }
+
+    def test_overhead_omitted_when_caller_measured_a_wider_window(self):
+        """A stream read to completion times the provider call to first byte, so the rest of the
+        stream is token generation, not LiteLLM overhead."""
+        logging_obj = self._make_logging_obj(llm_api_duration_ms=200.0)
+        assert response_timing_metrics(self.START, self.END, logging_obj, include_overhead=False) == {
+            "_response_ms": 1000.0
+        }
+
 
 class TestCallbackDurationInCustomHeaders:
     """Test that callback_duration_ms flows into get_custom_headers."""

tests/test_litellm/litellm_core_utils/test_litellm_logging.py

@@ -5994,3 +5994,110 @@ async def test_prompt_hook_injection_marker_recorded_for_every_surface(logging_o
         request_kwargs=untouched,
     )
     assert "litellm_gateway_injected_cache" not in untouched["metadata"]
+
+
+def test_get_standard_logging_object_payload_reads_overhead_from_logging_obj_for_dict_results(logging_obj):
+    """LIT-5466: /v1/messages returns a plain dict with no _hidden_params, so the overhead
+    recorded on the logging object must reach hidden_params.litellm_overhead_time_ms (SpendLogs)."""
+    import datetime
+
+    from litellm.litellm_core_utils.litellm_logging import (
+        get_standard_logging_object_payload,
+    )
+
+    logging_obj.set_response_timing_metrics({"_response_ms": 1000.0, "litellm_overhead_time_ms": 100.0})
+    now = datetime.datetime.now()
+    payload = get_standard_logging_object_payload(
+        kwargs={"litellm_call_id": "call-1", "model": "gpt-4o", "messages": []},
+        init_response_obj={"id": "msg_1", "type": "message", "role": "assistant", "content": []},
+        start_time=now,
+        end_time=now,
+        logging_obj=logging_obj,
+        status="success",
+    )
+
+    assert payload is not None
+    assert payload["hidden_params"]["litellm_overhead_time_ms"] == 100.0
+
+
+def test_get_standard_logging_object_payload_survives_logging_obj_without_timing_metrics(logging_obj):
+    """The payload is built inside a blanket except that returns None, so a logging object without
+    the timing carrier (custom subclasses, older pickles) must not silently drop every spend log."""
+    import datetime
+
+    from litellm.litellm_core_utils.litellm_logging import (
+        get_standard_logging_object_payload,
+    )
+
+    del logging_obj.response_timing_metrics
+    now = datetime.datetime.now()
+    payload = get_standard_logging_object_payload(
+        kwargs={"litellm_call_id": "call-1", "model": "gpt-4o", "messages": []},
+        init_response_obj={"id": "msg_1", "type": "message", "role": "assistant", "content": []},
+        start_time=now,
+        end_time=now,
+        logging_obj=logging_obj,
+        status="success",
+    )
+
+    assert payload is not None
+    assert payload["hidden_params"]["litellm_overhead_time_ms"] is None
+
+
+def test_get_standard_logging_object_payload_failure_status_keeps_overhead_none(logging_obj):
+    """A post_call guardrail can fail the request after the upstream call succeeded; the failure
+    payload keeps litellm_overhead_time_ms None, matching responses that carry their own _hidden_params."""
+    import datetime
+
+    from litellm.litellm_core_utils.litellm_logging import (
+        get_standard_logging_object_payload,
+    )
+
+    logging_obj.set_response_timing_metrics({"_response_ms": 1000.0, "litellm_overhead_time_ms": 100.0})
+    now = datetime.datetime.now()
+    payload = get_standard_logging_object_payload(
+        kwargs={"litellm_call_id": "call-1", "model": "gpt-4o", "messages": []},
+        init_response_obj={},
+        start_time=now,
+        end_time=now,
+        logging_obj=logging_obj,
+        status="failure",
+    )
+
+    assert payload is not None
+    assert payload["hidden_params"]["litellm_overhead_time_ms"] is None
+
+
+def test_get_standard_logging_object_payload_prefers_response_hidden_params_overhead(logging_obj):
+    """A response that carries its own litellm_overhead_time_ms (chat completions) wins over the logging object."""
+    import datetime
+
+    from litellm.litellm_core_utils.litellm_logging import (
+        get_standard_logging_object_payload,
+    )
+
+    logging_obj.set_response_timing_metrics({"_response_ms": 1000.0, "litellm_overhead_time_ms": 100.0})
+    response = ModelResponse()
+    response._hidden_params = {"litellm_overhead_time_ms": 5.0}
+    now = datetime.datetime.now()
+    payload = get_standard_logging_object_payload(
+        kwargs={"litellm_call_id": "call-1", "model": "gpt-4o", "messages": []},
+        init_response_obj=response,
+        start_time=now,
+        end_time=now,
+        logging_obj=logging_obj,
+        status="success",
+    )
+
+    assert payload is not None
+    assert payload["hidden_params"]["litellm_overhead_time_ms"] == 5.0
+
+
+def test_response_timing_metrics_survive_deepcopy(logging_obj):
+    """Proxy pre-call hooks deep-copy the logging object; the timing carrier must stay copyable."""
+    import copy
+
+    assert logging_obj.response_timing_metrics == {}
+    logging_obj.set_response_timing_metrics({"_response_ms": 12.5})
+
+    assert copy.deepcopy(logging_obj).response_timing_metrics == {"_response_ms": 12.5}

tests/test_litellm/llms/custom_httpx/test_llm_http_handler.py

@@ -271,6 +271,85 @@ async def test_async_response_api_handler_streams_when_provider_transform_adds_s
     assert client.post.call_args.kwargs["json"]["stream"] is True
 
 
+@pytest.mark.asyncio
+async def test_async_response_api_handler_streaming_passes_logging_obj_to_post():
+    """LIT-5466: @track_llm_api_timing only records llm_api_duration_ms when the POST
+    receives logging_obj; without it streaming /v1/responses never gets
+    x-litellm-overhead-duration-ms (the non-streaming site is pinned by
+    test_async_responses_records_llm_api_duration below)."""
+    handler = BaseLLMHTTPHandler()
+    config = Mock()
+    config.validate_environment.return_value = {}
+    config.get_complete_url.return_value = "https://chatgpt.example.com/responses"
+    config.transform_responses_api_request.return_value = {"model": "gpt-5", "input": "hi", "stream": True}
+    config.sign_request.return_value = ({}, None)
+    client = AsyncHTTPHandler()
+    client.post = AsyncMock(
+        return_value=httpx.Response(
+            200,
+            request=httpx.Request("POST", "https://chatgpt.example.com/responses"),
+        )
+    )
+    logging_obj = Mock()
+
+    await handler.async_response_api_handler(
+        model="gpt-5",
+        input="hi",
+        responses_api_provider_config=config,
+        response_api_optional_request_params={},
+        custom_llm_provider="chatgpt",
+        litellm_params=GenericLiteLLMParams(),
+        logging_obj=logging_obj,
+        client=client,
+    )
+
+    assert client.post.call_args.kwargs["logging_obj"] is logging_obj
+
+
+@pytest.mark.asyncio
+async def test_async_responses_records_llm_api_duration():
+    """aresponses must feed the httpx timing into the logging obj, so the proxy can emit
+    x-litellm-overhead-duration-ms on /v1/responses (mirrors the arerank regression test)."""
+
+    def handle(request: httpx.Request) -> httpx.Response:
+        return httpx.Response(
+            200,
+            json={
+                "id": "resp_1",
+                "object": "response",
+                "created_at": 1,
+                "model": "gpt-4o-mini",
+                "status": "completed",
+                "output": [
+                    {
+                        "type": "message",
+                        "id": "msg_1",
+                        "status": "completed",
+                        "role": "assistant",
+                        "content": [{"type": "output_text", "text": "pong", "annotations": []}],
+                    }
+                ],
+                "usage": {"input_tokens": 1, "output_tokens": 1, "total_tokens": 2},
+                "parallel_tool_calls": True,
+                "tool_choice": "auto",
+                "tools": [],
+            },
+        )
+
+    client = AsyncHTTPHandler()
+    client.client = httpx.AsyncClient(transport=httpx.MockTransport(handle))
+
+    response = await litellm.aresponses(
+        model="openai/gpt-4o-mini",
+        input="ping",
+        api_key="fake-key",
+        client=client,
+    )
+
+    assert response._hidden_params["litellm_overhead_time_ms"] is not None
+    assert response._hidden_params["_response_ms"] >= response._hidden_params["litellm_overhead_time_ms"]
+
+
 def test_get_agentic_loop_settings_defaults_and_overrides():
     handler = BaseLLMHTTPHandler()
 

tests/test_litellm/proxy/test_common_request_processing.py

@@ -2549,6 +2549,152 @@ class TestStreamingOverheadHeader:
         assert "x-litellm-overhead-duration-ms" in headers
         assert headers["x-litellm-overhead-duration-ms"] == "42.5"
 
+    @staticmethod
+    def _timing_logging_obj(timing_metrics):
+        from litellm.litellm_core_utils.litellm_logging import Logging as LiteLLMLoggingObj
+
+        logging_obj = LiteLLMLoggingObj(
+            model="openai/gpt-4o-mini",
+            messages=[{"role": "user", "content": "hi"}],
+            stream=True,
+            call_type="anthropic_messages",
+            start_time=None,
+            litellm_call_id="test-call-id",
+            function_id="test-function-id",
+        )
+        logging_obj.set_response_timing_metrics(timing_metrics)
+        return logging_obj
+
+    def test_get_custom_headers_reads_timing_from_logging_obj_when_response_has_no_hidden_params(self):
+        """
+        LIT-5466: /v1/messages results and the bridge stream wrappers carry no
+        _hidden_params, so the timing headers come from the logging object.
+        """
+        mock_user_api_key_dict = MagicMock(spec=UserAPIKeyAuth)
+        mock_user_api_key_dict.tpm_limit = None
+        mock_user_api_key_dict.rpm_limit = None
+        mock_user_api_key_dict.max_budget = None
+        mock_user_api_key_dict.spend = 0.0
+        mock_user_api_key_dict.allowed_model_region = None
+
+        headers = ProxyBaseLLMRequestProcessing.get_custom_headers(
+            user_api_key_dict=mock_user_api_key_dict,
+            call_id="test-call-id",
+            hidden_params={},
+            litellm_logging_obj=self._timing_logging_obj(
+                {"_response_ms": 500.0, "litellm_overhead_time_ms": 42.5}
+            ),
+        )
+
+        assert headers["x-litellm-response-duration-ms"] == "500.0"
+        assert headers["x-litellm-overhead-duration-ms"] == "42.5"
+
+    def test_get_custom_headers_skips_logging_obj_timing_on_the_failure_path(self):
+        """LIT-5466: a failed request reports no timing, the same as /v1/chat/completions."""
+        mock_user_api_key_dict = MagicMock(spec=UserAPIKeyAuth)
+        mock_user_api_key_dict.tpm_limit = None
+        mock_user_api_key_dict.rpm_limit = None
+        mock_user_api_key_dict.max_budget = None
+        mock_user_api_key_dict.spend = 0.0
+        mock_user_api_key_dict.allowed_model_region = None
+
+        headers = ProxyBaseLLMRequestProcessing.get_custom_headers(
+            user_api_key_dict=mock_user_api_key_dict,
+            call_id="test-call-id",
+            hidden_params={},
+            litellm_logging_obj=self._timing_logging_obj(
+                {"_response_ms": 500.0, "litellm_overhead_time_ms": 42.5}
+            ),
+            read_timing_from_logging_obj=False,
+        )
+
+        assert "x-litellm-response-duration-ms" not in headers
+        assert "x-litellm-overhead-duration-ms" not in headers
+
+    def test_get_custom_headers_takes_both_timing_values_from_one_source(self):
+        """A response that timed itself but has no overhead (lazy provider streams) does not pick
+        up the logging object's overhead, which was measured over a different window."""
+        mock_user_api_key_dict = MagicMock(spec=UserAPIKeyAuth)
+        mock_user_api_key_dict.tpm_limit = None
+        mock_user_api_key_dict.rpm_limit = None
+        mock_user_api_key_dict.max_budget = None
+        mock_user_api_key_dict.spend = 0.0
+        mock_user_api_key_dict.allowed_model_region = None
+
+        headers = ProxyBaseLLMRequestProcessing.get_custom_headers(
+            user_api_key_dict=mock_user_api_key_dict,
+            call_id="test-call-id",
+            hidden_params={"_response_ms": 300.0},
+            litellm_logging_obj=self._timing_logging_obj(
+                {"_response_ms": 500.0, "litellm_overhead_time_ms": 42.5}
+            ),
+        )
+
+        assert headers["x-litellm-response-duration-ms"] == "300.0"
+        assert "x-litellm-overhead-duration-ms" not in headers
+
+    def test_get_custom_headers_survives_a_logging_object_without_timing_metrics(self):
+        """Duck-typed logging objects (older custom code, test doubles) must not break headers."""
+        mock_user_api_key_dict = MagicMock(spec=UserAPIKeyAuth)
+        mock_user_api_key_dict.tpm_limit = None
+        mock_user_api_key_dict.rpm_limit = None
+        mock_user_api_key_dict.max_budget = None
+        mock_user_api_key_dict.spend = 0.0
+        mock_user_api_key_dict.allowed_model_region = None
+
+        class _NoTimingLoggingObj:
+            litellm_call_id = "test-call-id"
+            litellm_params = {}
+
+        headers = ProxyBaseLLMRequestProcessing.get_custom_headers(
+            user_api_key_dict=mock_user_api_key_dict,
+            call_id="test-call-id",
+            hidden_params={},
+            litellm_logging_obj=_NoTimingLoggingObj(),
+        )
+
+        assert "x-litellm-overhead-duration-ms" not in headers
+
+    def test_get_custom_headers_prefers_response_hidden_params_over_logging_obj_timing(self):
+        """A response that carries its own timing (chat completions) is not overridden."""
+        mock_user_api_key_dict = MagicMock(spec=UserAPIKeyAuth)
+        mock_user_api_key_dict.tpm_limit = None
+        mock_user_api_key_dict.rpm_limit = None
+        mock_user_api_key_dict.max_budget = None
+        mock_user_api_key_dict.spend = 0.0
+        mock_user_api_key_dict.allowed_model_region = None
+
+        headers = ProxyBaseLLMRequestProcessing.get_custom_headers(
+            user_api_key_dict=mock_user_api_key_dict,
+            call_id="test-call-id",
+            hidden_params={"_response_ms": 300.0, "litellm_overhead_time_ms": 7.5},
+            litellm_logging_obj=self._timing_logging_obj(
+                {"_response_ms": 500.0, "litellm_overhead_time_ms": 42.5}
+            ),
+        )
+
+        assert headers["x-litellm-response-duration-ms"] == "300.0"
+        assert headers["x-litellm-overhead-duration-ms"] == "7.5"
+
+    def test_get_custom_headers_omits_timing_when_no_source_has_it(self):
+        """No timing on the response and none on the logging object leaves both headers out."""
+        mock_user_api_key_dict = MagicMock(spec=UserAPIKeyAuth)
+        mock_user_api_key_dict.tpm_limit = None
+        mock_user_api_key_dict.rpm_limit = None
+        mock_user_api_key_dict.max_budget = None
+        mock_user_api_key_dict.spend = 0.0
+        mock_user_api_key_dict.allowed_model_region = None
+
+        headers = ProxyBaseLLMRequestProcessing.get_custom_headers(
+            user_api_key_dict=mock_user_api_key_dict,
+            call_id="test-call-id",
+            hidden_params={},
+            litellm_logging_obj=self._timing_logging_obj({}),
+        )
+
+        assert "x-litellm-response-duration-ms" not in headers
+        assert "x-litellm-overhead-duration-ms" not in headers
+
     def test_get_custom_headers_omits_overhead_when_none(self):
         """
         get_custom_headers() omits x-litellm-overhead-duration-ms

tests/test_litellm/responses/test_streaming_iterator.py

@@ -305,3 +305,24 @@ def test_stream_cache_write_completes_when_asyncio_run_closes_the_loop(monkeypat
     asyncio.run(_short_lived_script())
 
     assert len(writes) == 1
+
+
+def test_run_post_success_hooks_does_not_report_generation_time_as_overhead():
+    """LIT-5466: the provider call is timed to first byte, so at stream completion the total minus
+    that duration is token generation, not LiteLLM overhead."""
+    logging_obj = _logging_obj_stub()
+    logging_obj.model_call_details = {"litellm_params": {}, "llm_api_duration_ms": 200.0}
+    logging_obj.caching_details = None
+
+    class _CompletedEvent:
+        def __init__(self) -> None:
+            self._hidden_params: dict = {}
+
+    iterator = _make_iterator(sse_events=[], logging_obj=logging_obj)
+    iterator.completed_response = _CompletedEvent()
+    iterator.start_time = datetime(2025, 1, 1, 0, 0, 0)
+
+    iterator._run_post_success_hooks(datetime(2025, 1, 1, 0, 0, 10))
+
+    assert iterator.completed_response._hidden_params["_response_ms"] == 10000.0
+    assert "litellm_overhead_time_ms" not in iterator.completed_response._hidden_params