fix(passthrough): record real TTFT and start_time for streaming requests

[songkuan-zheng]

Summary

Streaming requests through any pass-through endpoint (/v1/messages,
/vertex_ai/*, /gemini/*, /cohere/*, …) logged completionStartTime
within ~1 ms of endTime in spend_logs — collapsing the streaming
phase to roughly zero and letting TTFT (time-to-first-token) effectively
soak up the entire request duration. Reported via the Anthropic
/v1/messages path; the root cause is in shared code so the fix
covers every pass-through endpoint.

Two interacting bugs

Both live in litellm/proxy/pass_through_endpoints/streaming_handler.py's
PassThroughStreamingHandler.chunk_processor:

Bug 1 — start_time arg is captured too late

The caller's start_time originates in
BaseAnthropicMessagesStreamingIterator.__init__, which runs after
the upstream HTTP response has already been received. So
SpendLogs.startTime reflects "moment we started reading the stream",
not "moment the client request entered the proxy". The real TTFT window
is silently subtracted from Duration.

Bug 2 — First-chunk arrival never recorded

The chunk loop yielded bytes to the client and collected them for
logging, but never noted when the first byte arrived. With
litellm_logging_obj.completion_start_time left as None, the fallback
at litellm_logging.py:1834-1837 sets it to end_time —
completionStartTime lands within ~1 ms of endTime (clock resolution
noise, not literally identical), and streaming_phase rounds to 0.

The bugs hide each other

State	Duration	TTFT	streaming_phase
Bug present	6528 ms	6527 ms	1 ms
Bug 2 fixed only	7698 ms	14 ms	7684 ms
Both fixed	8496 ms	2373 ms	6123 ms
Control (/v1/chat/completions, same model+prompt)	8143 ms	2071 ms	6072 ms

Numbers are from an Anthropic claude-sonnet-4-6 ~200-word streamed
completion against the e2e proxy. After the fix the pass-through path
is within ~5% of the transform path on the same upstream model — the
two should report the same streaming behavior because the underlying
HTTP request is the same.

Fix

At the top of chunk_processor's try block:

# Bug 1 fix: use the true request-entry timestamp
true_start = getattr(litellm_logging_obj, "start_time", None)
if isinstance(true_start, datetime) and (
    not isinstance(start_time, datetime) or true_start < start_time
):
    start_time = true_start

Inside the async for chunk in response.aiter_bytes(): loop, before
yielding to the client:

# Bug 2 fix: record first-chunk arrival
if litellm_logging_obj.completion_start_time is None:
    litellm_logging_obj._update_completion_start_time(
        completion_start_time=datetime.now()
    )

What changes

File	Change
litellm/proxy/pass_through_endpoints/streaming_handler.py	13 lines added inside chunk_processor: start_time override + first-chunk recording
e2e/cases/13_passthrough_streaming_ttft.md	New regression runbook
e2e/cases/data/13_passthrough_streaming_ttft.sh	Real-provider fixture: 200-word stream → poll spend_logs up to 30s → assert streaming_phase > 1s, ttft > 300ms, ttft < duration/2
e2e/cases/README.md	Index updated

Test plan

• Case 13 GREEN on this branch
• Cases 10, 11, 12 still GREEN (no regression in adjacent guards)
• Black 24.10.0 formatting clean
• Verified parity vs /v1/chat/completions transform path on same model

Blast radius

The shared chunk_processor is the streaming hot path for every
pass-through endpoint:

• /v1/messages, /anthropic/* (Anthropic)
• /vertex_ai/* (Vertex AI, both regular and live)
• /gemini/* (Google AI Studio)
• /cohere/* (Cohere)
• /openai/* (OpenAI pass-through)
• /assemblyai/* (AssemblyAI)
• /cursor/* (Cursor)

The user noticed it via Anthropic. The same fix improves TTFT
observability for all the others in the same release.

Out of scope

• The litellm.completion() / acompletion path (used by
  /v1/chat/completions) is unaffected. Its CustomStreamWrapper
  at litellm_core_utils/streaming_handler.py:1856 already calls
  _update_completion_start_time correctly.
• The fallback at litellm_logging.py:1834-1837 is left in place — it
  still protects callers who fail to set completion_start_time for
  non-streaming reasons. Now nobody in this code path needs to rely on
  it.