loggers.py 31.2 KB
Newer Older
1
# SPDX-License-Identifier: Apache-2.0
2
# SPDX-FileCopyrightText: Copyright contributors to the vLLM project
3

4
import logging
5
6
import time
from abc import ABC, abstractmethod
7
from typing import Callable, Optional, Union
8
9

import prometheus_client
10

11
from vllm.config import SupportsMetricsInfo, VllmConfig
12
13
from vllm.distributed.kv_transfer.kv_connector.v1.metrics import (
    KVConnectorLogging)
14
from vllm.logger import init_logger
15
from vllm.v1.core.kv_cache_utils import PrefixCachingMetrics
16
from vllm.v1.engine import FinishReason
17
from vllm.v1.metrics.prometheus import unregister_vllm_metrics
18
from vllm.v1.metrics.stats import IterationStats, SchedulerStats
19
from vllm.v1.spec_decode.metrics import SpecDecodingLogging, SpecDecodingProm
20
21
22

logger = init_logger(__name__)

23
24
StatLoggerFactory = Callable[[VllmConfig, int], "StatLoggerBase"]

25
26

class StatLoggerBase(ABC):
27
28
29
30
31
32
33
34
35
36
    """Interface for logging metrics.

    API users may define custom loggers that implement this interface.
    However, note that the `SchedulerStats` and `IterationStats` classes
    are not considered stable interfaces and may change in future versions.
    """

    @abstractmethod
    def __init__(self, vllm_config: VllmConfig, engine_index: int = 0):
        ...
37
38

    @abstractmethod
39
40
41
42
    def record(self,
               scheduler_stats: Optional[SchedulerStats],
               iteration_stats: Optional[IterationStats],
               engine_idx: int = 0):
43
44
        ...

45
46
47
48
    @abstractmethod
    def log_engine_initialized(self):
        ...

49
50
51
    def log(self):  # noqa
        pass

52
53
54

class LoggingStatLogger(StatLoggerBase):

55
    def __init__(self, vllm_config: VllmConfig, engine_index: int = 0):
56
        self.engine_index = engine_index
57
        self.vllm_config = vllm_config
58
        self._reset(time.monotonic())
59
        self.last_scheduler_stats = SchedulerStats()
60
61
62
        # Prefix cache metrics. This cannot be reset.
        # TODO: Make the interval configurable.
        self.prefix_caching_metrics = PrefixCachingMetrics()
63
        self.spec_decoding_logging = SpecDecodingLogging()
64
65
        kv_tranfer_config = self.vllm_config.kv_transfer_config
        self.kv_transfer_logging = KVConnectorLogging(kv_tranfer_config)
66
67
        self.last_prompt_throughput: float = 0.0
        self.last_generation_throughput: float = 0.0
68

69
70
71
72
    def _reset(self, now):
        self.last_log_time = now

        # Tracked stats over current local logging interval.
73
74
        self.num_prompt_tokens: int = 0
        self.num_generation_tokens: int = 0
75

76
77
    def _track_iteration_stats(self, iteration_stats: IterationStats):
        # Save tracked stats for token counters.
78
79
        self.num_prompt_tokens += iteration_stats.num_prompt_tokens
        self.num_generation_tokens += iteration_stats.num_generation_tokens
80

81
    def _get_throughput(self, tracked_stats: int, now: float) -> float:
82
        # Compute summary metrics for tracked stats
83
84
85
86
        delta_time = now - self.last_log_time
        if delta_time <= 0.0:
            return 0.0
        return float(tracked_stats / delta_time)
87

88
89
90
91
    def record(self,
               scheduler_stats: Optional[SchedulerStats],
               iteration_stats: Optional[IterationStats],
               engine_idx: int = 0):
92
93
        """Log Stats to standard output."""

94
95
        if iteration_stats:
            self._track_iteration_stats(iteration_stats)
96

97
98
99
        if scheduler_stats is not None:
            self.prefix_caching_metrics.observe(
                scheduler_stats.prefix_cache_stats)
100

101
102
103
            if scheduler_stats.spec_decoding_stats is not None:
                self.spec_decoding_logging.observe(
                    scheduler_stats.spec_decoding_stats)
