fix(prometheus): keep the handoff overhead stamp when a /v1/responses stream finishes

The Responses streaming iterator calls update_response_metadata again at stream end with
include_overhead=False, which replaced the timing stamped at handoff with one that had no
overhead, so litellm_overhead_latency_metric still had no sample for streamed /v1/responses

Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>
This commit is contained in:
kerry 2026-11-06 02:37:06 +00:00
parent ca87e24496
commit b2cc78a414
3 changed files with 49 additions and 2 deletions

View file

@ -299,7 +299,7 @@ def update_response_metadata(
# 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)
_logging_obj_timing_metrics(start_time, end_time, logging_obj, include_overhead)
)
return
@ -311,5 +311,20 @@ def update_response_metadata(
# the response assembled from the chunks never inherits the stream wrapper's
# ``_hidden_params``, so the logging payload reads the timing from the logging object
logging_obj.set_response_timing_metrics(
response_timing_metrics(start_time, end_time, logging_obj, include_overhead)
_logging_obj_timing_metrics(start_time, end_time, logging_obj, include_overhead)
)
def _logging_obj_timing_metrics(
start_time: datetime.datetime,
end_time: datetime.datetime,
logging_obj: LiteLLMLoggingObject,
include_overhead: bool,
) -> Mapping[str, float]:
"""A stream read to completion keeps the overhead stamped when the stream was handed back."""
timing_metrics: Final = response_timing_metrics(start_time, end_time, logging_obj, include_overhead)
stamped: Final[Mapping[str, float]] = getattr(logging_obj, "response_timing_metrics", None) or {}
stamped_overhead_ms: Final = stamped.get("litellm_overhead_time_ms")
if include_overhead or stamped_overhead_ms is None:
return timing_metrics
return {**timing_metrics, "litellm_overhead_time_ms": stamped_overhead_ms}

View file

@ -232,6 +232,33 @@ class TestDictResultsSkipMetadataUpdate:
)
assert result._hidden_params["litellm_overhead_time_ms"] == 100.0
def test_update_response_metadata_keeps_the_handoff_overhead_when_a_stream_is_read_to_completion(self):
"""A Responses API stream stamps its overhead when the stream is handed back and calls again at
stream end with include_overhead=False; that second call must not wipe the stamp."""
result = ModelResponse()
logging_obj = MagicMock()
logging_obj.stream = True
logging_obj.response_timing_metrics = {"_response_ms": 300.0, "litellm_overhead_time_ms": 100.0}
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, 10),
include_overhead=False,
)
logging_obj.set_response_timing_metrics.assert_called_once_with(
{"_response_ms": 10000.0, "litellm_overhead_time_ms": 100.0}
)
assert "litellm_overhead_time_ms" not in result._hidden_params
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."""

View file

@ -730,8 +730,10 @@ 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.stream = True
logging_obj.model_call_details = {"litellm_params": {}, "llm_api_duration_ms": 200.0}
logging_obj.caching_details = None
logging_obj.response_timing_metrics = {"_response_ms": 300.0, "litellm_overhead_time_ms": 100.0}
class _CompletedEvent:
def __init__(self) -> None:
@ -745,6 +747,9 @@ def test_run_post_success_hooks_does_not_report_generation_time_as_overhead():
assert iterator.completed_response._hidden_params["_response_ms"] == 10000.0
assert "litellm_overhead_time_ms" not in iterator.completed_response._hidden_params
logging_obj.set_response_timing_metrics.assert_called_once_with(
{"_response_ms": 10000.0, "litellm_overhead_time_ms": 100.0}
)
def _mock_config_with_completed_response(response: ResponsesAPIResponse) -> Mock: