fix(streaming): stamp completion_start_time on first chunk for /v1/messages and /v1/responses

[yucheng-berri]

Relevant issues

Linear ticket

Resolves LIT-4185

Pre-Submission checklist

Please complete all items before asking a LiteLLM maintainer to review your PR

• I have added meaningful tests
• My PR passes all CI/CD checks (e.g., lint, format, unit tests)
• My PR's scope is as isolated as possible; it only solves 1 specific problem
• I have requested a Greptile review by commenting @greptileai and received a Confidence Score of at least 4/5 before requesting a maintainer review

Delays in PR merge?

If you're seeing a delay in your PR being merged, ping the LiteLLM Team on Slack (#pr-review).

Screenshots / Proof of Fix

Live proxy + Postgres, hitting real provider APIs. Config declares a native Anthropic model, an OpenAI model, and a custom callback that prints what async_log_success_event receives (completion_start_time - start_time vs end_time - start_time).

Same three streaming curls on unfixed and fixed code; SpendLogs is the persisted signal Prometheus/OTEL/UI read.

Before (unfixed code)

$ curl -sS -N http://localhost:4000/v1/messages -H "Authorization: Bearer sk-1234" -H "Content-Type: application/json" \
    -d '{"model":"claude-haiku","max_tokens":800,"stream":true,"messages":[{"role":"user","content":"Write a 500-word essay about latency."}]}' \
    -o /dev/null -w "%{time_starttransfer}s ttfb / %{time_total}s total\n"
0.624481s ttfb / 8.921292s total

$ curl -sS -N http://localhost:4000/v1/chat/completions -H "Authorization: Bearer sk-1234" -H "Content-Type: application/json" \
    -d '{"model":"gpt-mini","stream":true,"messages":[{"role":"user","content":"Write a 500-word essay about latency."}]}' \
    -o /dev/null -w "%{time_starttransfer}s ttfb / %{time_total}s total\n"
0.830721s ttfb / 13.920983s total

$ curl -sS -N http://localhost:4000/v1/responses -H "Authorization: Bearer sk-1234" -H "Content-Type: application/json" \
    -d '{"model":"gpt-mini","stream":true,"input":"Write a 500-word essay about latency."}' \
    -o /dev/null -w "%{time_starttransfer}s ttfb / %{time_total}s total\n"
0.340454s ttfb / 8.417053s total

Callback (only acompletion reports honest TTFT; the other two hit the bug):

LIT4185 call_type=anthropic_messages stream=True ttft=8.302s total=8.302s cst_equals_end=True
LIT4185 call_type=acompletion       stream=True ttft=0.813s total=13.909s cst_equals_end=False

SpendLogs (Prometheus / OTEL / Admin UI all read completionStartTime from this row):

     call_type      |           model            | cst_equals_end | ttft_s | total_s
--------------------+----------------------------+----------------+--------+---------
 aresponses         | openai/gpt-4.1-mini        | f              |  8.397 |   8.398
 acompletion        | openai/gpt-4.1-mini        | f              |  0.813 |  13.909
 anthropic_messages | anthropic/claude-haiku-4-5 | t              |  8.302 |   8.302

anthropic_messages collapses to cst_equals_end=t explicitly. aresponses shows ttft = total - 1ms (the fallback in _success_handler_helper_fn sets completion_start_time = end_time). acompletion is the control and stays honest.

After (fixed code)

$ curl -sS -N http://localhost:4000/v1/messages ...
0.905877s ttfb / 8.328649s total

$ curl -sS -N http://localhost:4000/v1/chat/completions ...
1.167069s ttfb / 7.222803s total

$ curl -sS -N http://localhost:4000/v1/responses ...
0.553045s ttfb / 10.005348s total

Callback:

LIT4185 call_type=anthropic_messages stream=True ttft=0.004s total=7.428s cst_equals_end=False
LIT4185 call_type=acompletion       stream=True ttft=1.148s total=7.212s cst_equals_end=False

SpendLogs (top three rows are the fixed run, bottom three are the unfixed run for direct comparison):

     call_type      |           model            | cst_equals_end | ttft_s | total_s
--------------------+----------------------------+----------------+--------+---------
 aresponses         | openai/gpt-4.1-mini        | f              |  0.520 |   9.970
 acompletion        | openai/gpt-4.1-mini        | f              |  1.148 |   7.212
 anthropic_messages | anthropic/claude-haiku-4-5 | f              |  0.004 |   7.428
 aresponses         | openai/gpt-4.1-mini        | f              |  8.397 |   8.398
 acompletion        | openai/gpt-4.1-mini        | f              |  0.813 |  13.909
 anthropic_messages | anthropic/claude-haiku-4-5 | t              |  8.302 |   8.302