104
105
            if kv_connector_stats := scheduler_stats.kv_connector_stats:
                self.kv_transfer_logging.observe(kv_connector_stats)
106
            self.last_scheduler_stats = scheduler_stats
107

108
109
    def log(self):
        now = time.monotonic()
110
111
112
113
114
        prompt_throughput = self._get_throughput(self.num_prompt_tokens, now)
        generation_throughput = self._get_throughput(
            self.num_generation_tokens, now)

        self._reset(now)
115

116
117
        scheduler_stats = self.last_scheduler_stats

118
119
120
121
122
123
124
125
126
        log_fn = logger.info
        if not any(
            (prompt_throughput, generation_throughput,
             self.last_prompt_throughput, self.last_generation_throughput)):
            # Avoid log noise on an idle production system
            log_fn = logger.debug
        self.last_generation_throughput = generation_throughput
        self.last_prompt_throughput = prompt_throughput

127
        # Format and print output.
128
        log_fn(
129
            "Engine %03d: "
130
131
            "Avg prompt throughput: %.1f tokens/s, "
            "Avg generation throughput: %.1f tokens/s, "
132
133
134
            "Running: %d reqs, Waiting: %d reqs, "
            "GPU KV cache usage: %.1f%%, "
            "Prefix cache hit rate: %.1f%%",
135
            self.engine_index,
136
137
            prompt_throughput,
            generation_throughput,
138
139
            scheduler_stats.num_running_reqs,
            scheduler_stats.num_waiting_reqs,
140
            scheduler_stats.kv_cache_usage * 100,
141
            self.prefix_caching_metrics.hit_rate * 100,
142
        )
143
        self.spec_decoding_logging.log(log_fn=log_fn)
144
        self.kv_transfer_logging.log(log_fn=log_fn)
145

146
    def log_engine_initialized(self):
147
148
149
150
151
        if self.vllm_config.cache_config.num_gpu_blocks:
            logger.info(
                "Engine %03d: vllm cache_config_info with initialization "
                "after num_gpu_blocks is: %d", self.engine_index,
                self.vllm_config.cache_config.num_gpu_blocks)
152

153
154

class PrometheusStatLogger(StatLoggerBase):
155
156
157
158
    _gauge_cls = prometheus_client.Gauge
    _counter_cls = prometheus_client.Counter
    _histogram_cls = prometheus_client.Histogram
    _spec_decoding_cls = SpecDecodingProm
159

160
161
162
163
164
165
    def __init__(self,
                 vllm_config: VllmConfig,
                 engine_indexes: Optional[list[int]] = None):
        if engine_indexes is None:
            engine_indexes = [0]
        self.engine_indexes = engine_indexes
166
167

        unregister_vllm_metrics()
168
        self.vllm_config = vllm_config
169
170
171
172
173
        # Use this flag to hide metrics that were deprecated in
        # a previous release and which will be removed future
        self.show_hidden_metrics = \
            vllm_config.observability_config.show_hidden_metrics

174
        labelnames = ["model_name", "engine"]
175
        model_name = vllm_config.model_config.served_model_name
176
        max_model_len = vllm_config.model_config.max_model_len
177

178
179
180
181
182
        spec_decode_labelvalues: dict[int, list[str]] = {
            idx: [model_name, str(idx)]
            for idx in engine_indexes
        }

183
        self.spec_decoding_prom = self._spec_decoding_cls(
184
185
            vllm_config.speculative_config, labelnames,
            spec_decode_labelvalues)
186

187
188
189
        #
        # Scheduler state
        #
190
        gauge_scheduler_running = self._gauge_cls(
191
192
            name="vllm:num_requests_running",
            documentation="Number of requests in model execution batches.",
193
            multiprocess_mode="mostrecent",
194
195
196
197
            labelnames=labelnames)
        self.gauge_scheduler_running = make_per_engine(gauge_scheduler_running,
                                                       engine_indexes,
                                                       model_name)
198

