@tduncan / Nvidia-Optimization-Stack-VLLM
Code Commits Issues Pulls Cloud Agent CI/CD
main
main
md 717 lines 33.2 KB
Rendered Raw
1 # Metrics
2
3 vLLM exposes a rich set of metrics to support observability and capacity planning for the V1 engine.
4
5 ## Objectives
6
7 - Provide comprehensive coverage of engine and request level metrics to aid production monitoring.
8 - Prioritize Prometheus integrations, as this is what we expect to be used in production environments.
9 - Offer logging support (i.e. printing metrics to the info log) for ad-hoc testing, debugging, development, and exploratory use cases.
10
11 ## Background
12
13 Metrics in vLLM can be categorized as follows:
14
15 1. Server-level metrics: Global metrics that track the state and performance of the LLM engine. These are typically exposed as Gauges or Counters in Prometheus.
16 2. Request-level metrics: Metrics that track the characteristics (e.g. size and timing) of individual requests. These are typically exposed as Histograms in Prometheus and are often the SLOs that an SRE monitoring vLLM will be tracking.
17
18 The mental model is that server-level metrics help explain the values of request-level metrics.
19
20 ### Metrics Overview
21
22 ### v1 Metrics
23
24 In v1, an extensive set of metrics are exposed via a Prometheus-compatible `/metrics` endpoint using the `vllm:` prefix, for example:
25
26 - `vllm:num_requests_running` (Gauge) - Number of requests currently running.
27 - `vllm:kv_cache_usage_perc` (Gauge) - Fraction of used KV cache blocks (0–1).
28 - `vllm:prefix_cache_queries` (Counter) - Number of prefix cache queries.
29 - `vllm:prefix_cache_hits` (Counter) - Number of prefix cache hits.
30 - `vllm:prompt_tokens_total` (Counter) - Total number of prompt tokens processed.
31 - `vllm:generation_tokens_total` (Counter) - Total number of generated tokens.
32 - `vllm:request_success_total` (Counter) - Number of finished requests (by finish reason).
33 - `vllm:request_prompt_tokens` (Histogram) - Histogram of input prompt token counts.
34 - `vllm:request_generation_tokens` (Histogram) - Histogram of generation token counts.
35 - `vllm:time_to_first_token_seconds` (Histogram) - Time to first token (TTFT).
36 - `vllm:inter_token_latency_seconds` (Histogram) - Inter-token latency (time between consecutive streamed outputs).
37 - `vllm:request_time_per_output_token_seconds` (Histogram) - Per-request Time Per Output Token (TPOT).
38 - `vllm:e2e_request_latency_seconds` (Histogram) - End-to-end request latency.
39 - `vllm:request_prefill_time_seconds` (Histogram) - Request prefill time.
40 - `vllm:request_decode_time_seconds` (Histogram) - Request decode time.
41
42 These are documented under [Inferencing and Serving -> Production Metrics](../usage/metrics.md).
43
44 ### Grafana Dashboard
45
46 vLLM also provides [a reference example](../../examples/observability/prometheus_grafana/README.md) for how to collect and store these metrics using Prometheus and visualize them using a Grafana dashboard.
47
48 The subset of metrics exposed in the Grafana dashboard gives us an indication of which metrics are especially important:
49
50 - `vllm:e2e_request_latency_seconds_bucket` - End to end request latency measured in seconds.
51 - `vllm:prompt_tokens` - Prompt tokens.
52 - `vllm:generation_tokens` - Generation tokens.
53 - `vllm:inter_token_latency_seconds` - Inter-token latency in seconds, measured between consecutive streamed outputs. It approximates TPOT when each output contains exactly one token, but differs from request-level TPOT when an output contains multiple tokens or when aggregation weights differ.
54 - `vllm:request_time_per_output_token_seconds` - Per-request Time Per Output Token (TPOT) in seconds, computed as `(end-to-end latency - TTFT) / (number of output tokens - 1)`. It is recorded as zero for requests that generate no more than one token.
55 - `vllm:time_to_first_token_seconds` - Time to First Token (TTFT) latency in seconds.
56 - `vllm:num_requests_running` (also, `_swapped` and `_waiting`) - Number of requests in the RUNNING, WAITING, and SWAPPED states.
57 - `vllm:kv_cache_usage_perc` - Percentage of used cache blocks by vLLM.
58 - `vllm:request_prompt_tokens` - Request prompt length.
59 - `vllm:request_generation_tokens` - Request generation length.
60 - `vllm:request_success` - Number of finished requests by their finish reason: either an EOS token was generated or the max sequence length was reached.
61 - `vllm:request_queue_time_seconds` - Queue time.
62 - `vllm:request_prefill_time_seconds` - Requests prefill time.
63 - `vllm:request_decode_time_seconds` - Requests decode time.
64 - `vllm:request_max_num_generation_tokens` - Max generation tokens in a sequence group.
65
66 See [the PR which added this Dashboard](https://github.com/vllm-project/vllm/pull/2316) for interesting and useful background on the choices made here.
67
68 `vllm:inter_token_latency_seconds` records one sample per streamed output event
69 (the wall-clock gap between successive outputs), whereas
70 `vllm:request_time_per_output_token_seconds` is recorded once per finished request
71 as `(end-to-end latency - TTFT) / (number of output tokens - 1)`. These two
72 metrics differ when an output bundles multiple tokens (e.g. speculative
73 decoding) or when mean ITL and mean per-request TPOT are aggregated over
74 differing weights. See [Understanding the latency metrics](../benchmarking/cli.md#understanding-the-latency-metrics)
75 for the benchmark definitions. Requests that generate no more than one token
76 are recorded with a TPOT of zero, while `vllm bench serve` excludes them from
77 its TPOT statistics. Therefore, the Prometheus histogram and benchmark TPOT
78 statistics can differ. Use `vllm:request_time_per_output_token_seconds` for
79 request-level TPOT and `vllm:inter_token_latency_seconds` when you specifically
80 want the inter-output latency distribution.
81
82 ### Prometheus Client Library
83
84 Prometheus support was initially added [using the aioprometheus library](https://github.com/vllm-project/vllm/pull/1890), but a switch was made quickly to [prometheus_client](https://github.com/vllm-project/vllm/pull/2730). The rationale is discussed in both linked PRs.
85
86 During those migrations we briefly lost a `MetricsMiddleware` to track HTTP metrics, but this was reinstated [using prometheus_fastapi_instrumentator](https://github.com/vllm-project/vllm/pull/15657):
87
88 ```bash
89 $ curl http://0.0.0.0:8000/metrics 2>/dev/null | grep -P '^http_(?!.*(_bucket|_created|_sum)).*'
90 http_requests_total{handler="/v1/completions",method="POST",status="2xx"} 201.0
91 http_request_size_bytes_count{handler="/v1/completions"} 201.0
92 http_response_size_bytes_count{handler="/v1/completions"} 201.0
93 http_request_duration_highr_seconds_count 201.0
94 http_request_duration_seconds_count{handler="/v1/completions",method="POST"} 201.0
95 ```
96
97 ### Multi-process Mode
98
99 Historically, metrics were collected in the engine core process and multiprocess mode was used to make them available in the API server process. See <https://github.com/vllm-project/vllm/pull/7279>.
100
101 More recently, metrics are collected in the API server process and multiprocess mode is only used when `--api-server-count > 1`. See <https://github.com/vllm-project/vllm/pull/17546> and details on [API server scale-out](../serving/data_parallel_deployment.md#internal-load-balancing).
102
103 ### Built in Python/Process Metrics
104
105 The following metrics are supported by default by `prometheus_client`, but they are not exposed when multiprocess mode is used:
106
107 - `python_gc_objects_collected_total`
108 - `python_gc_objects_uncollectable_total`
109 - `python_gc_collections_total`
110 - `python_info`
111 - `process_virtual_memory_bytes`
112 - `process_resident_memory_bytes`
113 - `process_start_time_seconds`
114 - `process_cpu_seconds_total`
115 - `process_open_fds`
116 - `process_max_fds`
117
118 Therefore, these metrics are unavailable when `--api-server-count > 1`. It's questionable how relevant these are since they do not aggregate these stats for all processes that make up a vLLM instance.
119
120 ## Metrics Design
121
122 The ["Even Better Observability"](https://github.com/vllm-project/vllm/issues/3616) feature where was where much of the metrics design was planned. For example, see where [a detailed roadmap was laid out](https://github.com/vllm-project/vllm/issues/3616#issuecomment-2030858781).
123
124 ### Legacy PRs
125
126 To help understand the background to the metrics design, here are some of the relevant PRs which added the original, now legacy, metrics:
127
128 - <https://github.com/vllm-project/vllm/pull/1890>
129 - <https://github.com/vllm-project/vllm/pull/2316>
130 - <https://github.com/vllm-project/vllm/pull/2730>
131 - <https://github.com/vllm-project/vllm/pull/4464>
132 - <https://github.com/vllm-project/vllm/pull/7279>
133
134 ### Metrics Implementation PRs
135
136 For background, here are the relevant PRs relating to the metrics implementation <https://github.com/vllm-project/vllm/issues/10582>:
137
138 - <https://github.com/vllm-project/vllm/pull/11962>
139 - <https://github.com/vllm-project/vllm/pull/11973>
140 - <https://github.com/vllm-project/vllm/pull/10907>
141 - <https://github.com/vllm-project/vllm/pull/12416>
142 - <https://github.com/vllm-project/vllm/pull/12478>
143 - <https://github.com/vllm-project/vllm/pull/12516>
144 - <https://github.com/vllm-project/vllm/pull/12530>
145 - <https://github.com/vllm-project/vllm/pull/12561>
146 - <https://github.com/vllm-project/vllm/pull/12579>
147 - <https://github.com/vllm-project/vllm/pull/12592>
148 - <https://github.com/vllm-project/vllm/pull/12644>
149
150 ### Metrics Collection
151
152 In v1, we wish to move computation and overhead out of the engine core
153 process to minimize the time between each forward pass.
154
155 The overall idea of V1 EngineCore design is:
156
157 - EngineCore is the inner loop. Performance is most critical here
158 - AsyncLLM is the outer loop. This is overlapped with GPU execution
159 (ideally), so this is where any "overheads" should be if
160 possible. So AsyncLLM.output_handler_loop is the ideal place for the
161 metrics bookkeeping if possible.
162
163 We will achieve this by collecting metrics in the frontend API server,
164 and base these metrics on information we can glean from the
165 `EngineCoreOutputs` returned by the engine core process to the
166 frontend.
167
168 ### Interval Calculations
169
170 Many of our metrics are the time interval between various events in
171 the processing of a request. It is best practice to use timestamps
172 based on "monotonic time" (`time.monotonic()`) rather than "wall-clock
173 time" (`time.time()`) to calculate intervals as the former is
174 unaffected by system clock changes (e.g. from NTP).
175
176 It's also important to note that monotonic clocks differ between
177 processes - each process has its own reference point. So it is
178 meaningless to compare monotonic timestamps from different processes.
179
180 Therefore, in order to calculate an interval, we must compare two
181 monotonic timestamps from the same process.
182
183 ### Scheduler Stats
184
185 The engine core process will collect some key statistics from the
186 scheduler - e.g. the number of requests that were scheduled or waiting
187 after the last scheduler pass - and include those statistics in
188 `EngineCoreOutputs`.
189
190 ### Engine Core Events
191
192 The engine core will also record the timestamp of certain per-request
193 events so that the frontend can calculate the interval between these
194 events.
195
196 The events are:
197
198 - `QUEUED` - when the request was received by the engine core and
199 added to the scheduler queue.
200 - `SCHEDULED` - when the request was first scheduled for execution.
201 - `PREEMPTED` - the request has been put back in the waiting queue
202 in order to make room for other requests to complete. It will be
203 re-scheduled in future and re-start its prefill phase.
204 - `NEW_TOKENS` - when the output included in `EngineCoreOutput` was
205 generated. Since this is common to all requests in a given
206 iteration, we use a single timestamp on `EngineCoreOutputs` to
207 record this event.
208
209 And the calculated intervals are:
210
211 - Queue interval - between `QUEUED` and most recent `SCHEDULED`.
212 - Prefill interval - between most recent `SCHEDULED` and the subsequent
213 first `NEW_TOKENS`.
214 - Decode interval - between first (after the most recent `SCHEDULED`) and
215 last `NEW_TOKENS`.
216 - Inference interval - between most recent `SCHEDULED` and last `NEW_TOKENS`.
217 - Inter-token interval - between successive `NEW_TOKENS`.
218
219 Put another way:
220
221 ![Interval calculations - common case](../assets/design/metrics/intervals-1.png)
222
223 We explored the possibility of having the frontend calculate these
224 intervals using the timing of events visible by the frontend. However,
225 the frontend does not have visibility into the timing of the `QUEUED`
226 and `SCHEDULED` events and, since we need to calculate intervals based
227 on monotonic timestamps from the same process ... we need the engine
228 core to record timestamps for all of these events.
229
230 #### Interval Calculations vs Preemptions
231
232 When a preemption occurs during decode, since any already generated
233 tokens are reused, we consider the preemption as affecting the
234 inter-token, decode, and inference intervals.
235
236 ![Interval calculations - preempted decode](../assets/design/metrics/intervals-2.png)
237
238 When a preemption occurs during prefill (assuming such an event
239 is possible), we consider the preemption as affecting the
240 time-to-first-token and prefill intervals.
241
242 ![Interval calculations - preempted prefill](../assets/design/metrics/intervals-3.png)
243
244 ### Frontend Stats Collection
245
246 As the frontend processes a single `EngineCoreOutputs` - i.e. the
247 output from a single engine core iteration - it collects various
248 statistics relating to that iteration:
249
250 - The total number of new tokens generated in this iteration.
251 - The total number of prompt tokens processed by the prefills that
252 completed in this iteration.
253 - The queue intervals for any requests that were scheduled in this
254 iteration.
255 - The prefill intervals for any requests that completed prefill in
256 this iteration.
257 - The inter-token intervals, for all requests included in this iteration.
258 - The Time-To-First-Token (TTFT) for any requests that completed
259 prefill in this iteration. However, we calculate this interval
260 relative to when the request was first received by the frontend
261 (`arrival_time`) in order to account for input processing time.
262 Currently `arrival_time` starts when tokenization begins.
263
264 For any requests that were completed in a given iteration, we also
265 record:
266
267 - The inference and decode intervals - relative to the scheduled and
268 first token events, as described above.
269 - End-to-end latency - the interval between frontend `arrival_time`
270 and the frontend receiving the final token.
271
272 ### KV Cache Residency Metrics
273
274 We also emit a set of histograms that describe how long sampled KV cache
275 blocks stay resident and how often they are reused. Sampling
276 (`--kv-cache-metrics-sample`) keeps the overhead tiny; when a block is
277 chosen we record:
278
279 - `lifetime` – allocation ⟶ eviction
280 - `idle before eviction` – last touch ⟶ eviction
281 - `reuse gaps` – the pauses between touches when the block gets reused
282
283 Those map directly to the Prometheus metrics:
284
285 - `vllm:kv_block_lifetime_seconds` – how long each sampled block exists.
286 - `vllm:kv_block_idle_before_evict_seconds` – idle tail after the final access.
287 - `vllm:kv_block_reuse_gap_seconds` – time between consecutive touches.
288
289 The engine core only ships raw eviction events via `SchedulerStats`; the
290 frontend drains them, turns them into Prometheus observations, and also
291 exposes the same data through `LLM.get_metrics()` when logging is on.
292 Looking at lifetime and idle time on one chart makes it easy to spot
293 stranded cache or workloads that pin prompts for a long decode.
294
295 ### Metrics Publishing - Logging
296
297 The `LoggingStatLogger` metrics publisher outputs a log `INFO` message
298 every 5 seconds with some key metrics:
299
300 - The current number of running/waiting requests
301 - The current GPU cache usage
302 - The number of prompt tokens processed per second over the past 5
303 seconds
304 - The number of new tokens generated per second over the past 5
305 seconds
306 - The prefix cache hit rate over the most recent 1k kv-cache block queries
307
308 ### Metrics Publishing - Prometheus
309
310 The `PrometheusStatLogger` metrics publisher makes the metrics
311 available via a `/metrics` HTTP endpoint in a Prometheus-compatible
312 format. A Prometheus instance can then be configured to poll this
313 endpoint (e.g. every second) and record the values in its time-series
314 database. Prometheus is often used via Grafana, allowing these metrics
315 to be graphed over time.
316
317 Prometheus supports the following metric types:
318
319 - Counter: a value that will increase over time, never reducing, and
320 generally reset to zero when the vLLM instance restarts. For
321 example, the number of tokens generated over the lifetime of the
322 instance.
323 - Gauge: a value that goes up and down, for example the number of
324 requests currently scheduled for execution.
325 - Histogram: a count of metric samples, recorded in buckets. For
326 example, the number of requests whose TTFT was <1ms, <5ms, <10ms,
327 <20ms, and so on.
328
329 Prometheus metrics can also be labelled, allowing metrics to be
330 combined according to matching labels. In vLLM, we add a `model_name`
331 label to every metric which includes the name of the model served by
332 that instance.
333
334 Example output:
335
336 ```bash
337 $ curl http://0.0.0.0:8000/metrics
338 # HELP vllm:num_requests_running Number of requests in model execution batches.
339 # TYPE vllm:num_requests_running gauge
340 vllm:num_requests_running{model_name="meta-llama/Llama-3.1-8B-Instruct"} 8.0
341 ...
342 # HELP vllm:generation_tokens_total Number of generation tokens processed.
343 # TYPE vllm:generation_tokens_total counter
344 vllm:generation_tokens_total{model_name="meta-llama/Llama-3.1-8B-Instruct"} 27453.0
345 ...
346 # HELP vllm:request_success_total Count of successfully processed requests.
347 # TYPE vllm:request_success_total counter
348 vllm:request_success_total{finished_reason="stop",model_name="meta-llama/Llama-3.1-8B-Instruct"} 1.0
349 vllm:request_success_total{finished_reason="length",model_name="meta-llama/Llama-3.1-8B-Instruct"} 131.0
350 vllm:request_success_total{finished_reason="abort",model_name="meta-llama/Llama-3.1-8B-Instruct"} 0.0
351 ...
352 # HELP vllm:time_to_first_token_seconds Histogram of time to first token in seconds.
353 # TYPE vllm:time_to_first_token_seconds histogram
354 vllm:time_to_first_token_seconds_bucket{le="0.001",model_name="meta-llama/Llama-3.1-8B-Instruct"} 0.0
355 vllm:time_to_first_token_seconds_bucket{le="0.005",model_name="meta-llama/Llama-3.1-8B-Instruct"} 0.0
356 vllm:time_to_first_token_seconds_bucket{le="0.01",model_name="meta-llama/Llama-3.1-8B-Instruct"} 0.0
357 vllm:time_to_first_token_seconds_bucket{le="0.02",model_name="meta-llama/Llama-3.1-8B-Instruct"} 13.0
358 vllm:time_to_first_token_seconds_bucket{le="0.04",model_name="meta-llama/Llama-3.1-8B-Instruct"} 97.0
359 vllm:time_to_first_token_seconds_bucket{le="0.06",model_name="meta-llama/Llama-3.1-8B-Instruct"} 123.0
360 vllm:time_to_first_token_seconds_bucket{le="0.08",model_name="meta-llama/Llama-3.1-8B-Instruct"} 138.0
361 vllm:time_to_first_token_seconds_bucket{le="0.1",model_name="meta-llama/Llama-3.1-8B-Instruct"} 140.0
362 vllm:time_to_first_token_seconds_count{model_name="meta-llama/Llama-3.1-8B-Instruct"} 140.0
363 ```
364
365 !!! note
366 The choice of histogram buckets to be most useful to users
367 across a broad set of use cases is not straightforward and will
368 require refinement over time.
369
370 ### Cache Config Info
371
372 `prometheus_client` has support for
373 [Info metrics](https://prometheus.github.io/client_python/instrumenting/info/)
374 which are equivalent to a `Gauge` whose value is permanently set to 1,
375 but exposes interesting key/value pair information via labels. This is
376 used for information about an instance that does not change - so it
377 only needs to be observed at startup - and allows comparing across
378 instances in Prometheus.
379
380 We use this concept for the `vllm:cache_config_info` metric:
381
382 ```text
383 # HELP vllm:cache_config_info Information of the LLMEngine CacheConfig
384 # TYPE vllm:cache_config_info gauge
385 vllm:cache_config_info{block_size="16",cache_dtype="auto",cpu_offload_gb="0",enable_prefix_caching="False",gpu_memory_utilization="0.9",...} 1.0
386 ```
387
388 However, `prometheus_client` has
389 [never supported Info metrics in multiprocessing mode](https://github.com/prometheus/client_python/pull/300) -
390 for [unclear reasons](gh-pr:7279#discussion_r1710417152). We
391 simply use a `Gauge` metric set to 1 and
392 `multiprocess_mode="mostrecent"` instead.
393
394 ### LoRA Metrics
395
396 The `vllm:lora_requests_info` `Gauge` is somewhat similar, except the
397 value is the current wall-clock time, and is updated every iteration.
398
399 The label names used are:
400
401 - `running_lora_adapters`: a per-adapter count of the number requests
402 running using that adapter, formatted as a comma-separated string.
403 - `waiting_lora_adapters`: similar, except counting requests that are
404 waiting to be scheduled.
405 - `max_lora` - the static "max number of LoRAs in a single batch."
406 configuration.
407
408 Encoding a running/waiting counts for multiple adapters in a
409 comma-separated string seems quite misguided - we could use labels to
410 distinguish between per-adapter counts. This should be revisited.
411
412 Note that `multiprocess_mode="livemostrecent"` is used - the most
413 recent metric is used, but only from currently running processes.
414
415 This was added in <https://github.com/vllm-project/vllm/pull/9477> and there is
416 [at least one known user](https://github.com/kubernetes-sigs/gateway-api-inference-extension/pull/54).
417 If we revisit this design and deprecate the old metric, we should
418 coordinate with downstream users so they can migrate before the removal.
419
420 ### Prefix Cache metrics
421
422 The discussion in <https://github.com/vllm-project/vllm/issues/10582> about adding prefix cache metrics yielded
423 some interesting points which may be relevant to how we approach
424 future metrics.
425
426 Every time the prefix cache is queried, we record the number of tokens
427 queried and the number of queried tokens present in the cache
428 (i.e. hits).
429
430 However, the metric of interest is the hit rate - i.e. the number of
431 hits per query.
432
433 In the case of logging, we expect the user is best served by
434 calculating the hit rate over a fixed number of the most recent
435 queries (the interval is fixed to 1k most recent queries for now).
436
437 In the case of Prometheus though, we should take advantage of the
438 time-series nature of Prometheus and allow the user to calculate the
439 hit rate over an interval of their choosing. For example, a PromQL
440 query to calculate the hit interval of the past 5 minutes:
441
442 ```text
443 rate(cache_query_hit[5m]) / rate(cache_query_total[5m])
444 ```
445
446 To achieve this, we should record the queries and hits as counters in
447 Prometheus, rather than recording the hit rate as a gauge.
448
449 ## Deprecated Metrics
450
451 ### How To Deprecate
452
453 Deprecating metrics shouldn't be taken lightly. Users may not notice a
454 metric has been deprecated, and may be quite inconvenienced when it is
455 suddenly (from their perspective) when it is removed, even if there is
456 an equivalent metric for them to use.
457
458 As an example, see how `vllm:avg_prompt_throughput_toks_per_s` was
459 [deprecated](https://github.com/vllm-project/vllm/pull/2764) (with a comment in the code),
460 [removed](https://github.com/vllm-project/vllm/pull/12383), and then [noticed by a user](https://github.com/vllm-project/vllm/issues/13218).
461
462 In general:
463
464 1. We should be cautious about deprecating metrics, especially since
465 it can be hard to predict the user impact.
466 2. We should include a prominent deprecation notice in the help string
467 that is included in the `/metrics' output.
468 3. We should list deprecated metrics in user-facing documentation and
469 release notes.
470 4. We should consider hiding deprecated metrics behind a CLI argument
471 in order to give administrators
472 [an escape hatch](https://kubernetes.io/docs/concepts/cluster-administration/system-metrics/#show-hidden-metrics)
473 for some time before deleting them.
474
475 See the [deprecation policy](../contributing/deprecation_policy.md) for
476 the project-wide deprecation policy.
477
478 ### Unimplemented - `vllm:tokens_total`
479
480 Added by <https://github.com/vllm-project/vllm/pull/4464>, but apparently never implemented. This can just be
481 removed.
482
483 ### Duplicated - Queue Time
484
485 The `vllm:time_in_queue_requests` Histogram metric was added by
486 <https://github.com/vllm-project/vllm/pull/9659> and its calculation is:
487
488 ```python
489 self.metrics.first_scheduled_time = now
490 self.metrics.time_in_queue = now - self.metrics.arrival_time
491 ```
492
493 Two weeks later, <https://github.com/vllm-project/vllm/pull/4464> added `vllm:request_queue_time_seconds` leaving
494 us with:
495
496 ```python
497 if seq_group.is_finished():
498 if (seq_group.metrics.first_scheduled_time is not None and
499 seq_group.metrics.first_token_time is not None):
500 time_queue_requests.append(
501 seq_group.metrics.first_scheduled_time -
502 seq_group.metrics.arrival_time)
503 ...
504 if seq_group.metrics.time_in_queue is not None:
505 time_in_queue_requests.append(
506 seq_group.metrics.time_in_queue)
507 ```
508
509 This seems duplicative, and one of them should be removed. The latter
510 is used by the Grafana dashboard, so we should deprecate or remove the
511 former.
512
513 ### Prefix Cache Hit Rate
514
515 See above - we now expose 'queries' and 'hits' counters rather than a
516 'hit rate' gauge.
517
518 ### KV Cache Offloading
519
520 Two legacy metrics relate to a "swapped" preemption mode that is no
521 longer relevant in v1:
522
523 - `vllm:num_requests_swapped`
524 - `vllm:cpu_cache_usage_perc`
525
526 In this mode, when a request was preempted (e.g. to make room in KV
527 cache to complete other requests), kv cache blocks were swapped out to
528 CPU memory. The `--swap-space` flag has been removed as this feature
529 is no longer used in V1.
530
531 Historically, [vLLM has long supported beam search](https://github.com/vllm-project/vllm/issues/6226). The
532 SequenceGroup encapsulated the idea of N Sequences which
533 all shared the same prompt kv blocks. This enabled KV cache block
534 sharing between requests, and copy-on-write to do branching. CPU
535 swapping was intended for these beam search like cases.
536
537 Later, the concept of prefix caching was introduced, which allowed KV
538 cache blocks to be shared implicitly. This proved to be a better
539 option than CPU swapping since blocks can be evicted slowly on demand
540 and the part of the prompt that was evicted can be recomputed.
541
542 SequenceGroup was removed in V1, although a replacement will be
543 required for "parallel sampling" (`n>1`).
544 [Beam search was moved out of the core](https://github.com/vllm-project/vllm/issues/8306). There was a
545 lot of complex code for a very uncommon feature.
546
547 In V1, with prefix caching being better (zero over head) and therefore
548 on by default, the preemption and recompute strategy should work
549 better.
550
551 ## Future Work
552
553 ### Parallel Sampling
554
555 Some legacy metrics are only relevant in the context of "parallel
556 sampling". This is where the `n` parameter in a request is used to
557 request multiple completions from the same prompt.
558
559 As part of adding parallel sampling support in <https://github.com/vllm-project/vllm/pull/10980>, we should
560 also add these metrics.
561
562 - `vllm:request_params_n` (Histogram)
563
564 Observes the value of the 'n' parameter of every finished request.
565
566 - `vllm:request_max_num_generation_tokens` (Histogram)
567
568 Observes the maximum output length of all sequences in every finished
569 sequence group. In the absence of parallel sampling, this is
570 equivalent to `vllm:request_generation_tokens`.
571
572 ### Speculative Decoding
573
574 Some legacy metrics are specific to "speculative decoding". This is where
575 we generate candidate tokens using a faster, approximate method or
576 model and then validate those tokens with the larger model.
577
578 - `vllm:spec_decode_draft_acceptance_rate` (Gauge)
579 - `vllm:spec_decode_efficiency` (Gauge)
580 - `vllm:spec_decode_num_accepted_tokens` (Counter)
581 - `vllm:spec_decode_num_draft_tokens` (Counter)
582 - `vllm:spec_decode_num_emitted_tokens` (Counter)
583
584 There is a PR under review (<https://github.com/vllm-project/vllm/pull/12193>) to add "prompt lookup (ngram)"
585 speculative decoding to v1. Other techniques will follow. We should
586 revisit these metrics in this context.
587
588 !!! note
589 We should probably expose acceptance rate as separate accepted
590 and draft counters, like we do for prefix caching hit rate. Efficiency
591 likely also needs similar treatment.
592
593 ### Autoscaling and Load-balancing
594
595 A common use case for our metrics is to support automated scaling of
596 vLLM instances.
597
598 For related discussion from the
599 [Kubernetes Serving Working Group](https://github.com/kubernetes/community/tree/master/wg-serving),
600 see:
601
602 - [Standardizing Large Model Server Metrics in Kubernetes](https://docs.google.com/document/d/1SpSp1E6moa4HSrJnS4x3NpLuj88sMXr2tbofKlzTZpk)
603 - [Benchmarking LLM Workloads for Performance Evaluation and Autoscaling in Kubernetes](https://docs.google.com/document/d/1k4Q4X14hW4vftElIuYGDu5KDe2LtV1XammoG-Xi3bbQ)
604 - [Inference Perf](https://github.com/kubernetes-sigs/wg-serving/tree/main/proposals/013-inference-perf)
605 - <https://github.com/vllm-project/vllm/issues/5041> and <https://github.com/vllm-project/vllm/pull/12726>.
606
607 This is a non-trivial topic. Consider this comment from Rob:
608
609 > I think this metric should focus on trying to estimate what the max
610 > concurrency that will cause the average request length > queries per
611 > second ... since this is really what will "saturate" the server.
612
613 A clear goal is that we should expose the metrics required to detect
614 this saturation point, so administrators can implement auto-scaling
615 rules based on those. However, in order to do so, we need to have a
616 clear view on how an administrator (and automated monitoring system)
617 should judge an instance as approaching saturation:
618
619 > To identify, what is the saturation point for model server compute
620 > (the inflection point where we cannot get more throughput with a
621 > higher request rate, but start to incur additional latency) so we
622 > can autoscale effectively?
623
624 ### Metric Naming
625
626 Our approach to naming metrics probably deserves to be revisited:
627
628 1. The use of colons in metric names seems contrary to
629 ["colons are reserved for user defined recording rules"](https://prometheus.io/docs/concepts/data_model/#metric-names-and-labels).
630 2. Most of our metrics follow the convention of ending with units, but
631 not all do.
632 3. Some of our metric names end with `_total`:
633
634 If there is a suffix of `_total` on the metric name, it will be removed. When
635 exposing the time series for counter, a `_total` suffix will be added. This is
636 for compatibility between OpenMetrics and the Prometheus text format, as OpenMetrics
637 requires the `_total` suffix.
638
639 ### Adding More Metrics
640
641 There is no shortage of ideas for new metrics:
642
643 - Examples from other projects like
644 [TGI](https://github.com/IBM/text-generation-inference?tab=readme-ov-file#metrics)
645 - Proposals arising from specific use cases, like the Kubernetes
646 auto-scaling topic above
647 - Proposals that might arise out of standardisation efforts like
648 [OpenTelemetry Semantic Conventions for Gen AI](https://github.com/open-telemetry/semantic-conventions/tree/main/docs/gen-ai).
649
650 We should be cautious in our approach to adding new metrics. While
651 metrics are often relatively straightforward to add:
652
653 1. They can be difficult to remove - see the section on deprecation
654 above.
655 2. They can have a meaningful performance impact when enabled. And
656 metrics are usually of very limited use unless they can be enabled
657 by default and in production.
658 3. They have an impact on development and maintenance of the
659 project. Every metric added over time has made this effort more
660 time-consuming, and perhaps not all metrics justify this ongoing
661 investment in their maintenance.
662
663 ## Tracing - OpenTelemetry
664
665 Metrics provide an aggregated view over time of the system's
666 performance and health. Tracing, on the other hand, tracks individual
667 requests as they move through different services and components. Both
668 fall under the more general heading of "Observability".
669
670 vLLM has support for OpenTelemetry tracing:
671
672 - Added by <https://github.com/vllm-project/vllm/pull/4687> and reinstated by <https://github.com/vllm-project/vllm/pull/20372>
673 - Configured with `--otlp-traces-endpoint` and `--collect-detailed-traces`
674 - [OpenTelemetry blog post](https://opentelemetry.io/blog/2024/llm-observability/)
675 - [User-facing docs](../../examples/observability/opentelemetry/README.md)
676 - [Blog post](https://medium.com/@ronen.schaffer/follow-the-trail-supercharging-vllm-with-opentelemetry-distributed-tracing-aa655229b46f)
677 - [IBM product docs](https://www.ibm.com/docs/en/instana-observability/current?topic=mgaa-monitoring-large-language-models-llms-vllm-public-preview)
678
679 OpenTelemetry has a
680 [Gen AI Working Group](https://github.com/open-telemetry/community/blob/main/projects/gen-ai.md).
681
682 Since metrics is a big enough topic on its own, we consider the topic
683 of tracing to be quite separate from metrics.
684
685 ### OpenTelemetry Model Forward vs Execute Time
686
687 The current implementation exposes the following two metrics:
688
689 - `vllm:model_forward_time_milliseconds` (Histogram) - The time spent
690 in the model forward pass when this request was in the batch.
691 - `vllm:model_execute_time_milliseconds` (Histogram) - The time spent
692 in the model execute function. This will include model forward,
693 block/sync across workers, cpu-gpu sync time and sampling time.
694
695 These metrics are only enabled when OpenTelemetry tracing is enabled
696 and if `--collect-detailed-traces=all/model/worker` is used. The
697 documentation for this option states:
698
699 > collect detailed traces for the specified modules. This involves
700 > use of possibly costly and or blocking operations and hence might
701 > have a performance impact.
702
703 The metrics were added by <https://github.com/vllm-project/vllm/pull/7089> and show up in an OpenTelemetry trace
704 as:
705
706 ```text
707 -> gen_ai.latency.time_in_scheduler: Double(0.017550230026245117)
708 -> gen_ai.latency.time_in_model_forward: Double(3.151565277099609)
709 -> gen_ai.latency.time_in_model_execute: Double(3.6468167304992676)
710 ```
711
712 We already have `inference_time` and `decode_time` metrics, so the
713 question is whether there are sufficiently common use cases for the
714 higher-resolution timings to justify the overhead.
715
716 Since we are going to treat the question of OpenTelemetry support
717 separately, we will include these particular metrics under that topic.