TTFT is a real fraction of total for both previously-broken paths; the control keeps working; nothing collapses to cst_equals_end

Type

🐛 Bug Fix

Changes

Streaming pass-through for native Anthropic /v1/messages (PassThroughStreamingHandler.chunk_processor) and the /v1/responses streaming iterator (BaseResponsesAPIStreamingIterator._process_chunk) never set logging_obj.completion_start_time. Logging._success_handler_helper_fn then fell back to completion_start_time = end_time, so every downstream TTFT consumer (Prometheus, OTEL, Langfuse, Admin UI, spend logs completionStartTime, custom callbacks) reported time-to-first-token equal to total request duration. /v1/chat/completions streaming was unaffected because CustomStreamWrapper already stamps the first chunk

The fix stamps completion_start_time on the first upstream byte in each of those two spots via logging_obj._update_completion_start_time(...), guarded on is None so it's write-once and never overwrites a real value if something upstream already stamped

The agentic-hook path for /v1/messages (AgenticAnthropicStreamingIterator) wraps the same chunk_processor stream, so fixing the underlying chunk_processor covers it transitively; no separate change is needed in the agentic iterator

---

Note

Low Risk
Narrow observability fix on streaming hot paths with write-once guards; no auth, billing, or API contract changes beyond more accurate TTFT timestamps.

Overview
Fixes LIT-4185: streaming on native Anthropic /v1/messages (pass-through) and /v1/responses never set logging_obj.completion_start_time, so success logging fell back to completion_start_time = end_time and TTFT looked like full request duration in SpendLogs, Prometheus, OTEL, and callbacks. Chat completions streaming was already correct via CustomStreamWrapper.

Pass-through (PassThroughStreamingHandler): new _stamp_first_chunk_if_needed runs on every upstream byte chunk (normal and cost-injection paths) and calls _update_completion_start_time only when completion_start_time is None.

Responses API (BaseResponsesAPIStreamingIterator._process_chunk): same write-once stamp on the first non-empty SSE payload (after [DONE] handling, before JSON parse).

Tests add LIT-4185 regressions (first-chunk stamp, no overwrite on later chunks, cost-injection path) and align mocks with completion_start_time = None.

^{Reviewed by Cursor Bugbot for commit fff0039. Bugbot is set up for automated code reviews on this repo. Configure here.}

[CLAassistant]

All committers have signed the CLA.

[yucheng-berri]

@greptileai

[greptile-apps]

Greptile Summary

This PR fixes a missing completion_start_time stamp in two streaming paths — /v1/messages pass-through (PassThroughStreamingHandler.chunk_processor) and /v1/responses (BaseResponsesAPIStreamingIterator._process_chunk) — that caused every TTFT consumer (Prometheus, OTEL, SpendLogs, custom callbacks) to report time-to-first-token equal to total request duration. The fix inserts a write-once _update_completion_start_time call guarded by is None, mirroring what CustomStreamWrapper already does for /v1/chat/completions.

• streaming_handler.py: Stamps completion_start_time on the first raw HTTP byte received from upstream, in both the hot path and the cost-injection branch, with the same write-once guard in each branch.
• streaming_iterator.py: Stamps on the first non-empty, non-[DONE] SSE data field in _process_chunk, consistent with the same guard semantics.
• Tests: Three new mock-only regression tests cover first-chunk stamping and write-once no-overwrite for both affected paths; existing mocks in test_base_responses_api_streaming_iterator.py are updated to expose the completion_start_time attribute that spec=LiteLLMLoggingObj mocks would otherwise omit.

Confidence Score: 4/5

The change is narrowly scoped to two streaming paths that previously never set completion_start_time; the write-once guard ensures nothing is overwritten if an outer wrapper already stamped it, and the control path (chat/completions) is entirely untouched.

All changes are correct and well-tested. The only note is a minor code duplication in streaming_handler.py where the identical two-line stamp block is copy-pasted into both branches rather than extracted once before the branch — no behavioral impact but worth tidying.

No files require special attention; all modified files are straightforward and the new test file follows existing conventions.

Important Files Changed