199
        gauge_scheduler_waiting = self._gauge_cls(
200
201
            name="vllm:num_requests_waiting",
            documentation="Number of requests waiting to be processed.",
202
            multiprocess_mode="mostrecent",
203
204
205
206
            labelnames=labelnames)
        self.gauge_scheduler_waiting = make_per_engine(gauge_scheduler_waiting,
                                                       engine_indexes,
                                                       model_name)
207

208
209
210
        #
        # GPU cache
        #
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
        # Deprecated in 0.9.2 - Renamed as vllm:kv_cache_usage_perc
        # With 0.11.x you can enable with --show-hidden-metrics-for-version=0.10
        # TODO: remove in 0.12.0
        if self.show_hidden_metrics:
            gauge_gpu_cache_usage = self._gauge_cls(
                name="vllm:gpu_cache_usage_perc",
                documentation=(
                    "GPU KV-cache usage. 1 means 100 percent usage."
                    "DEPRECATED: Use vllm:kv_cache_usage_perc instead."),
                multiprocess_mode="mostrecent",
                labelnames=labelnames)
            self.gauge_gpu_cache_usage = make_per_engine(
                gauge_gpu_cache_usage, engine_indexes, model_name)

        # Deprecated in 0.9.2 - Renamed as vllm:prefix_cache_queries
        # With 0.11.x you can enable with --show-hidden-metrics-for-version=0.10
        # TODO: remove in 0.12.0
        if self.show_hidden_metrics:
            counter_gpu_prefix_cache_queries = self._counter_cls(
                name="vllm:gpu_prefix_cache_queries",
                documentation=(
                    "GPU prefix cache queries, in terms of number of queried"
                    "tokens. DEPRECATED: Use vllm:prefix_cache_queries instead."
                ),
                labelnames=labelnames)
            self.counter_gpu_prefix_cache_queries = make_per_engine(
                counter_gpu_prefix_cache_queries, engine_indexes, model_name)

        # Deprecated in 0.9.2 - Renamed as vllm:prefix_cache_hits
        # With 0.11.x you can enable with --show-hidden-metrics-for-version=0.10
        # TODO: remove in 0.12.0
        if self.show_hidden_metrics:
            counter_gpu_prefix_cache_hits = self._counter_cls(
                name="vllm:gpu_prefix_cache_hits",
                documentation=(
                    "GPU prefix cache hits, in terms of number of cached "
                    "tokens. DEPRECATED: Use vllm:prefix_cache_hits instead."),
                labelnames=labelnames)
            self.counter_gpu_prefix_cache_hits = make_per_engine(
                counter_gpu_prefix_cache_hits, engine_indexes, model_name)
251

252
        gauge_kv_cache_usage = self._gauge_cls(
253
254
            name="vllm:kv_cache_usage_perc",
            documentation="KV-cache usage. 1 means 100 percent usage.",
255
256
257
            labelnames=labelnames)
        self.gauge_kv_cache_usage = make_per_engine(gauge_kv_cache_usage,
                                                    engine_indexes, model_name)
258

259
        counter_prefix_cache_queries = self._counter_cls(
260
261
262
            name="vllm:prefix_cache_queries",
            documentation=(
                "Prefix cache queries, in terms of number of queried tokens."),
263
264
265
            labelnames=labelnames)
        self.counter_prefix_cache_queries = make_per_engine(
            counter_prefix_cache_queries, engine_indexes, model_name)
266

267
        counter_prefix_cache_hits = self._counter_cls(
268
269
270
            name="vllm:prefix_cache_hits",
            documentation=(
                "Prefix cache hits, in terms of number of cached tokens."),
271
272
273
            labelnames=labelnames)
        self.counter_prefix_cache_hits = make_per_engine(
            counter_prefix_cache_hits, engine_indexes, model_name)
274

275
276
277
        #
        # Counters
        #
278
        counter_num_preempted_reqs = self._counter_cls(
279
            name="vllm:num_preemptions",
280
            documentation="Cumulative number of preemption from the engine.",
281
282
283
            labelnames=labelnames)
        self.counter_num_preempted_reqs = make_per_engine(
            counter_num_preempted_reqs, engine_indexes, model_name)
284

