[BUG]: TTFT metric shows inconsistent values when using Istio traffic mirroring

[chay1045]

Describe the Bug

When using Istio VirtualService traffic mirroring to send shadow traffic to Dynamo (with vLLM backend), the time_to_first_token_seconds histogram metric reports higher values compared to direct requests (without mirroring).
The difference is approximately ~12ms additional latency in TTFT when requests are mirrored vs sent directly.

Steps to Reproduce

Test Setup

• Dynamo frontend with vLLM backend
• Istio VirtualService configured to mirror traffic

Istio Mirroring Configuration

apiVersion: networking.istio.io/v1beta1
kind: VirtualService
metadata:
  name: llm-mirror
spec:
  gateways:
    - llm-gateway
  hosts:
    - "*"
  http:
    - route:
        - destination:
            host: primary-llm-service
            port:
              number: 8000
      mirror:
        host: dynamo-frontend
        port:
          number: 8000
      mirrorPercentage:
        value: 100.0

Test Configuration

• Request type: streaming=false (non-streaming)
• Requests sent through Istio Ingress Gateway

Observations

Scenario	TTFT & Request Duration Difference (Dynamo - vLLM)
Without mirroring (direct requests)	~11ms
With Istio mirroring	~23ms

The ~11ms baseline is expected Dynamo overhead (HTTP handling, tokenization, routing, etc.). The additional ~12ms when mirroring is the bug.

Expected Behavior

TTFT should be consistent between mirrored and non-mirrored requests, with only the expected Dynamo processing overhead (~11ms) compared to vLLM's native TTFT metric.

Actual Behavior

TTFT shows approximately 12ms additional latency when requests are received via Istio mirroring compared to direct requests.

Environment

I am using HGX H100s with a K3s Cluster I built the container for vLLM from the source code for v0.8.0 (some commits ahead of v0.8.0)

Additional Context

Key Findings

• ITL is identical in both scenarios.
• Envoy sidecar logs show no errors - the sidecar appears to be handling the mirrored traffic normally
• Non-streaming requests: The issue was observed with streaming=false, so it's not related to SSE stream handling

Screenshots

No response

[adityapuranik99]

Hi @chay1045! I traced through the code and found that TTFT timing starts after HTTP request parsing/header processing (metrics.rs:886). When Istio mirrors traffic, the extra proxy headers (x-envoy-, x-forwarded-, etc.) add ~12ms overhead during this parsing phase, which happens before the timer starts.

Question: Should TTFT measure "LLM processing time" (current behavior, excludes HTTP overhead) or "end-to-end latency" (would include HTTP/proxy overhead)? The 12ms difference seems like expected HTTP processing overhead rather than a bug - but wanted to confirm the intended definition before proposing a fix.

[adityapuranik99]

Here's the relevant code for reference (metrics.rs:881-890):

fn new(metrics: Arc<Metrics>, model: String) -> Self {
    ResponseMetricCollector {
        metrics,
        model,
        is_first_token: true,
        last_response_time: None,
        start_time: Instant::now(),  // TTFT timer starts here
        osl: 0,
        cached_tokens_observed: false,
    }
}

The timer starts after Axum has already parsed the HTTP headers and body. Istio's extra proxy headers (x-envoy-, x-forwarded-, etc.) add ~12ms of parsing overhead before Instant::now() is called, which explains the discrepancy.

[chay1045]

Thanks for tracing through the code @adityapuranik99! However, I don't think the extra header parsing explains the observed TTFT discrepancy.

Looking at the code you referenced:

fn new(metrics: Arc<Metrics>, model: String) -> Self {
    ResponseMetricCollector {
        // ...
        start_time: Instant::now(),  // TTFT timer starts here
        // ...
    }
}

The TTFT timer starts after Axum has finished parsing the HTTP request. This means:

• Without mirroring: Axum parses headers (fast) → timer starts → process request → timer ends
• With mirroring: Axum parses extra headers (+12ms) → timer starts → process request → timer ends

In both cases, the TTFT measurement (timer end - timer start) should be identical because the extra parsing time occurs before Instant::now() is called. The 12ms parsing overhead would affect total end-to-end latency but would be excluded from the TTFT metric.

However, I'm observing a ~12ms difference in the TTFT metric itself between mirrored and direct requests (not just in total latency). This suggests the extra latency is being introduced after the timer starts, not before.

Additionally, ITL (inter-token latency) is identical in both scenarios. The extra latency appears specifically in the time-to-first-token measurement and the Avg Request Duration.