c2bd2196fc · tduncan/Nvidia-Optimization-Stack-VLLM

@@ -0,0 +1,712 @@

1 +# Metrics

2 +

3 +Ensure the v1 LLM Engine exposes a superset of the metrics available in v0.

4 +

5 +## Objectives

6 +

7 +- Achieve parity of metrics between v0 and v1.

8 +- The priority use case is accessing these metrics via Prometheus as this is what we expect to be used in production environments.

9 +- Logging support - i.e. printing metrics to the info log - is provided for more 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: these are 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: these are metrics that track the characteristics - e.g. size and timing - of individual requests. These are typically exposed as Histrograms in Prometheus, and are often the SLO that an SRE monitoring vLLM will be tracking.

17 +

18 +The mental model is that the "Server-level Metrics" explain why the "Request-level Metrics" are what they are.

19 +

20 +### v0 Metrics

21 +

22 +In v0, the following metrics are exposed via a Prometheus-compatible `/metrics` endpoint using the `vllm:` prefix:

23 +

24 +- `vllm:num_requests_running` (Gauge)

25 +- `vllm:num_requests_swapped` (Gauge)

26 +- `vllm:num_requests_waiting` (Gauge)

27 +- `vllm:gpu_cache_usage_perc` (Gauge)

28 +- `vllm:cpu_cache_usage_perc` (Gauge)

29 +- `vllm:gpu_prefix_cache_hit_rate` (Gauge)

30 +- `vllm:cpu_prefix_cache_hit_rate` (Gauge)

31 +- `vllm:prompt_tokens_total` (Counter)

32 +- `vllm:generation_tokens_total` (Counter)

33 +- `vllm:request_success_total` (Counter)

34 +- `vllm:request_prompt_tokens` (Histogram)

35 +- `vllm:request_generation_tokens` (Histogram)

36 +- `vllm:time_to_first_token_seconds` (Histogram)

37 +- `vllm:time_per_output_token_seconds` (Histogram)

38 +- `vllm:e2e_request_latency_seconds` (Histogram)

39 +- `vllm:request_queue_time_seconds` (Histogram)

40 +- `vllm:request_inference_time_seconds` (Histogram)

41 +- `vllm:request_prefill_time_seconds` (Histogram)

42 +- `vllm:request_decode_time_seconds` (Histogram)

43 +- `vllm:request_max_num_generation_tokens` (Histogram)

44 +- `vllm:num_preemptions_total` (Counter)

45 +- `vllm:cache_config_info` (Gauge)

46 +- `vllm:lora_requests_info` (Gauge)

47 +- `vllm:tokens_total` (Counter)

48 +- `vllm:iteration_tokens_total` (Histogram)

49 +- `vllm:time_in_queue_requests` (Histogram)