285
        counter_prompt_tokens = self._counter_cls(
286
            name="vllm:prompt_tokens",
287
            documentation="Number of prefill tokens processed.",
288
289
290
291
            labelnames=labelnames)
        self.counter_prompt_tokens = make_per_engine(counter_prompt_tokens,
                                                     engine_indexes,
                                                     model_name)
292

293
        counter_generation_tokens = self._counter_cls(
294
            name="vllm:generation_tokens",
295
            documentation="Number of generation tokens processed.",
296
297
298
            labelnames=labelnames)
        self.counter_generation_tokens = make_per_engine(
            counter_generation_tokens, engine_indexes, model_name)
299

300
301
        self.counter_request_success: dict[FinishReason, dict[
            int, prometheus_client.Counter]] = {}
302
        counter_request_success_base = self._counter_cls(
303
            name="vllm:request_success",
304
305
            documentation="Count of successfully processed requests.",
            labelnames=labelnames + ["finished_reason"])
306
        for reason in FinishReason:
307
308
309
310
311
312
            self.counter_request_success[reason] = {
                idx:
                counter_request_success_base.labels(model_name, str(idx),
                                                    str(reason))
                for idx in engine_indexes
            }
313

314
315
316
        #
        # Histograms of counts
        #
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
        histogram_num_prompt_tokens_request = self._histogram_cls(
            name="vllm:request_prompt_tokens",
            documentation="Number of prefill tokens processed.",
            buckets=build_1_2_5_buckets(max_model_len),
            labelnames=labelnames)
        self.histogram_num_prompt_tokens_request = make_per_engine(
            histogram_num_prompt_tokens_request, engine_indexes, model_name)

        histogram_num_generation_tokens_request = self._histogram_cls(
            name="vllm:request_generation_tokens",
            documentation="Number of generation tokens processed.",
            buckets=build_1_2_5_buckets(max_model_len),
            labelnames=labelnames)
        self.histogram_num_generation_tokens_request = make_per_engine(
            histogram_num_generation_tokens_request, engine_indexes,
            model_name)
333

334
335
336
        # TODO: This metric might be incorrect in case of using multiple
        # api_server counts which uses prometheus mp.
        # See: https://github.com/vllm-project/vllm/pull/18053
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
        histogram_iteration_tokens = self._histogram_cls(
            name="vllm:iteration_tokens_total",
            documentation="Histogram of number of tokens per engine_step.",
            buckets=[
                1, 8, 16, 32, 64, 128, 256, 512, 1024, 2048, 4096, 8192, 16384
            ],
            labelnames=labelnames)
        self.histogram_iteration_tokens = make_per_engine(
            histogram_iteration_tokens, engine_indexes, model_name)

        histogram_max_num_generation_tokens_request = self._histogram_cls(
            name="vllm:request_max_num_generation_tokens",
            documentation=
            "Histogram of maximum number of requested generation tokens.",
            buckets=build_1_2_5_buckets(max_model_len),
            labelnames=labelnames)
        self.histogram_max_num_generation_tokens_request = make_per_engine(
            histogram_max_num_generation_tokens_request, engine_indexes,
            model_name)

        histogram_n_request = self._histogram_cls(
            name="vllm:request_params_n",
            documentation="Histogram of the n request parameter.",
            buckets=[1, 2, 5, 10, 20],
            labelnames=labelnames)
        self.histogram_n_request = make_per_engine(histogram_n_request,
                                                   engine_indexes, model_name)

        histogram_max_tokens_request = self._histogram_cls(
            name="vllm:request_params_max_tokens",
            documentation="Histogram of the max_tokens request parameter.",
            buckets=build_1_2_5_buckets(max_model_len),
            labelnames=labelnames)
        self.histogram_max_tokens_request = make_per_engine(
            histogram_max_tokens_request, engine_indexes, model_name)
372
373
374
375

        #
        # Histogram of timing intervals
        #