Filename	Overview
litellm/proxy/pass_through_endpoints/streaming_handler.py	Stamps completion_start_time on the first upstream byte in both the hot path and the cost-injection branch via a write-once guard; logic is correct and handles both branches.
litellm/responses/streaming_iterator.py	Stamps completion_start_time on the first non-empty, non-DONE SSE data field in _process_chunk; write-once guard is correct and consistent with the streaming handler approach.
tests/test_litellm/proxy/pass_through_endpoints/test_streaming_handler_interrupt.py	Three new mock-only regression tests: first-chunk stamp, write-once no-overwrite, and cost-injection branch stamp. All tests are well-structured with no real network calls.
tests/test_litellm/responses/test_streaming_iterator.py	New test file with two mock-only tests covering first-chunk stamp and no-overwrite of prior completion_start_time for the ResponsesAPI streaming iterator.
tests/llm_responses_api_testing/test_base_responses_api_streaming_iterator.py	Existing tests updated to set completion_start_time = None on mocks so spec-constrained Mocks expose the attribute; no behavioral weakening of existing assertions.

_{Reviews (1): Last reviewed commit: "fix(streaming): stamp completion_start_t..." | Re-trigger Greptile}

[greptile-apps]

The identical two-line stamp block appears in both the hot path and the cost-injection branch. The guard could live once, right after raw_bytes.append(chunk), before the if endpoint_type branch — removing the duplication without changing behavior.

Suggested change

	async for chunk in response.aiter_bytes():
	raw_bytes.append(chunk)
	if litellm_logging_obj.completion_start_time is None:
	litellm_logging_obj._update_completion_start_time(completion_start_time=datetime.now())
	if endpoint_type == EndpointType.VERTEX_AI:
	async for chunk in response.aiter_bytes():
	raw_bytes.append(chunk)
	if litellm_logging_obj.completion_start_time is None:
	litellm_logging_obj._update_completion_start_time(
	completion_start_time=datetime.now()
	)
	if endpoint_type == EndpointType.VERTEX_AI:

Note: If this suggestion doesn't match your team's coding style, reply to this and let me know. I'll remember it for next time!

[greptile-apps]

Greptile Summary

This PR fixes missing completion_start_time stamping in the /v1/messages pass-through streaming handler and the /v1/responses streaming iterator, so downstream TTFT consumers (Prometheus, OTEL, SpendLogs, Langfuse) no longer collapse time-to-first-token to the full generation duration.

• streaming_handler.py: Adds a write-once completion_start_time stamp on the first upstream byte in both the hot path and the cost-injection path, consistent with how CustomStreamWrapper handles /v1/chat/completions.
• streaming_iterator.py: Stamps before JSON parsing in _process_chunk, after the early-return guards for empty and [DONE] chunks, with a correct dual None-check since logging_obj is optional on this class.
• Tests: New dedicated regression files for both paths, plus required attribute scaffolding in existing mocks so the is None guard is exercised rather than bypassed by a truthy Mock stub.

Confidence Score: 5/5

Safe to merge — the change is a targeted, write-once telemetry stamp applied only on the first upstream chunk in two previously-unpatched streaming paths, with no effect on request routing, response content, or auth.

Both production changes are minimal and isolated to the TTFT telemetry path. The write-once guard (is None) is correctly implemented and consistent with the existing CustomStreamWrapper pattern. datetime is imported in both modified files, _update_completion_start_time initializes the field to None in Logging.init, and the method is a simple two-line setter. Existing tests have been correctly updated to set the mock attribute to None so the guard is properly exercised. New regression tests cover both streaming branches.

No files require special attention.

Important Files Changed

Filename	Overview
litellm/proxy/pass_through_endpoints/streaming_handler.py	Adds write-once completion_start_time stamping on first chunk in both the hot path and cost-injection path; guard and placement are correct.
litellm/responses/streaming_iterator.py	Stamps completion_start_time before JSON parsing in _process_chunk; correctly guards with both None-check on logging_obj and is-None on the attribute.
tests/test_litellm/responses/test_streaming_iterator.py	New regression test file with mock-only tests; verifies stamp fires exactly once on first chunk and is skipped when already set.
tests/test_litellm/proxy/pass_through_endpoints/test_streaming_handler_interrupt.py	Adds three new regression tests for completion_start_time stamping in both streaming handler branches (hot path and cost-injection path).
tests/llm_responses_api_testing/test_base_responses_api_streaming_iterator.py	Existing tests updated to set mock_logging_obj.completion_start_time = None, required so Mock(spec=...) doesn't return a truthy stub that bypasses the new is-None guard.

_{Reviews (2): Last reviewed commit: "fix(streaming): stamp completion_start_t..." | Re-trigger Greptile}

[codecov]

Codecov Report

✅ All modified and coverable lines are covered by tests.

📢 Thoughts on this report? Let us know!

[yucheng-berri]

bugbot run

[cursor]

✅ Bugbot reviewed your changes and found no new issues!

Comment @cursor review or bugbot run to trigger another review on this PR

^{Reviewed by Cursor Bugbot for commit fff0039. Configure here.}