50 +- `vllm:model_forward_time_milliseconds` (Histogram

51 +- `vllm:model_execute_time_milliseconds` (Histogram)

52 +- `vllm:request_params_n` (Histogram)

53 +- `vllm:request_params_max_tokens` (Histogram)

54 +- `vllm:spec_decode_draft_acceptance_rate` (Gauge)

55 +- `vllm:spec_decode_efficiency` (Gauge)

56 +- `vllm:spec_decode_num_accepted_tokens_total` (Counter)

57 +- `vllm:spec_decode_num_draft_tokens_total` (Counter)

58 +- `vllm:spec_decode_num_emitted_tokens_total` (Counter)

59 +

60 +These are documented under [Inferencing and Serving -> Production Metrics](project:../../serving/metrics.md).

61 +

62 +### Grafana Dashboard

63 +

64 +vLLM also provides [a reference example](https://docs.vllm.ai/en/latest/getting_started/examples/prometheus_grafana.html) for how to collect and store these metrics using Prometheus and visualize them using a Grafana dashboard.

65 +

66 +The subset of metrics exposed in the Grafana dashboard gives us an indication of which metrics are especially important:

67 +

68 +- `vllm:e2e_request_latency_seconds_bucket` - End to end request latency measured in seconds

69 +- `vllm:prompt_tokens_total` - Prompt Tokens/Sec

70 +- `vllm:generation_tokens_total` - Generation Tokens/Sec

71 +- `vllm:time_per_output_token_seconds` - Inter token latency (Time Per Output Token, TPOT) in second.

72 +- `vllm:time_to_first_token_seconds` - Time to First Token (TTFT) latency in seconds.

73 +- `vllm:num_requests_running` (also, `_swapped` and `_waiting`) - Number of requests in RUNNING, WAITING, and SWAPPED state

74 +- `vllm:gpu_cache_usage_perc` - Percentage of used cache blocks by vLLM.

75 +- `vllm:request_prompt_tokens` - Request prompt length

76 +- `vllm:request_generation_tokens` - request generation length

77 +- `vllm:request_success_total` - Number of finished requests by their finish reason: either an EOS token was generated or the max sequence length was reached

78 +- `vllm:request_queue_time_seconds` - Queue Time

79 +- `vllm:request_prefill_time_seconds` - Requests Prefill Time

80 +- `vllm:request_decode_time_seconds` - Requests Decode Time

81 +- `vllm:request_max_num_generation_tokens` - Max Generation Token in Sequence Group

82 +

83 +See [the PR which added this Dashboard](gh-pr:2316) for interesting and useful background on the choices made here.

84 +

85 +### Prometheus Client Library

86 +

87 +Prometheus support was initially added [using the aioprometheus library](gh-pr:1890), but a switch was made quickly to [prometheus_client](gh-pr:2730). The rationale is discussed in both linked PRs.

88 +

89 +### Multi-process Mode

90 +

91 +In v0, metrics are collected in the engine core process and we use multi-process mode to make them available in the API server process. See <gh-pr:7279>.

92 +

93 +### Built in Python/Process Metrics

94 +

95 +The following metrics are supported by default by `prometheus_client`, but the are not exposed with multiprocess mode is used:

96 +

97 +- `python_gc_objects_collected_total`

98 +- `python_gc_objects_uncollectable_total`

99 +- `python_gc_collections_total`

100 +- `python_info`

101 +- `process_virtual_memory_bytes`

102 +- `process_resident_memory_bytes`

103 +- `process_start_time_seconds`

104 +- `process_cpu_seconds_total`

105 +- `process_open_fds`

106 +- `process_max_fds`

107 +

108 +This is relevant because if we move away from multiprocess mode in v1,

109 +we get these back. However, it's questionable how relevant these are

110 +if they don't aggregate these stats for all processes that make up a

111 +vLLM instance.

112 +

113 +### v0 PRs and Issues

114 +

115 +For background, these are some of the relevant PRs which added the v0 metrics:

116 +

117 +- <gh-pr:1890>

118 +- <gh-pr:2316>

119 +- <gh-pr:2730>

120 +- <gh-pr:4464>

121 +- <gh-pr:7279>

122 +

123 +Also note the ["Even Better Observability"](gh-issue:3616) feature where e.g. [a detailed roadmap was laid out](gh-issue:3616#issuecomment-2030858781).

124 +

125 +## v1 Design

126 +

127 +### v1 PRs

128 +

129 +For background, here are the relevant v1 PRs relating to the v1

130 +metrics issue <gh-issue:10582>:

131 +

132 +- <gh-pr:11962>

133 +- <gh-pr:11973>

134 +- <gh-pr:10907>

135 +- <gh-pr:12416>

136 +- <gh-pr:12478>

137 +- <gh-pr:12516>

138 +- <gh-pr:12530>

139 +- <gh-pr:12561>

140 +- <gh-pr:12579>

141 +- <gh-pr:12592>

142 +- <gh-pr:12644>

143 +

144 +### Metrics Collection

145 +

146 +In v1, we wish to move computation and overhead out of the engine core

147 +process to minimize the time between each forward pass.

148 +

149 +The overall idea of V1 EngineCore design is:

150 +- EngineCore is the inner loop. Performance is most critical here

151 +- AsyncLLM is the outer loop. This is overlapped with GPU execution

152 + (ideally), so this is where any "overheads" should be if

153 + possible. So AsyncLLM.output_handler_loop is the ideal place for the

154 + metrics bookkeeping if possible.

155 +

156 +We will achieve this by collecting metrics in the frontend API server,

157 +and base these metrics on information we can glean from the

158 +`EngineCoreOutputs` returned by the engine core process to the

159 +frontend.

160 +

161 +### Interval Calculations

162 +

163 +Many of our metrics are the time interval between various events in

164 +the processing of a request. It is best practice to use timestamps

165 +based on "monotonic time" (`time.monotonic()`) rather than "wall-clock

166 +time" (`time.time()`) to calculate intervals as the former is

167 +unaffected by system clock changes (e.g. from NTP).

168 +

169 +It's also important to note that monotonic clocks differ between

170 +processes - each process has its own reference. point. So it is

171 +meaningless to compare monotonic timestamps from different processes.

172 +

173 +Therefore, in order to calculate an interval, we must compare two

174 +monotonic timestamps from the same process.

175 +

176 +### Scheduler Stats

177 +

178 +The engine core process will collect some key statistics from the

179 +scheduler - e.g. the number of requests that were scheduled or waiting

180 +after the last scheduler pass - and include those statistics in

181 +`EngineCoreOutputs`.

182 +

183 +### Engine Core Events

184 +

185 +The engine core will also record the timestamp of certain per-request

186 +events so that the frontend can calculate the interval between these

187 +events.

188 +

189 +The events are:

190 +

191 +- `QUEUED` - when the request was received by the engine core and

192 + added to the scheduler queue.

193 +- `SCHEDULED` - when the request was first scheduled for execution.

194 +- `PREEMPTED` - the request has been put back in the waiting queue

195 + in order to make room for other requests to complete. It will be

196 + re-scheduled in future and re-start its prefill phase.

197 +- `NEW_TOKENS` - when the output included in `EngineCoreOutput` was

198 + generated. Since this is common to all requests in a given

199 + iteration, we use a single timestamp on `EngineCoreOutputs` to

200 + record this event.

201 +

202 +And the calculated intervals are:

203 +

204 +- Queue interval - between `QUEUED` and most recent `SCHEDULED`.

205 +- Prefill interval - between most recent `SCHEDULED` and the subsequent

206 + first `NEW_TOKENS`.

207 +- Decode interval - between first (after the most recent `SCHEDULED`) and

208 + last `NEW_TOKENS`.

209 +- Inference interval - between most recent `SCHEDULED` and last `NEW_TOKENS`.

210 +- Inter-token interval - between successive `NEW_TOKENS`.

211 +

212 +Put another way:

213 +

214 +:::{image} /assets/design/v1/metrics/intervals-1.png

215 +:alt: Interval calculations - common case

216 +:::

217 +

218 +We explored the possibility of having the frontend calculate these

219 +intervals using the timing of events visible by the frontend. However,

220 +the frontend does not have visibility into the timing of the `QUEUED`

221 +and `SCHEDULED` events and, since we need to calculate intervals based

222 +on monotonic timestamps from the same process ... we need the engine

223 +core to record timestamps for all of these events.

224 +

225 +#### Interval Calculations vs Preemptions

226 +

227 +When a preemption occurs during decode, since any already generated

228 +tokens are reused, we consider the preemption as affecting the

229 +inter-token, decode, and inference intervals.

230 +

231 +:::{image} /assets/design/v1/metrics/intervals-2.png

232 +:alt: Interval calculations - preempted decode

233 +:::

234 +

235 +When a preemption occurs during prefill (assuming such an event

236 +is possible), we consider the preemption as affecting the

237 +time-to-first-token and prefill intervals.

238 +

239 +:::{image} /assets/design/v1/metrics/intervals-3.png

240 +:alt: Interval calculations - preempted prefill

241 +:::

242 +

243 +### Frontend Stats Collection

244 +

245 +As the frontend processes a single `EngineCoreOutputs` - i.e. the

246 +output from a single engine core iteration - it collects various

247 +statistics relating to that iteration:

248 +

249 +- The total number of new tokens generated in this iteration.

250 +- The total number of prompt tokens processed by the prefills that

251 + completed in this iteration.

252 +- The queue intervals for any requests that were scheduled in this

253 + iteration.

254 +- The prefill intervals for any requests that completed prefill in

255 + this iteration.

256 +- The inter-token intervals (Time Per Output Token, TPOT), for all

257 + 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 +

263 +For any requests that were completed in a given iteration, we also

264 +record:

265 +

266 +- The inference and decode intervals - relative to the scheduled and

267 + first token events, as described above.

268 +- End-to-end latency - the interval between frontend `arrival_time`

269 + and the frontend receiving the final token.

270 +

271 +### Metrics Publishing - Logging

272 +

273 +The `LoggingStatLogger` metrics publisher outputs a log `INFO` message

274 +every 5 seconds with some key metrics:

275 +

276 +- The current number of running/waiting requests

277 +- The current GPU cache usage

278 +- The number of prompt tokens processed per second over the past 5

279 + seconds

280 +- The number of new tokens generated per second over the past 5

281 + seconds

282 +- The prefix cache hit rate over the most recent 1k kv-cache block queries

283 +

284 +### Metrics Publishing - Prometheus

285 +

286 +The `PrometheusStatLogger` metrics publisher makes the metrics

287 +available via a `/metrics` HTTP endpoint in a Prometheus-compatible

288 +format. A Prometheus instance can then be configured to poll this

289 +endpoint (e.g. every second) and record the values in its time-series

290 +database. Prometheus is often used via Grafana, allowing these metrics

291 +to be graphed over time.

292 +

293 +Prometheus supports the following metric types:

294 +

295 +- Counter: a value that will increase over time, never reducing, and

296 + generally reset to zero when the vLLM instance restarts. For

297 + example, the number of tokens generated over the lifetime of the

298 + instance.

299 +- Gauge: a value that goes up and down, for example the number of

300 + requests currently scheduled for execution.

301 +- Histogram: a count of metric samples, recorded in buckets. For

302 + example, the number of requests whose TTFT was <1ms, <5ms, <10ms,

303 + <20ms, and so on.

304 +

305 +Prometheus metrics can also be labelled, allowing metrics to be

306 +combined according to matching labels. In vLLM, we add a `model_name`

307 +label to every metric which includes the name of the model served by

308 +that instance.

309 +

310 +Example output:

311 +

312 +```bash

313 +$ curl http://0.0.0.0:8000/metrics

314 +# HELP vllm:num_requests_running Number of requests in model execution batches.

315 +# TYPE vllm:num_requests_running gauge

316 +vllm:num_requests_running{model_name="meta-llama/Llama-3.1-8B-Instruct"} 8.0

317 +...

318 +# HELP vllm:generation_tokens_total Number of generation tokens processed.

319 +# TYPE vllm:generation_tokens_total counter

320 +vllm:generation_tokens_total{model_name="meta-llama/Llama-3.1-8B-Instruct"} 27453.0

321 +...

322 +# HELP vllm:request_success_total Count of successfully processed requests.

323 +# TYPE vllm:request_success_total counter

324 +vllm:request_success_total{finished_reason="stop",model_name="meta-llama/Llama-3.1-8B-Instruct"} 1.0

325 +vllm:request_success_total{finished_reason="length",model_name="meta-llama/Llama-3.1-8B-Instruct"} 131.0

326 +vllm:request_success_total{finished_reason="abort",model_name="meta-llama/Llama-3.1-8B-Instruct"} 0.0

327 +...

328 +# HELP vllm:time_to_first_token_seconds Histogram of time to first token in seconds.

329 +# TYPE vllm:time_to_first_token_seconds histogram

330 +vllm:time_to_first_token_seconds_bucket{le="0.001",model_name="meta-llama/Llama-3.1-8B-Instruct"} 0.0

331 +vllm:time_to_first_token_seconds_bucket{le="0.005",model_name="meta-llama/Llama-3.1-8B-Instruct"} 0.0

332 +vllm:time_to_first_token_seconds_bucket{le="0.01",model_name="meta-llama/Llama-3.1-8B-Instruct"} 0.0

333 +vllm:time_to_first_token_seconds_bucket{le="0.02",model_name="meta-llama/Llama-3.1-8B-Instruct"} 13.0

334 +vllm:time_to_first_token_seconds_bucket{le="0.04",model_name="meta-llama/Llama-3.1-8B-Instruct"} 97.0

335 +vllm:time_to_first_token_seconds_bucket{le="0.06",model_name="meta-llama/Llama-3.1-8B-Instruct"} 123.0

336 +vllm:time_to_first_token_seconds_bucket{le="0.08",model_name="meta-llama/Llama-3.1-8B-Instruct"} 138.0

337 +vllm:time_to_first_token_seconds_bucket{le="0.1",model_name="meta-llama/Llama-3.1-8B-Instruct"} 140.0

338 +vllm:time_to_first_token_seconds_count{model_name="meta-llama/Llama-3.1-8B-Instruct"} 140.0

339 +```

340 +

341 +Note - the choice of histogram buckets to be most useful to users

342 +across a broad set of use cases is not straightforward and will

343 +require refinement over time.

344 +

345 +### Cache Config Info

346 +

347 +`prometheus_client` has support for [Info

348 +metrics](https://prometheus.github.io/client_python/instrumenting/info/)

349 +which are equivalent to a `Gauge` whose value is permanently set to 1,

350 +but exposes interesting key/value pair information via labels. This is

351 +used for information about an instance that does not change - so it

352 +only needs to be observed at startup - and allows comparing across

353 +instances in Prometheus.

354 +

355 +We use this concept for the `vllm:cache_config_info` metric:

356 +

357 +```

358 +# HELP vllm:cache_config_info Information of the LLMEngine CacheConfig

359 +# TYPE vllm:cache_config_info gauge

360 +vllm:cache_config_info{block_size="16",cache_dtype="auto",calculate_kv_scales="False",cpu_offload_gb="0",enable_prefix_caching="False",gpu_memory_utilization="0.9",...} 1.0

361 +

362 +```

363 +

364 +However, `prometheus_client` has [never supported Info metrics in

365 +multiprocessing

366 +mode](https://github.com/prometheus/client_python/pull/300) - for

367 +[unclear

368 +reasons](gh-pr:7279#discussion_r1710417152). We

369 +simply use a `Gauge` metric set to 1 and

370 +`multiprocess_mode="mostrecent"` instead.

371 +

372 +### LoRA Metrics

373 +

374 +The `vllm:lora_requests_info` `Gauge` is somewhat similar, except the

375 +value is the current wall-clock time, and is updated every iteration.

376 +

377 +The label names used are:

378 +

379 +- `running_lora_adapters`: a per-adapter count of the number requests

380 + running using that adapter, formatted as a comma-separated string.

381 +- `waiting_lora_adapters`: similar, except counting requests that are

382 + waiting to be scheduled.

383 +- `max_lora` - the static "max number of LoRAs in a single batch."

384 + configuration.

385 +

386 +Encoding a running/waiting counts for multiple adapters in a

387 +comma-separated string seems quite misguided - we could use labels to

388 +distinguish between per-adapter counts. This should be revisited.

389 +

390 +Note that `multiprocess_mode="livemostrecent"` is used - the most

391 +recent metric is used, but only from currently running processes.

392 +

393 +This was added in

394 +<gh-pr:9477> and there is

395 +[at least one known

396 +user](https://github.com/kubernetes-sigs/gateway-api-inference-extension/pull/54). If

397 +we revisit this design and deprecate the old metric, we should reduce

398 +the need for a significant deprecation period by making the change in

399 +v0 also and asking this project to move to the new metric.

400 +

401 +### Prefix Cache metrics

402 +

403 +The discussion in <gh-issue:10582> about adding prefix cache metrics yielded

404 +some interesting points which may be relevant to how we approach

405 +future metrics.

406 +

407 +Every time the prefix cache is queried, we record the number of blocks

408 +queried and the number of queried blocks present in the cache

409 +(i.e. hits).

410 +

411 +However, the metric of interest is the hit rate - i.e. the number of

412 +hits per query.

413 +

414 +In the case of logging, we expect the user is best served by

415 +calculating the hit rate over a fixed number of the most recent

416 +queries (the interval is fixed to 1k most recent queries for now).

417 +

418 +In the case of Prometheus though, we should take advantage of the

419 +time-series nature of Prometheus and allow the user to calculate the

420 +hit rate over an interval of their choosing. For example, a PromQL

421 +query to calculate the hit interval of the past 5 minutes:

422 +

423 +```text

424 +rate(cache_query_hit[5m]) / rate(cache_query_total[5m])

425 +```

426 +

427 +To achieve this, we should record the queries and hits as counters in

428 +Prometheus, rather than recording the hit rate as a gauge.

429 +

430 +## Deprecated Metrics

431 +

432 +### How To Deprecate

433 +

434 +Deprecating metrics shouldn't be taken lightly. Users may not notice a

435 +metric has been deprecated, and may be quite inconvenienced when it is

436 +suddenly (from their perspective) when it is removed, even if there is

437 +an equivalent metric for them to use.

438 +

439 +As an example, see how `vllm:avg_prompt_throughput_toks_per_s` was

440 +[deprecated](gh-pr:2764) (with a

441 +comment in the code),

442 +[removed](gh-pr:12383), and then

443 +[noticed by a

444 +user](gh-issue:13218).

445 +

446 +In general:

447 +

448 +1) We should be cautious about deprecating metrics, especially since

449 + it can be hard to predict the user impact.

450 +2) We should include a prominent deprecation notice in the help string

451 + that is included in the `/metrics' output.

452 +3) We should list deprecated metrics in user-facing documentation and

453 + release notes.

454 +4) We should consider hiding deprecated metrics behind a CLI argument

455 + in order to give administrators [an escape

456 + hatch](https://kubernetes.io/docs/concepts/cluster-administration/system-metrics/#show-hidden-metrics)

457 + for some time before deleting them.

458 +

459 +### Unimplemented - `vllm:tokens_total`

460 +

461 +Added by <gh-pr:4464>, but apparently never implemented. This can just be

462 +removed.

463 +

464 +### Duplicated - Queue Time

465 +

466 +The `vllm:time_in_queue_requests` Histogram metric was added by

467 +<gh-pr:9659> and its calculation is:

468 +

469 +```

470 + self.metrics.first_scheduled_time = now

471 + self.metrics.time_in_queue = now - self.metrics.arrival_time

472 +```

473 +

474 +Two weeks later, <gh-pr:4464> added `vllm:request_queue_time_seconds` leaving

475 +us with:

476 +

477 +```

478 +if seq_group.is_finished():

479 + if (seq_group.metrics.first_scheduled_time is not None and

480 + seq_group.metrics.first_token_time is not None):

481 + time_queue_requests.append(

482 + seq_group.metrics.first_scheduled_time -

483 + seq_group.metrics.arrival_time)

484 + ...

485 + if seq_group.metrics.time_in_queue is not None:

486 + time_in_queue_requests.append(

487 + seq_group.metrics.time_in_queue)

488 +```

489 +

490 +This seems duplicative, and one of them should be removed. The latter

491 +is used by the Grafana dashboard, so we should deprecate or remove the

492 +former from v0.

493 +

494 +### Prefix Cache Hit Rate

495 +

496 +See above - we now expose 'queries' and 'hits' counters rather than a

497 +'hit rate' gauge.

498 +

499 +### KV Cache Offloading

500 +

501 +Two v0 metrics relate to a "swapped" preemption mode that is no

502 +longer relevant in v1:

503 +

504 +- `vllm:num_requests_swapped`

505 +- `vllm:cpu_cache_usage_perc`

506 +

507 +In this mode, when a request is preempted (e.g. to make room in KV

508 +cache to complete other requests), we swap kv cache blocks out to CPU

509 +memory. This is also known as "KV cache offloading" and is configured

510 +with `--swap-space` and `--preemption-mode`.

511 +

512 +In v0, [VLLM has long supported beam

513 +search](gh-issue:6226). The

514 +SequenceGroup encapsulated the idea of N Sequences which

515 +all shared the same prompt kv blocks. This enabled KV cache block

516 +sharing between requests, and copy-on-write to do branching. CPU

517 +swapping was intended for these beam search like cases.

518 +

519 +Later, the concept of prefix caching was introduced, which allowed KV

520 +cache blocks to be shared implicitly. This proved to be a better

521 +option than CPU swapping since blocks can be evicted slowly on demand

522 +and the part of the prompt that was evicted can be recomputed.

523 +

524 +SequenceGroup was removed in V1, although a replacement will be

525 +required for "parallel sampling" (`n>1`). [Beam search was moved out of

526 +the core (in

527 +V0)](gh-issue:8306). There was a

528 +lot of complex code for a very uncommon feature.

529 +

530 +In V1, with prefix caching being better (zero over head) and therefore

531 +on by default, the preemption and recompute strategy should work

532 +better.

533 +

534 +## Future Work

535 +

536 +### Parallel Sampling

537 +

538 +Some v0 metrics are only relevant in the context of "parallel

539 +sampling". This is where the `n` parameter in a request is used to

540 +request multiple completions from the same prompt.

541 +

542 +As part of adding parallel sampling support in <gh-pr:10980> we should

543 +also add these metrics.

544 +

545 +- `vllm:request_params_n` (Histogram)

546 +

547 +Observes the value of the 'n' parameter of every finished request.

548 +

549 +- `vllm:request_max_num_generation_tokens` (Histogram)

550 +

551 +Observes the maximum output length of all sequences in every finished

552 +sequence group. In the absence of parallel sampling, this is

553 +equivalent to `vllm:request_generation_tokens`.

554 +

555 +### Speculative Decoding

556 +

557 +Some v0 metrics are specific to "speculative decoding". This is where

558 +we generate candidate tokens using a faster, approximate method or

559 +model and then validate those tokens with the larger model.

560 +

561 +- `vllm:spec_decode_draft_acceptance_rate` (Gauge)

562 +- `vllm:spec_decode_efficiency` (Gauge)

563 +- `vllm:spec_decode_num_accepted_tokens_total` (Counter)

564 +- `vllm:spec_decode_num_draft_tokens_total` (Counter)

565 +- `vllm:spec_decode_num_emitted_tokens_total` (Counter)

566 +

567 +There is a PR under review (<gh-pr:12193>) to add "prompt lookup (ngram)"

568 +seculative decoding to v1. Other techniques will follow. We should

569 +revisit the v0 metrics in this context.

570 +

571 +Note - we should probably expose acceptance rate as separate accepted

572 +and draft counters, like we do for prefix caching hit rate. Efficiency

573 +likely also needs similar treatment.

574 +

575 +### Autoscaling and Load-balancing

576 +

577 +A common use case for our metrics is to support automated scaling of

578 +vLLM instances.

579 +

580 +For related discussion from the [Kubernetes Serving Working

581 +Group](https://github.com/kubernetes/community/tree/master/wg-serving),

582 +see:

583 +

584 +- [Standardizing Large Model Server Metrics in

585 + Kubernetes](https://docs.google.com/document/d/1SpSp1E6moa4HSrJnS4x3NpLuj88sMXr2tbofKlzTZpk)

586 +- [Benchmarking LLM Workloads for Performance Evaluation and

587 + Autoscaling in

588 + Kubernetes](https://docs.google.com/document/d/1k4Q4X14hW4vftElIuYGDu5KDe2LtV1XammoG-Xi3bbQ)

589 +- [Inference

590 + Perf](https://github.com/kubernetes-sigs/wg-serving/tree/main/proposals/013-inference-perf)

591 +- <gh-issue:5041> and <gh-pr:12726>.

592 +

593 +This is a non-trivial topic. Consider this comment from Rob:

594 +

595 +> I think this metric should focus on trying to estimate what the max

596 +> concurrency that will cause the average request length > queries per

597 +> second ... since this is really what will "saturate" the server.

598 +

599 +A clear goal is that we should expose the metrics required to detect

600 +this saturation point, so administrators can implement auto-scaling

601 +rules based on those. However, in order to do so, we need to have a

602 +clear view on how an administrator (and automated monitoring system)

603 +should judge an instance as approaching saturation:

604 +

605 +> To identify, what is the saturation point for model server compute

606 +> (the inflection point where we cannot get more throughput with a

607 +> higher request rate, but start to incur additional latency) so we

608 +> can autoscale effectively?

609 +

610 +### Metric Naming

611 +

612 +Our approach to naming metrics probably deserves to be revisited:

613 +

614 +1. The use of colons in metric names seems contrary to ["colons are

615 + reserved for user defined recording

616 + rules"](https://prometheus.io/docs/concepts/data_model/#metric-names-and-labels)

617 +2. Most of our metrics follow the convention of ending with units, but

618 + not all do.

619 +3. Some of our metric names end with `_total`:

620 +

621 +```

622 +If there is a suffix of `_total` on the metric name, it will be removed. When

623 +exposing the time series for counter, a `_total` suffix will be added. This is

624 +for compatibility between OpenMetrics and the Prometheus text format, as OpenMetrics

625 +requires the `_total` suffix.

626 +```

627 +

628 +### Adding More Metrics

629 +

630 +There is no shortage of ideas for new metrics:

631 +

632 +- Examples from other projects like

633 + [TGI](https://github.com/IBM/text-generation-inference?tab=readme-ov-file#metrics)

634 +- Proposals arising from specific use cases, like the Kubernetes

635 + auto-scaling topic above

636 +- Proposals that might arise out of standardisation efforts like

637 + [OpenTelemetry Semantic Conventions for Gen

638 + AI](https://github.com/open-telemetry/semantic-conventions/tree/main/docs/gen-ai).

639 +

640 +We should be cautious in our approach to adding new metrics. While

641 +metrics are often relatively straightforward to add:

642 +

643 +1. They can be difficult to remove - see the section on deprecation

644 + above.

645 +2. They can have a meaningful performance impact when enabled. And

646 + metrics are usually of very limited use unless they can be enabled

647 + by default and in production.

648 +3. They have an impact on development and maintenance of the

649 + project. Every metric added to v0 has made this v1 effort more

650 + time-consuming, and perhaps not all metrics justify this ongoing

651 + investment in their maintenance.

652 +

653 +## Tracing - OpenTelemetry

654 +

655 +Metrics provide an aggregated view over time of the system's

656 +performance and health. Tracing, on the other hand, tracks individual

657 +requests as they move through different services and components. Both

658 +fall under the more general heading of "Observability".

659 +

660 +v0 has support for OpenTelemetry tracing:

661 +

662 +- Added by <gh-pr:4687>

663 +- Configured with `--oltp-traces-endpoint` and

664 + `--collect-detailed-traces`

665 +- [OpenTelemetry blog

666 + post](https://opentelemetry.io/blog/2024/llm-observability/)

667 +- [User-facing

668 + docs](https://docs.vllm.ai/en/latest/getting_started/examples/opentelemetry.html)

669 +- [Blog

670 + post](https://medium.com/@ronen.schaffer/follow-the-trail-supercharging-vllm-with-opentelemetry-distributed-tracing-aa655229b46f)

671 +- [IBM product

672 + docs](https://www.ibm.com/docs/en/instana-observability/current?topic=mgaa-monitoring-large-language-models-llms-vllm-public-preview)

673 +

674 +OpenTelemetry has a [Gen AI Working

675 +Group](https://github.com/open-telemetry/community/blob/main/projects/gen-ai.md).

676 +

677 +Since metrics is a big enough topic on its own, we are going to tackle

678 +the topic of tracing in v1 separately.

679 +

680 +### OpenTelemetry Model Forward vs Execute Time

681 +

682 +In v0, we have the following two metrics:

683 +

684 +- `vllm:model_forward_time_milliseconds` (Histogram) - The time spent

685 + in the model forward pass when this request was in the batch.

686 +- `vllm:model_execute_time_milliseconds` (Histogram) - The time spent

687 + in the model execute function. This will include model forward,

688 + block/sync across workers, cpu-gpu sync time and sampling time.

689 +

690 +These metrics are only enabled when OpenTelemetry tracing is enabled

691 +and if `--collect-detailed-traces=all/model/worker` is used. The

692 +documentation for this option states:

693 +

694 +> collect detailed traces for the specified "modules. This involves

695 +> use of possibly costly and or blocking operations and hence might

696 +> have a performance impact.

697 +

698 +The metrics were added by <gh-pr:7089> and who up in an OpenTelemetry trace

699 +as:

700 +

701 +```

702 +-> gen_ai.latency.time_in_scheduler: Double(0.017550230026245117)

703 +-> gen_ai.latency.time_in_model_forward: Double(3.151565277099609)

704 +-> gen_ai.latency.time_in_model_execute: Double(3.6468167304992676)

705 +```

706 +

707 +We already have `inference_time` and `decode_time` metrics, so the

708 +question is whether there are sufficiently common use cases for the

709 +higher-resolution timings to justify the overhead.

710 +

711 +Since we are going to treat the question of OpenTelemetry support

712 +separately, we will include these particular metrics under that topic.

[v1][Metrics] Add design doc (#12745)