376
377
378
379
380
381
382
383
384
385
386
387
        histogram_time_to_first_token = self._histogram_cls(
            name="vllm:time_to_first_token_seconds",
            documentation="Histogram of time to first token in seconds.",
            buckets=[
                0.001, 0.005, 0.01, 0.02, 0.04, 0.06, 0.08, 0.1, 0.25, 0.5,
                0.75, 1.0, 2.5, 5.0, 7.5, 10.0, 20.0, 40.0, 80.0, 160.0, 640.0,
                2560.0
            ],
            labelnames=labelnames)
        self.histogram_time_to_first_token = make_per_engine(
            histogram_time_to_first_token, engine_indexes, model_name)

388
389
        # Deprecated in 0.11 - Renamed as vllm:inter_token_latency_seconds
        # TODO: in 0.12, only enable if show_hidden_metrics=True
390
391
        histogram_time_per_output_token = self._histogram_cls(
            name="vllm:time_per_output_token_seconds",
392
393
394
            documentation=(
                "Histogram of time per output token in seconds."
                "DEPRECATED: Use vllm:inter_token_latency_seconds instead."),
395
396
397
398
399
400
401
            buckets=[
                0.01, 0.025, 0.05, 0.075, 0.1, 0.15, 0.2, 0.3, 0.4, 0.5, 0.75,
                1.0, 2.5, 5.0, 7.5, 10.0, 20.0, 40.0, 80.0
            ],
            labelnames=labelnames)
        self.histogram_time_per_output_token = make_per_engine(
            histogram_time_per_output_token, engine_indexes, model_name)
402

403
404
405
406
407
408
409
410
411
412
413
        histogram_inter_token_latency = self._histogram_cls(
            name="vllm:inter_token_latency_seconds",
            documentation="Histogram of inter-token latency in seconds.",
            buckets=[
                0.01, 0.025, 0.05, 0.075, 0.1, 0.15, 0.2, 0.3, 0.4, 0.5, 0.75,
                1.0, 2.5, 5.0, 7.5, 10.0, 20.0, 40.0, 80.0
            ],
            labelnames=labelnames)
        self.histogram_inter_token_latency = make_per_engine(
            histogram_inter_token_latency, engine_indexes, model_name)

414
415
416
417
418
419
420
421
422
423
424
425
426
        histogram_request_time_per_output_token = self._histogram_cls(
            name="vllm:request_time_per_output_token_seconds",
            documentation=
            "Histogram of time_per_output_token_seconds per request.",
            buckets=[
                0.01, 0.025, 0.05, 0.075, 0.1, 0.15, 0.2, 0.3, 0.4, 0.5, 0.75,
                1.0, 2.5, 5.0, 7.5, 10.0, 20.0, 40.0, 80.0
            ],
            labelnames=labelnames)
        self.histogram_request_time_per_output_token = make_per_engine(
            histogram_request_time_per_output_token, engine_indexes,
            model_name)

427
428
        request_latency_buckets = [
            0.3, 0.5, 0.8, 1.0, 1.5, 2.0, 2.5, 5.0, 10.0, 15.0, 20.0, 30.0,
429
            40.0, 50.0, 60.0, 120.0, 240.0, 480.0, 960.0, 1920.0, 7680.0
430
        ]
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
        histogram_e2e_time_request = self._histogram_cls(
            name="vllm:e2e_request_latency_seconds",
            documentation="Histogram of e2e request latency in seconds.",
            buckets=request_latency_buckets,
            labelnames=labelnames)
        self.histogram_e2e_time_request = make_per_engine(
            histogram_e2e_time_request, engine_indexes, model_name)

        histogram_queue_time_request = self._histogram_cls(
            name="vllm:request_queue_time_seconds",
            documentation=
            "Histogram of time spent in WAITING phase for request.",
            buckets=request_latency_buckets,
            labelnames=labelnames)
        self.histogram_queue_time_request = make_per_engine(
            histogram_queue_time_request, engine_indexes, model_name)

        histogram_inference_time_request = self._histogram_cls(
            name="vllm:request_inference_time_seconds",
            documentation=
            "Histogram of time spent in RUNNING phase for request.",
            buckets=request_latency_buckets,
            labelnames=labelnames)
        self.histogram_inference_time_request = make_per_engine(
            histogram_inference_time_request, engine_indexes, model_name)

        histogram_prefill_time_request = self._histogram_cls(
            name="vllm:request_prefill_time_seconds",
            documentation=
            "Histogram of time spent in PREFILL phase for request.",
            buckets=request_latency_buckets,
            labelnames=labelnames)
        self.histogram_prefill_time_request = make_per_engine(
            histogram_prefill_time_request, engine_indexes, model_name)

        histogram_decode_time_request = self._histogram_cls(
            name="vllm:request_decode_time_seconds",
            documentation=
            "Histogram of time spent in DECODE phase for request.",
            buckets=request_latency_buckets,
            labelnames=labelnames)
        self.histogram_decode_time_request = make_per_engine(
            histogram_decode_time_request, engine_indexes, model_name)
