@tduncan / Nvidia-Optimization-Stack-VLLM / commits / 86db6c3070

[Frontend] add per-request timing `metrics` field to response body of Chat/Completions APIs (#46768)

Signed-off-by: Nicholas Edelman <nedelman@nvidia.com> Signed-off-by: Simon Mo <simon@inferact.ai> Co-authored-by: Simon Mo <simon@inferact.ai> Co-authored-by: GPT-5.5 <noreply@cursor.com>

nv-nedelman-1 committed Jul 6, 2026 at 19:48 UTC 86db6c307073217599a993f1a801e3c204f2eb17
12 files changed +565 -4
docs/features/per_request_metrics.md new
+127
@@ -0,0 +1,127 @@
1 +# Per-Request Metrics
2 +
3 +vLLM can return per-request timing metrics directly in API responses.
4 +This is useful for billing, SLA monitoring, and latency analysis at the
5 +individual request level, as a complement to the server-aggregated Prometheus
6 +metrics exposed at `/metrics`.
7 +
8 +## Enabling
9 +
10 +Start the server with `--enable-per-request-metrics`:
11 +
12 +```bash
13 +vllm serve meta-llama/Llama-3.1-8B-Instruct --enable-per-request-metrics
14 +```
15 +
16 +When this flag is set, supported API responses include metrics for each
17 +attributable request.
18 +
19 +!!! note
20 + At high concurrency, enabling per-request metrics computation may introduce
21 + non-negligible CPU overhead. Benchmark your specific workload to evaluate the
22 + impact before enabling in production.
23 +
24 +## Response Format
25 +
26 +When per-request metrics are enabled, the response includes a `metrics` object:
27 +
28 +```json
29 +{
30 + "id": "chatcmpl-abc123",
31 + "object": "chat.completion",
32 + "model": "meta-llama/Llama-3.1-8B-Instruct",
33 + "choices": [ ... ],
34 + "usage": {
35 + "prompt_tokens": 42,
36 + "completion_tokens": 128,
37 + "total_tokens": 170
38 + },
39 + "metrics": {
40 + "time_to_first_token_ms": 85.2,
41 + "generation_time_ms": 1240.5,
42 + "queue_time_ms": 12.3,
43 + "mean_itl_ms": 9.1,
44 + "tokens_per_second": 103.2
45 + }
46 +}
47 +```
48 +
49 +| Field | Description |
50 +| --- | --- |
51 +| `time_to_first_token_ms` | Time from when the request was scheduled until the first output token was generated (TTFT). |
52 +| `generation_time_ms` | Decode time: time from the first output token to the last output token. Excludes both queue wait and prefill/TTFT. |
53 +| `queue_time_ms` | Time the request spent waiting in the scheduler queue before processing began. |
54 +| `mean_itl_ms` | Mean inter-token latency (average time between successive output tokens) during the decode phase. `null` for single-token responses. |
55 +| `tokens_per_second` | Overall output token throughput: all generated tokens over the inference interval (scheduling to last output token). Unlike `generation_time_ms`, this includes the prefill phase, so it reflects end-to-end generation speed rather than pure decode speed. |
56 +
57 +All fields are `null` if the underlying timing data is not available for that
58 +request.
59 +
60 +!!! note
61 + Timing metrics describe a single generation stream, so they are only
62 + returned when the request maps to exactly one. They are suppressed (the
63 + `metrics` object is `null`) for requests with `n > 1`, because the
64 + underlying timing data reflects only one of the `n` sequences and cannot be
65 + accurately attributed to the request as a whole. Token usage
66 + (`prompt_tokens`, `completion_tokens`) remains accurate in these cases.
67 + Per-request metrics also require server-side statistics logging, which is
68 + on by default. vLLM rejects `--enable-per-request-metrics` when
69 + `--disable-log-stats` is also set.
70 +
71 +## Example Request
72 +
73 +=== "Non-streaming"
74 +
75 + ```python
76 + from openai import OpenAI
77 +
78 + client = OpenAI(base_url="http://localhost:8000/v1", api_key="token")
79 +
80 + response = client.chat.completions.create(
81 + model="meta-llama/Llama-3.1-8B-Instruct",
82 + messages=[{"role": "user", "content": "What is the capital of France?"}],
83 + )
84 +
85 + print(response.usage)
86 + print(response.model_extra.get("metrics"))
87 + ```
88 +
89 +=== "Streaming"
90 +
91 + In streaming responses, metrics are attached to the final usage chunk (the
92 + chunk sent after all content chunks). That chunk is only emitted when usage
93 + reporting is enabled with `stream_options.include_usage: true` or forced
94 + server-side with `--enable-force-include-usage`. Without forced usage, a
95 + streaming client must set `stream_options.include_usage: true` to receive
96 + metrics.
97 +
98 + ```python
99 + from openai import OpenAI
100 +
101 + client = OpenAI(base_url="http://localhost:8000/v1", api_key="token")
102 +
103 + stream = client.chat.completions.create(
104 + model="meta-llama/Llama-3.1-8B-Instruct",
105 + messages=[{"role": "user", "content": "What is the capital of France?"}],
106 + stream=True,
107 + stream_options={"include_usage": True},
108 + )
109 +
110 + for chunk in stream:
111 + if chunk.usage:
112 + print("Usage:", chunk.usage)
113 + print("Metrics:", chunk.model_extra.get("metrics"))
114 + ```
115 +
116 +## Completions API
117 +
118 +Per-request metrics are also available on the `/v1/completions` endpoint using
119 +the same `metrics` response field. As with `n > 1`, metrics are omitted for
120 +requests with multiple prompts, because the timing data cannot be attributed to
121 +a single prompt's generation.
122 +
123 +## Relationship to Prometheus Metrics
124 +
125 +The `metrics` response field provides per-request values for a single request.
126 +The `/metrics` Prometheus endpoint exposes server-level histograms (e.g.
127 +`vllm:time_to_first_token_seconds`) that aggregate across all requests.
tests/entrypoints/openai/chat_completion/test_serving_chat.py
+173
@@ -2,6 +2,7 @@
2 # SPDX-FileCopyrightText: Copyright contributors to the vLLM project
3 import asyncio
4 import json
5 +from collections.abc import AsyncIterator
6 from contextlib import suppress
7 from dataclasses import dataclass, field
8 from typing import Any
@@ -19,6 +20,7 @@ from tests.entrypoints.openai.utils import (
20 from tests.utils import RemoteOpenAIServer
21 from vllm._aiter_ops import is_aiter_found_and_supported
22 from vllm.config import MultiModalConfig
23 +from vllm.entrypoints.generate.base.serving import build_per_request_timing_metrics
24 from vllm.entrypoints.openai.chat_completion.protocol import (
25 ChatCompletionRequest,
26 ChatCompletionResponse,
@@ -50,9 +52,17 @@ from vllm.tokenizers import get_tokenizer
52 from vllm.tokenizers.mistral import MistralTokenizer
53 from vllm.tokenizers.registry import cached_tokenizer_from_config
54 from vllm.v1.engine.async_llm import AsyncLLM
55 +from vllm.v1.metrics.stats import RequestStateStats
56
57 GPT_OSS_MODEL_NAME = "openai/gpt-oss-20b"
58 GPT_OSS_SPECULATOR_NAME = "RedHatAI/gpt-oss-20b-speculator.eagle3"
59 +_PER_REQUEST_STATS = RequestStateStats(
60 + queued_ts=1.0,
61 + scheduled_ts=1.5,
62 + first_token_ts=2.0,
63 + last_token_ts=3.0,
64 + num_generation_tokens=2,
65 +)
66
67
68 @pytest.fixture(scope="module")
@@ -608,6 +618,169 @@ def _build_serving_chat(
618 return serving_chat
619
620
621 +def _build_minimal_metrics_serving_chat(
622 + enable_per_request_metrics: bool,
623 + enable_force_include_usage: bool = False,
624 +) -> OpenAIServingChat:
625 + serving = OpenAIServingChat.__new__(OpenAIServingChat)
626 + serving.response_role = "assistant"
627 + serving.parser_cls = None
628 + serving.enable_auto_tools = False
629 + serving.enable_prompt_tokens_details = False
630 + serving.enable_log_outputs = False
631 + serving.enable_log_deltas = False
632 + serving.enable_force_include_usage = enable_force_include_usage
633 + serving.request_logger = None
634 + serving.system_fingerprint = None
635 + serving.enable_per_request_metrics = enable_per_request_metrics
636 + return serving
637 +
638 +
639 +def _make_metrics_request_output(
640 + metrics: RequestStateStats | None = _PER_REQUEST_STATS,
641 + token_ids: tuple[int, ...] = (100, 101),
642 +) -> RequestOutput:
643 + return RequestOutput(
644 + request_id="test-id",
645 + prompt="Test prompt",
646 + prompt_token_ids=[1, 2, 3],
647 + prompt_logprobs=None,
648 + outputs=[
649 + CompletionOutput(
650 + index=0,
651 + text="Hello",
652 + token_ids=list(token_ids),
653 + cumulative_logprob=None,
654 + logprobs=None,
655 + finish_reason="stop",
656 + )
657 + ],
658 + finished=True,
659 + metrics=metrics,
660 + )
661 +
662 +
663 +async def _single_request_output(
664 + request_output: RequestOutput,
665 +) -> AsyncIterator[RequestOutput]:
666 + yield request_output
667 +
668 +
669 +async def _collect_metrics_stream_chunks(
670 + serving: OpenAIServingChat,
671 + request: ChatCompletionRequest,
672 +) -> list[dict[str, Any]]:
673 + chunks: list[dict[str, Any]] = []
674 + async for line in serving.chat_completion_stream_generator(
675 + request,
676 + _single_request_output(_make_metrics_request_output()),
677 + "chatcmpl-test-id",
678 + "test-model",
679 + conversation=[{"role": "user", "content": "Test"}],
680 + tokenizer=MagicMock(),
681 + request_metadata=RequestResponseMetadata(request_id="chatcmpl-test-id"),
682 + ):
683 + line = line.strip()
684 + if not line.startswith("data: "):
685 + continue
686 + payload = line[len("data: ") :]
687 + if payload != "[DONE]":
688 + chunks.append(json.loads(payload))
689 + return chunks
690 +
691 +
692 +def test_build_per_request_timing_metrics_valid_timestamps():
693 + metrics = build_per_request_timing_metrics(
694 + _PER_REQUEST_STATS, num_generation_tokens=10
695 + )
696 +
697 + assert metrics.time_to_first_token_ms == pytest.approx(500.0)
698 + assert metrics.generation_time_ms == pytest.approx(1000.0)
699 + assert metrics.queue_time_ms == pytest.approx(500.0)
700 + assert metrics.mean_itl_ms == pytest.approx(1000.0 / 9, rel=1e-4)
701 + assert metrics.tokens_per_second == pytest.approx(10.0 / 1.5, rel=1e-4)
702 +
703 +
704 +@pytest.mark.asyncio
705 +async def test_chat_per_request_metrics_follow_server_flag():
706 + request = ChatCompletionRequest(
707 + model="test-model",
708 + messages=[{"role": "user", "content": "Test prompt"}],
709 + max_tokens=10,
710 + stream=False,
711 + )
712 + request_output = _make_metrics_request_output()
713 +
714 + disabled_serving = _build_minimal_metrics_serving_chat(
715 + enable_per_request_metrics=False
716 + )
717 + disabled_response = await disabled_serving.chat_completion_full_generator(
718 + request,
719 + _single_request_output(request_output),
720 + "chatcmpl-test-id",
721 + "test-model",
722 + conversation=[{"role": "user", "content": "Test"}],
723 + tokenizer=MagicMock(),
724 + request_metadata=RequestResponseMetadata(request_id="chatcmpl-test-id"),
725 + )
726 + assert disabled_response.metrics is None
727 +
728 + enabled_serving = _build_minimal_metrics_serving_chat(
729 + enable_per_request_metrics=True
730 + )
731 + enabled_response = await enabled_serving.chat_completion_full_generator(
732 + request,
733 + _single_request_output(request_output),
734 + "chatcmpl-test-id",
735 + "test-model",
736 + conversation=[{"role": "user", "content": "Test"}],
737 + tokenizer=MagicMock(),
738 + request_metadata=RequestResponseMetadata(request_id="chatcmpl-test-id"),
739 + )
740 + assert enabled_response.metrics is not None
741 + assert enabled_response.metrics.time_to_first_token_ms == pytest.approx(500.0)
742 +
743 +
744 +@pytest.mark.asyncio
745 +async def test_chat_per_request_metrics_suppressed_for_n_greater_than_one():
746 + serving = _build_minimal_metrics_serving_chat(enable_per_request_metrics=True)
747 + response = await serving.chat_completion_full_generator(
748 + ChatCompletionRequest(
749 + model="test-model",
750 + messages=[{"role": "user", "content": "Test prompt"}],
751 + max_tokens=10,
752 + stream=False,
753 + n=2,
754 + ),
755 + _single_request_output(_make_metrics_request_output()),
756 + "chatcmpl-test-id",
757 + "test-model",
758 + conversation=[{"role": "user", "content": "Test"}],
759 + tokenizer=MagicMock(),
760 + request_metadata=RequestResponseMetadata(request_id="chatcmpl-test-id"),
761 + )
762 + assert response.metrics is None
763 +
764 +
765 +@pytest.mark.asyncio
766 +async def test_chat_streaming_metrics_ride_on_usage_chunk():
767 + serving = _build_minimal_metrics_serving_chat(enable_per_request_metrics=True)
768 + chunks = await _collect_metrics_stream_chunks(
769 + serving,
770 + ChatCompletionRequest(
771 + model="test-model",
772 + messages=[{"role": "user", "content": "Test prompt"}],
773 + max_tokens=10,
774 + stream=True,
775 + stream_options={"include_usage": True},
776 + ),
777 + )
778 +
779 + usage_chunks = [chunk for chunk in chunks if chunk.get("usage")]
780 + assert usage_chunks
781 + assert usage_chunks[-1]["metrics"]["time_to_first_token_ms"] == pytest.approx(500.0)
782 +
783 +
784 @dataclass
785 class MockEngine:
786 model_config: MockModelConfig = field(default_factory=MockModelConfig)
tests/entrypoints/openai/completion/test_completion_error.py
+97 -1
@@ -11,7 +11,10 @@ from pydantic import ValidationError
11 from vllm.config.multimodal import MultiModalConfig
12 from vllm.entrypoints.openai.completion.protocol import CompletionRequest
13 from vllm.entrypoints.openai.completion.serving import OpenAIServingCompletion
14 -from vllm.entrypoints.openai.engine.protocol import GenerationError
14 +from vllm.entrypoints.openai.engine.protocol import (
15 + GenerationError,
16 + RequestResponseMetadata,
17 +)
18 from vllm.entrypoints.openai.models.protocol import BaseModelPath
19 from vllm.entrypoints.openai.models.serving import OpenAIServingModels
20 from vllm.entrypoints.scale_out.render.serving import ServingRender
@@ -20,9 +23,17 @@ from vllm.renderers.hf import HfRenderer
23 from vllm.renderers.online_renderer import OnlineRenderer
24 from vllm.tokenizers.registry import cached_tokenizer_from_config
25 from vllm.v1.engine.async_llm import AsyncLLM
26 +from vllm.v1.metrics.stats import RequestStateStats
27
28 MODEL_NAME = "openai-community/gpt2"
29 MODEL_NAME_SHORT = "gpt2"
30 +_PER_REQUEST_STATS = RequestStateStats(
31 + queued_ts=1.0,
32 + scheduled_ts=1.5,
33 + first_token_ts=2.0,
34 + last_token_ts=3.0,
35 + num_generation_tokens=2,
36 +)
37 BASE_MODEL_PATHS = [
38 BaseModelPath(name=MODEL_NAME, model_path=MODEL_NAME),
39 BaseModelPath(name=MODEL_NAME_SHORT, model_path=MODEL_NAME_SHORT),
@@ -93,6 +104,39 @@ def _build_serving_completion(engine: AsyncLLM) -> OpenAIServingCompletion:
104 )
105
106
107 +def _build_minimal_metrics_serving_completion(
108 + enable_per_request_metrics: bool,
109 +) -> OpenAIServingCompletion:
110 + serving = OpenAIServingCompletion.__new__(OpenAIServingCompletion)
111 + serving.enable_prompt_tokens_details = False
112 + serving.system_fingerprint = None
113 + serving.enable_per_request_metrics = enable_per_request_metrics
114 + return serving
115 +
116 +
117 +def _make_metrics_request_output(
118 + metrics: RequestStateStats | None = _PER_REQUEST_STATS,
119 +) -> RequestOutput:
120 + return RequestOutput(
121 + request_id="test-id",
122 + prompt="Test prompt",
123 + prompt_token_ids=[1, 2, 3],
124 + prompt_logprobs=None,
125 + outputs=[
126 + CompletionOutput(
127 + index=0,
128 + text="Hello",
129 + token_ids=[100, 101],
130 + cumulative_logprob=None,
131 + logprobs=None,
132 + finish_reason="stop",
133 + )
134 + ],
135 + finished=True,
136 + metrics=metrics,
137 + )
138 +
139 +
140 def _build_renderer(model_config: MockModelConfig):
141 return HfRenderer(
142 MockVllmConfig(model_config, parallel_config=MockParallelConfig()),
@@ -100,6 +144,58 @@ def _build_renderer(model_config: MockModelConfig):
144 )
145
146
147 +def test_completion_per_request_metrics_follow_server_flag():
148 + request = CompletionRequest(model=MODEL_NAME, prompt="Test prompt", max_tokens=10)
149 + request_output = _make_metrics_request_output()
150 +
151 + disabled_serving = _build_minimal_metrics_serving_completion(
152 + enable_per_request_metrics=False
153 + )
154 + disabled_response = disabled_serving.request_output_to_completion_response(
155 + [request_output],
156 + request,
157 + "cmpl-test-id",
158 + 0,
159 + MODEL_NAME,
160 + None,
161 + RequestResponseMetadata(request_id="cmpl-test-id"),
162 + )
163 + assert disabled_response.metrics is None
164 +
165 + enabled_serving = _build_minimal_metrics_serving_completion(
166 + enable_per_request_metrics=True
167 + )
168 + enabled_response = enabled_serving.request_output_to_completion_response(
169 + [request_output],
170 + request,
171 + "cmpl-test-id",
172 + 0,
173 + MODEL_NAME,
174 + None,
175 + RequestResponseMetadata(request_id="cmpl-test-id"),
176 + )
177 + assert enabled_response.metrics is not None
178 + assert enabled_response.metrics.time_to_first_token_ms == pytest.approx(500.0)
179 +
180 +
181 +def test_completion_per_request_metrics_suppressed_for_multiple_prompts():
182 + serving = _build_minimal_metrics_serving_completion(enable_per_request_metrics=True)
183 + response = serving.request_output_to_completion_response(
184 + [_make_metrics_request_output(), _make_metrics_request_output()],
185 + CompletionRequest(
186 + model=MODEL_NAME,
187 + prompt=["Test prompt", "Another prompt"],
188 + max_tokens=10,
189 + ),
190 + "cmpl-test-id",
191 + 0,
192 + MODEL_NAME,
193 + None,
194 + RequestResponseMetadata(request_id="cmpl-test-id"),
195 + )
196 + assert response.metrics is None
197 +
198 +
199 @pytest.mark.asyncio
200 async def test_completion_error_non_stream():
201 """test finish_reason='error' returns 500 InternalServerError (non-streaming)"""
tests/entrypoints/openai/test_cli_args.py
+8
@@ -206,6 +206,14 @@ def test_chat_template_validation_for_sad_paths(serve_parser):
206 validate_parsed_serve_args(args)
207
208
209 +def test_per_request_metrics_requires_log_stats(serve_parser):
210 + args = serve_parser.parse_args(
211 + args=["--enable-per-request-metrics", "--disable-log-stats"]
212 + )
213 + with pytest.raises(ValueError):
214 + validate_parsed_serve_args(args)
215 +
216 +
217 @pytest.mark.parametrize(
218 "cli_args, expected_middleware",
219 [
vllm/entrypoints/generate/api_router.py
+2
@@ -130,6 +130,7 @@ async def init_generate_state(
130 enable_force_include_usage=args.enable_force_include_usage,
131 enable_log_outputs=args.enable_log_outputs,
132 enable_log_deltas=args.enable_log_deltas,
133 + enable_per_request_metrics=args.enable_per_request_metrics,
134 )
135 state.openai_serving_chat = (
136 OpenAIServingChat(**_chat_kwargs) if "generate" in supported_tasks else None
@@ -150,6 +151,7 @@ async def init_generate_state(
151 return_tokens_as_token_ids=args.return_tokens_as_token_ids,
152 enable_prompt_tokens_details=args.enable_prompt_tokens_details,
153 enable_force_include_usage=args.enable_force_include_usage,
154 + enable_per_request_metrics=args.enable_per_request_metrics,
155 )
156 if "generate" in supported_tasks
157 else None
vllm/entrypoints/generate/base/serving.py
+57
@@ -18,6 +18,7 @@ from vllm.entrypoints.openai.completion.protocol import CompletionRequest
18 from vllm.entrypoints.openai.engine.protocol import (
19 ErrorResponse,
20 GenerationError,
21 + PerRequestTimingMetrics,
22 )
23 from vllm.entrypoints.openai.models.serving import OpenAIServingModels
24 from vllm.entrypoints.openai.responses.protocol import ResponsesRequest
@@ -34,6 +35,7 @@ from vllm.tracing import (
35 extract_trace_headers,
36 log_tracing_disabled_warning,
37 )
38 +from vllm.v1.metrics.stats import RequestStateStats
39
40 logger = init_logger(__name__)
41
@@ -41,6 +43,61 @@ RequestT = TypeVar("RequestT", bound=AnyRequest)
43 _T = TypeVar("_T")
44
45
46 +def build_per_request_timing_metrics(
47 + metrics: RequestStateStats | None,
48 + num_generation_tokens: int,
49 +) -> PerRequestTimingMetrics:
50 + """Build per-request timing metrics from ``RequestStateStats``.
51 +
52 + ``generation_time_ms`` is the decode interval only (first output token to
53 + last output token); it excludes both queue wait and prefill/TTFT.
54 + ``tokens_per_second`` is overall output throughput: all generated tokens
55 + over the inference interval (scheduling to last output token), so it counts
56 + the prefill/TTFT phase and is not simply the reciprocal of ``mean_itl_ms``.
57 + Each field is left ``None`` when the timestamps it depends on are
58 + unavailable.
59 + """
60 + if metrics is None:
61 + return PerRequestTimingMetrics()
62 +
63 + queued_ts = metrics.queued_ts
64 + scheduled_ts = metrics.scheduled_ts
65 + first_token_ts = metrics.first_token_ts
66 + last_token_ts = metrics.last_token_ts
67 +
68 + time_to_first_token_ms: float | None = None
69 + generation_time_ms: float | None = None
70 + queue_time_ms: float | None = None
71 + mean_itl_ms: float | None = None
72 + tokens_per_second: float | None = None
73 +
74 + if scheduled_ts > 0 and first_token_ts > 0:
75 + time_to_first_token_ms = (first_token_ts - scheduled_ts) * 1000
76 +
77 + if first_token_ts > 0 and last_token_ts > 0:
78 + generation_time_ms = (last_token_ts - first_token_ts) * 1000
79 +
80 + if queued_ts > 0 and scheduled_ts > 0:
81 + queue_time_ms = (scheduled_ts - queued_ts) * 1000
82 +
83 + if first_token_ts > 0 and last_token_ts > 0 and num_generation_tokens > 1:
84 + decode_time = last_token_ts - first_token_ts
85 + mean_itl_ms = decode_time / (num_generation_tokens - 1) * 1000
86 +
87 + if scheduled_ts > 0 and last_token_ts > 0:
88 + inference_time_ms = (last_token_ts - scheduled_ts) * 1000
89 + if inference_time_ms > 0:
90 + tokens_per_second = num_generation_tokens / inference_time_ms * 1000
91 +
92 + return PerRequestTimingMetrics(
93 + time_to_first_token_ms=time_to_first_token_ms,
94 + generation_time_ms=generation_time_ms,
95 + queue_time_ms=queue_time_ms,
96 + mean_itl_ms=mean_itl_ms,
97 + tokens_per_second=tokens_per_second,
98 + )
99 +
100 +
101 @dataclass(kw_only=True)
102 class ServeContext(Generic[RequestT]):
103 request: RequestT
vllm/entrypoints/openai/chat_completion/protocol.py
+3
@@ -26,6 +26,7 @@ from vllm.entrypoints.openai.engine.protocol import (
26 FunctionDefinition,
27 LegacyStructuralTagResponseFormat,
28 OpenAIBaseModel,
29 + PerRequestTimingMetrics,
30 StreamOptions,
31 StructuralTagResponseFormat,
32 ToolCall,
@@ -133,6 +134,7 @@ class ChatCompletionResponse(OpenAIBaseModel):
134 kv_transfer_params: dict[str, Any] | None = Field(
135 default=None, description="KVTransfer parameters."
136 )
137 + metrics: PerRequestTimingMetrics | None = None
138
139
140 class ChatCompletionResponseStreamChoice(OpenAIBaseModel):
@@ -160,6 +162,7 @@ class ChatCompletionStreamResponse(OpenAIBaseModel):
162 # Rendered prompt text from chat templating (only set when
163 # ``return_prompt_text=True`` on the request); only sent on the first chunk.
164 prompt_text: str | None = None
165 + metrics: PerRequestTimingMetrics | None = None
166
167
168 class ChatCompletionToolsParam(OpenAIBaseModel):
vllm/entrypoints/openai/chat_completion/serving.py
+35
@@ -22,6 +22,7 @@ from vllm.entrypoints.chat_utils import (
22 from vllm.entrypoints.generate.base.serving import (
23 GenerateBaseServing,
24 GenerationError,
25 + build_per_request_timing_metrics,
26 clamp_prompt_logprobs,
27 format_token_id_placeholder,
28 )
@@ -41,6 +42,7 @@ from vllm.entrypoints.openai.engine.protocol import (
42 DeltaMessage,
43 ErrorResponse,
44 FunctionCall,
45 + PerRequestTimingMetrics,
46 PromptTokenUsageInfo,
47 RequestResponseMetadata,
48 ToolCall,
@@ -123,6 +125,7 @@ class OpenAIServingChat(GenerateBaseServing):
125 enable_log_outputs: bool = False,
126 enable_log_deltas: bool = True,
127 default_chat_template_kwargs: dict[str, Any] | None = None,
128 + enable_per_request_metrics: bool = False,
129 ) -> None:
130 super().__init__(
131 engine_client=engine_client,
@@ -161,6 +164,7 @@ class OpenAIServingChat(GenerateBaseServing):
164
165 self.enable_prompt_tokens_details = enable_prompt_tokens_details
166 self.enable_force_include_usage = enable_force_include_usage
167 + self.enable_per_request_metrics = enable_per_request_metrics
168 self.default_sampling_params = self.model_config.get_diff_sampling_param()
169 mc = self.model_config
170 self.override_max_tokens = (
@@ -461,8 +465,10 @@ class OpenAIServingChat(GenerateBaseServing):
465 stream_options, self.enable_force_include_usage
466 )
467
468 + last_res: RequestOutput | None = None
469 try:
470 async for res in result_generator:
471 + last_res = res
472 if res.prompt_token_ids is not None:
473 num_prompt_tokens = len(res.prompt_token_ids)
474 if res.encoder_prompt_token_ids is not None:
@@ -752,6 +758,21 @@ class OpenAIServingChat(GenerateBaseServing):
758 mm_token_counts,
759 )
760
761 + # In streaming, metrics ride on this final usage chunk, which is
762 + # only emitted when usage reporting is enabled (i.e.
763 + # ``stream_options.include_usage=true`` or
764 + # ``--enable-force-include-usage``).
765 + stream_per_request_metrics: PerRequestTimingMetrics | None = None
766 + if (
767 + self.enable_per_request_metrics
768 + # See note in chat_completion_full_generator: suppress for n>1.
769 + and (request.n or 1) == 1
770 + ):
771 + last_metrics = last_res.metrics if last_res is not None else None
772 + stream_per_request_metrics = build_per_request_timing_metrics(
773 + last_metrics, completion_tokens
774 + )
775 +
776 final_usage_chunk = ChatCompletionStreamResponse(
777 id=request_id,
778 object=chunk_object_type,
@@ -760,6 +781,7 @@ class OpenAIServingChat(GenerateBaseServing):
781 model=model_name,
782 usage=final_usage,
783 system_fingerprint=self.system_fingerprint,
784 + metrics=stream_per_request_metrics,
785 )
786 final_usage_data = final_usage_chunk.model_dump_json(
787 exclude_unset=True, exclude_none=True
@@ -1003,6 +1025,18 @@ class OpenAIServingChat(GenerateBaseServing):
1025
1026 request_metadata.final_usage_info = usage
1027
1028 + per_request_metrics: PerRequestTimingMetrics | None = None
1029 + if (
1030 + self.enable_per_request_metrics
1031 + # Timing metrics describe a single generation stream. For n>1 the
1032 + # returned stats belong to only one of the n sequences, so they
1033 + # cannot be accurately attributed to the request; suppress instead.
1034 + and (request.n or 1) == 1
1035 + ):
1036 + per_request_metrics = build_per_request_timing_metrics(
1037 + final_res.metrics, num_generated_tokens
1038 + )
1039 +
1040 # ``final_res.prompt`` is the rendered chat-templated prompt text
1041 prompt_text = final_res.prompt if request.return_prompt_text else None
1042
@@ -1019,6 +1053,7 @@ class OpenAIServingChat(GenerateBaseServing):
1053 ),
1054 prompt_text=prompt_text,
1055 kv_transfer_params=final_res.kv_transfer_params,
1056 + metrics=per_request_metrics,
1057 )
1058
1059 # Log complete response if output logging is enabled
vllm/entrypoints/openai/cli_args.py
+10 -3
@@ -25,12 +25,9 @@ from vllm.entrypoints.serve.utils.constants import (
25 H11_MAX_HEADER_COUNT_DEFAULT,
26 H11_MAX_INCOMPLETE_EVENT_SIZE_DEFAULT,
27 )
28 -from vllm.logger import init_logger
28 from vllm.tool_parsers import ToolParserManager
29 from vllm.utils.argparse_utils import FlexibleArgumentParser
30
32 -logger = init_logger(__name__)
33 -
31
32 class LoRAParserAction(argparse.Action):
33 def __call__(
@@ -134,6 +131,8 @@ class BaseFrontendArgs:
131 log. The default of None means unlimited."""
132 enable_prompt_tokens_details: bool = False
133 """If set to True, enable prompt_tokens_details in usage."""
134 + enable_per_request_metrics: bool = False
135 + """If set to True, include per-request timing metrics in API responses."""
136 enable_server_load_tracking: bool = False
137 """If set to True, enable tracking server_load_metrics in the app state."""
138 enable_force_include_usage: bool = False
@@ -398,6 +397,14 @@ def validate_parsed_serve_args(args: argparse.Namespace):
397 if args.enable_log_outputs and not args.enable_log_requests:
398 raise TypeError("Error: --enable-log-outputs requires --enable-log-requests")
399
400 + if getattr(args, "enable_per_request_metrics", False) and getattr(
401 + args, "disable_log_stats", False
402 + ):
403 + raise ValueError(
404 + "Error: --enable-per-request-metrics requires engine statistics "
405 + "logging; remove --disable-log-stats to enable per-request metrics."
406 + )
407 +
408 if args.data_parallel_multi_port_external_lb:
409 from vllm.entrypoints.openai.dp_supervisor import (
410 validate_multi_port_external_lb_args,
vllm/entrypoints/openai/completion/protocol.py
+3
@@ -15,6 +15,7 @@ from vllm.entrypoints.openai.engine.protocol import (
15 AnyResponseFormat,
16 LegacyStructuralTagResponseFormat,
17 OpenAIBaseModel,
18 + PerRequestTimingMetrics,
19 StreamOptions,
20 StructuralTagResponseFormat,
21 UsageInfo,
@@ -558,6 +559,7 @@ class CompletionResponse(OpenAIBaseModel):
559 kv_transfer_params: dict[str, Any] | None = Field(
560 default=None, description="KVTransfer parameters."
561 )
562 + metrics: PerRequestTimingMetrics | None = None
563
564
565 class CompletionResponseStreamChoice(OpenAIBaseModel):
@@ -589,3 +591,4 @@ class CompletionStreamResponse(OpenAIBaseModel):
591 # Set only on the final chunk of a stream to mirror non-streaming responses
592 # without the per-chunk serialization overhead.
593 system_fingerprint: str | None = None
594 + metrics: PerRequestTimingMetrics | None = None
vllm/entrypoints/openai/completion/serving.py
+42
@@ -16,6 +16,7 @@ from vllm.engine.protocol import EngineClient
16 from vllm.entrypoints.generate.base.serving import (
17 GenerateBaseServing,
18 GenerationError,
19 + build_per_request_timing_metrics,
20 clamp_prompt_logprobs,
21 format_token_id_placeholder,
22 )
@@ -29,6 +30,7 @@ from vllm.entrypoints.openai.completion.protocol import (
30 )
31 from vllm.entrypoints.openai.engine.protocol import (
32 ErrorResponse,
33 + PerRequestTimingMetrics,
34 PromptTokenUsageInfo,
35 RequestResponseMetadata,
36 UsageInfo,
@@ -61,6 +63,7 @@ class OpenAIServingCompletion(GenerateBaseServing):
63 return_tokens_as_token_ids: bool = False,
64 enable_prompt_tokens_details: bool = False,
65 enable_force_include_usage: bool = False,
66 + enable_per_request_metrics: bool = False,
67 ):
68 super().__init__(
69 engine_client=engine_client,
@@ -72,6 +75,7 @@ class OpenAIServingCompletion(GenerateBaseServing):
75 self.online_renderer = online_renderer
76 self.enable_prompt_tokens_details = enable_prompt_tokens_details
77 self.enable_force_include_usage = enable_force_include_usage
78 + self.enable_per_request_metrics = enable_per_request_metrics
79
80 self.default_sampling_params = self.model_config.get_diff_sampling_param()
81 mc = self.model_config
@@ -300,8 +304,10 @@ class OpenAIServingCompletion(GenerateBaseServing):
304 stream_options, self.enable_force_include_usage
305 )
306
307 + last_res: RequestOutput | None = None
308 try:
309 async for prompt_idx, res in result_generator:
310 + last_res = res
311 prompt_token_ids = res.prompt_token_ids
312 prompt_logprobs = res.prompt_logprobs
313
@@ -448,6 +454,23 @@ class OpenAIServingCompletion(GenerateBaseServing):
454 )
455
456 if include_usage:
457 + # In streaming, metrics ride on this final usage chunk, which is
458 + # only emitted when usage reporting is enabled (i.e.
459 + # ``stream_options.include_usage=true`` or
460 + # ``--enable-force-include-usage``).
461 + stream_per_request_metrics: PerRequestTimingMetrics | None = None
462 + if (
463 + self.enable_per_request_metrics
464 + # See note in request_output_to_completion_response: suppress
465 + # when not attributable to one stream (multi-prompt or n>1).
466 + and num_prompts == 1
467 + and (request.n or 1) == 1
468 + ):
469 + last_metrics = last_res.metrics if last_res is not None else None
470 + stream_per_request_metrics = build_per_request_timing_metrics(
471 + last_metrics, total_completion_tokens
472 + )
473 +
474 final_usage_chunk = CompletionStreamResponse(
475 id=request_id,
476 created=created_time,
@@ -455,6 +478,7 @@ class OpenAIServingCompletion(GenerateBaseServing):
478 choices=[],
479 usage=final_usage_info,
480 system_fingerprint=self.system_fingerprint,
481 + metrics=stream_per_request_metrics,
482 )
483 final_usage_data = final_usage_chunk.model_dump_json(
484 exclude_unset=False, exclude_none=True
@@ -589,6 +613,23 @@ class OpenAIServingCompletion(GenerateBaseServing):
613 )
614
615 request_metadata.final_usage_info = usage
616 +
617 + per_request_metrics: PerRequestTimingMetrics | None = None
618 + if (
619 + self.enable_per_request_metrics
620 + # Metrics describe a single generation stream, so suppress them when
621 + # they cannot be attributed to one: multiple prompts (timestamps
622 + # span prompts) or n>1 (stats belong to one of the n sequences).
623 + and len(final_res_batch) == 1
624 + and (request.n or 1) == 1
625 + ):
626 + last_metrics = (
627 + last_final_res.metrics if last_final_res is not None else None
628 + )
629 + per_request_metrics = build_per_request_timing_metrics(
630 + last_metrics, num_generated_tokens
631 + )
632 +
633 if final_res_batch:
634 kv_transfer_params = final_res_batch[0].kv_transfer_params
635 return CompletionResponse(
@@ -599,6 +640,7 @@ class OpenAIServingCompletion(GenerateBaseServing):
640 usage=usage,
641 system_fingerprint=self.system_fingerprint,
642 kv_transfer_params=kv_transfer_params,
643 + metrics=per_request_metrics,
644 )
645
646 def _create_completion_logprobs(
vllm/entrypoints/openai/engine/protocol.py
+8
@@ -115,6 +115,14 @@ class UsageInfo(OpenAIBaseModel):
115 prompt_tokens_details: PromptTokenUsageInfo | None = None
116
117
118 +class PerRequestTimingMetrics(OpenAIBaseModel):
119 + time_to_first_token_ms: float | None = None
120 + generation_time_ms: float | None = None
121 + queue_time_ms: float | None = None
122 + mean_itl_ms: float | None = None
123 + tokens_per_second: float | None = None
124 +
125 +
126 class RequestResponseMetadata(BaseModel):
127 request_id: str
128 final_usage_info: UsageInfo | None = None