474

475
476
477
        #
        # LoRA metrics
        #
478
479
480

        # TODO: This metric might be incorrect in case of using multiple
        # api_server counts which uses prometheus mp.
481
482
        self.gauge_lora_info: Optional[prometheus_client.Gauge] = None
        if vllm_config.lora_config is not None:
483
484
485
            if len(self.engine_indexes) > 1:
                raise NotImplementedError(
                    "LoRA in DP mode is not supported yet.")
486
487
488
489
490
            self.labelname_max_lora = "max_lora"
            self.labelname_waiting_lora_adapters = "waiting_lora_adapters"
            self.labelname_running_lora_adapters = "running_lora_adapters"
            self.max_lora = vllm_config.lora_config.max_loras
            self.gauge_lora_info = \
491
                self._gauge_cls(
492
493
                    name="vllm:lora_requests_info",
                    documentation="Running stats on lora requests.",
494
                    multiprocess_mode="sum",
495
496
497
498
                    labelnames=[
                        self.labelname_max_lora,
                        self.labelname_waiting_lora_adapters,
                        self.labelname_running_lora_adapters,
499
500
                    ],
                )
501

502
503
    def log_metrics_info(self, type: str, config_obj: SupportsMetricsInfo):
        metrics_info = config_obj.metrics_info()
504
        metrics_info["engine"] = ""
505
506
507
508
509
510
511
512
513
514

        name, documentation = None, None
        if type == "cache_config":
            name = "vllm:cache_config_info"
            documentation = "Information of the LLMEngine CacheConfig"
        assert name is not None, f"Unknown metrics info type {type}"

        # Info type metrics are syntactic sugar for a gauge permanently set to 1
        # Since prometheus multiprocessing mode does not support Info, emulate
        # info here with a gauge.
515
        info_gauge = self._gauge_cls(
516
517
            name=name,
            documentation=documentation,
518
519
            multiprocess_mode="mostrecent",
            labelnames=metrics_info.keys(),
520
521
522
523
524
525
526
527
528
529
        )
        for engine_index in self.engine_indexes:
            metrics_info = config_obj.metrics_info()
            metrics_info["engine"] = str(engine_index)
            info_gauge.labels(**metrics_info).set(1)

    def record(self,
               scheduler_stats: Optional[SchedulerStats],
               iteration_stats: Optional[IterationStats],
               engine_idx: int = 0):
530
        """Log to prometheus."""
531
        if scheduler_stats is not None:
532
533
534
535
            self.gauge_scheduler_running[engine_idx].set(
                scheduler_stats.num_running_reqs)
            self.gauge_scheduler_waiting[engine_idx].set(
                scheduler_stats.num_waiting_reqs)
536

537
538
539
            if self.show_hidden_metrics:
                self.gauge_gpu_cache_usage[engine_idx].set(
                    scheduler_stats.kv_cache_usage)
540
541
            self.gauge_kv_cache_usage[engine_idx].set(
                scheduler_stats.kv_cache_usage)
542

543
544
545
546
547
            if self.show_hidden_metrics:
                self.counter_gpu_prefix_cache_queries[engine_idx].inc(
                    scheduler_stats.prefix_cache_stats.queries)
                self.counter_gpu_prefix_cache_hits[engine_idx].inc(
                    scheduler_stats.prefix_cache_stats.hits)
548

549
            self.counter_prefix_cache_queries[engine_idx].inc(
550
                scheduler_stats.prefix_cache_stats.queries)
551
            self.counter_prefix_cache_hits[engine_idx].inc(
552
553
                scheduler_stats.prefix_cache_stats.hits)

554
555
            if scheduler_stats.spec_decoding_stats is not None:
                self.spec_decoding_prom.observe(
556
                    scheduler_stats.spec_decoding_stats, engine_idx)
557

558
559
560
        if iteration_stats is None:
            return

561
562
563
564
565
        self.counter_num_preempted_reqs[engine_idx].inc(
            iteration_stats.num_preempted_reqs)
        self.counter_prompt_tokens[engine_idx].inc(
            iteration_stats.num_prompt_tokens)
        self.counter_generation_tokens[engine_idx].inc(
566
            iteration_stats.num_generation_tokens)
567
        self.histogram_iteration_tokens[engine_idx].observe(
568
569
            iteration_stats.num_prompt_tokens + \
            iteration_stats.num_generation_tokens)
570

571
        for max_gen_tokens in iteration_stats.max_num_generation_tokens_iter:
572
573
            self.histogram_max_num_generation_tokens_request[
                engine_idx].observe(max_gen_tokens)
574
        for n_param in iteration_stats.n_params_iter:
575
            self.histogram_n_request[engine_idx].observe(n_param)
576
        for ttft in iteration_stats.time_to_first_tokens_iter:
577
            self.histogram_time_to_first_token[engine_idx].observe(ttft)
578
579
580
        for itl in iteration_stats.inter_token_latencies_iter:
            self.histogram_inter_token_latency[engine_idx].observe(itl)
            self.histogram_time_per_output_token[engine_idx].observe(itl)
581

582
        for finished_request in iteration_stats.finished_requests:
583
584
585
            self.counter_request_success[
                finished_request.finish_reason][engine_idx].inc()
            self.histogram_e2e_time_request[engine_idx].observe(
586
                finished_request.e2e_latency)
587
            self.histogram_queue_time_request[engine_idx].observe(
588
                finished_request.queued_time)
589
            self.histogram_prefill_time_request[engine_idx].observe(
590
                finished_request.prefill_time)
591
            self.histogram_inference_time_request[engine_idx].observe(
592
                finished_request.inference_time)
593
            self.histogram_decode_time_request[engine_idx].observe(
594
                finished_request.decode_time)
595
            self.histogram_num_prompt_tokens_request[engine_idx].observe(
596
                finished_request.num_prompt_tokens)
597
            self.histogram_num_generation_tokens_request[engine_idx].observe(
598
                finished_request.num_generation_tokens)
599
600
            self.histogram_request_time_per_output_token[engine_idx].observe(
                finished_request.mean_time_per_output_token)
601
            if finished_request.max_tokens_param:
602
                self.histogram_max_tokens_request[engine_idx].observe(
603
                    finished_request.max_tokens_param)
604

605
606
607
608
609
610
611
612
613
614
615
616
617
        if self.gauge_lora_info is not None:
            running_lora_adapters = \
                ",".join(iteration_stats.running_lora_adapters.keys())
            waiting_lora_adapters = \
                ",".join(iteration_stats.waiting_lora_adapters.keys())
            lora_info_labels = {
                self.labelname_running_lora_adapters: running_lora_adapters,
                self.labelname_waiting_lora_adapters: waiting_lora_adapters,
                self.labelname_max_lora: self.max_lora,
            }
            self.gauge_lora_info.labels(**lora_info_labels)\
                                .set_to_current_time()

618
619
620
    def log_engine_initialized(self):
        self.log_metrics_info("cache_config", self.vllm_config.cache_config)

621

622
623
624
625
626
627
628
629
630
631
632
633
PromMetric = Union[
    prometheus_client.Gauge,
    prometheus_client.Counter,
    prometheus_client.Histogram,
]


def make_per_engine(metric: PromMetric, engine_idxs: list[int],
                    model_name: str) -> dict[int, PromMetric]:
    return {idx: metric.labels(model_name, str(idx)) for idx in engine_idxs}


634
def build_buckets(mantissa_lst: list[int], max_value: int) -> list[int]:
635
636
637
638
639
640
    """
    Builds a list of buckets with increasing powers of 10 multiplied by
    mantissa values until the value exceeds the specified maximum.

    """
    exponent = 0
641
    buckets: list[int] = []
642
643
644
645
646
647
648
649
650
651
    while True:
        for m in mantissa_lst:
            value = m * 10**exponent
            if value <= max_value:
                buckets.append(value)
            else:
                return buckets
        exponent += 1


652
def build_1_2_5_buckets(max_value: int) -> list[int]:
653
654
655
656
657
658
    """
    Example:
    >>> build_1_2_5_buckets(100)
    [1, 2, 5, 10, 20, 50, 100]
    """
    return build_buckets([1, 2, 5], max_value)
659
660


661
662
663
664
665
666
667
668
669
670
671
672
673
674
675
676
677
678
class StatLoggerManager:
    """
    StatLoggerManager:
        Logging happens at the level of the EngineCore (per scheduler).
         * DP: >1 EngineCore per AsyncLLM - loggers for each EngineCore.
         * With Local Logger, just make N copies for N EngineCores.
         * With Prometheus, we need a single logger with N "labels"

        This class abstracts away this implementation detail from
        the AsyncLLM, allowing the AsyncLLM to just call .record()
        and .log() to a simple interface.
    """

    def __init__(
        self,
        vllm_config: VllmConfig,
        engine_idxs: Optional[list[int]] = None,
        custom_stat_loggers: Optional[list[StatLoggerFactory]] = None,
679
        enable_default_loggers: bool = True,
680
        client_count: int = 1,
681
682
683
    ):
        self.engine_idxs = engine_idxs if engine_idxs else [0]

684
        factories: list[StatLoggerFactory] = []
685
        if custom_stat_loggers is not None:
686
687
688
            factories.extend(custom_stat_loggers)

        if enable_default_loggers and logger.isEnabledFor(logging.INFO):
689
690
691
692
693
694
            if client_count > 1:
                logger.warning(
                    "AsyncLLM created with api_server_count more than 1; "
                    "disabling stats logging to avoid incomplete stats.")
            else:
                factories.append(LoggingStatLogger)
695
696
697
698
699
700
701
702
703
704
705
706
707
708
709
710
711
712
713
714
715
716
717
718
719
720
721
722
723
724
725
726
727
728
729
730
731
732
733
734
735
736
737
738
739
740
741
742

        # engine_idx: StatLogger
        self.per_engine_logger_dict: dict[int, list[StatLoggerBase]] = {}
        prometheus_factory = PrometheusStatLogger
        for engine_idx in self.engine_idxs:
            loggers: list[StatLoggerBase] = []
            for logger_factory in factories:
                # If we get a custom prometheus logger, use that
                # instead. This is typically used for the ray case.
                if (isinstance(logger_factory, type)
                        and issubclass(logger_factory, PrometheusStatLogger)):
                    prometheus_factory = logger_factory
                    continue
                loggers.append(logger_factory(vllm_config,
                                              engine_idx))  # type: ignore
            self.per_engine_logger_dict[engine_idx] = loggers

        # For Prometheus, need to share the metrics between EngineCores.
        # Each EngineCore's metrics are expressed as a unique label.
        self.prometheus_logger = prometheus_factory(vllm_config, engine_idxs)

    def record(
        self,
        scheduler_stats: Optional[SchedulerStats],
        iteration_stats: Optional[IterationStats],
        engine_idx: Optional[int] = None,
    ):
        if engine_idx is None:
            engine_idx = 0

        per_engine_loggers = self.per_engine_logger_dict[engine_idx]
        for logger in per_engine_loggers:
            logger.record(scheduler_stats, iteration_stats, engine_idx)

        self.prometheus_logger.record(scheduler_stats, iteration_stats,
                                      engine_idx)

    def log(self):
        for per_engine_loggers in self.per_engine_logger_dict.values():
            for logger in per_engine_loggers:
                logger.log()

    def log_engine_initialized(self):
        self.prometheus_logger.log_engine_initialized()

        for per_engine_loggers in self.per_engine_logger_dict.values():
            for logger in per_engine_loggers:
                logger.log_engine_initialized()