174 lines
6.9 KiB
Python
174 lines
6.9 KiB
Python
from vllm.logger import init_logger
|
|
from aioprometheus import Counter, Gauge, Histogram
|
|
|
|
import time
|
|
import numpy as np
|
|
from typing import List
|
|
from dataclasses import dataclass
|
|
|
|
logger = init_logger(__name__)
|
|
|
|
labels = {}
|
|
|
|
|
|
def add_global_metrics_labels(**kwargs):
|
|
labels.update(kwargs)
|
|
|
|
|
|
# The begin-* and end* here are used by the documentation generator
|
|
# to extract the metrics definitions.
|
|
|
|
# begin-metrics-definitions
|
|
gauge_avg_prompt_throughput = Gauge("vllm:avg_prompt_throughput_toks_per_s",
|
|
"Average prefill throughput in tokens/s.")
|
|
gauge_avg_generation_throughput = Gauge(
|
|
"vllm:avg_generation_throughput_toks_per_s",
|
|
"Average generation throughput in tokens/s.")
|
|
counter_prompt_tokens = Counter("vllm:prompt_tokens_total",
|
|
"Number of prefill tokens processed.")
|
|
counter_generation_tokens = Counter("vllm:generation_tokens_total",
|
|
"Number of generation tokens processed.")
|
|
|
|
gauge_scheduler_running = Gauge(
|
|
"vllm:num_requests_running",
|
|
"Number of requests currently running on GPU.")
|
|
gauge_scheduler_swapped = Gauge("vllm:num_requests_swapped",
|
|
"Number of requests swapped to CPU.")
|
|
gauge_scheduler_waiting = Gauge("vllm:num_requests_waiting",
|
|
"Number of requests waiting to be processed.")
|
|
|
|
gauge_gpu_cache_usage = Gauge(
|
|
"vllm:gpu_cache_usage_perc",
|
|
"GPU KV-cache usage. 1 means 100 percent usage.")
|
|
gauge_cpu_cache_usage = Gauge(
|
|
"vllm:cpu_cache_usage_perc",
|
|
"CPU KV-cache usage. 1 means 100 percent usage.")
|
|
|
|
histogram_time_to_first_token = Histogram(
|
|
"vllm:time_to_first_token_seconds",
|
|
"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
|
|
])
|
|
histogram_time_per_output_tokens = Histogram(
|
|
"vllm:time_per_output_token_seconds",
|
|
"Histogram of time per output token 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
|
|
])
|
|
histogram_e2e_request_latency = Histogram(
|
|
"vllm:e2e_request_latency_seconds",
|
|
"Histogram of end to end request latency in seconds.",
|
|
buckets=[1.0, 2.5, 5.0, 10.0, 15.0, 20.0, 30.0, 40.0, 50.0, 60.0])
|
|
# end-metrics-definitions
|
|
|
|
|
|
@dataclass
|
|
class Stats:
|
|
"""Created by LLMEngine for use by StatLogger."""
|
|
now: float
|
|
|
|
# System stats.
|
|
num_running: int
|
|
num_waiting: int
|
|
num_swapped: int
|
|
gpu_cache_usage: float
|
|
cpu_cache_usage: float
|
|
|
|
# Raw stats from last model iteration.
|
|
num_prompt_tokens: int
|
|
num_generation_tokens: int
|
|
time_to_first_tokens: List[float]
|
|
time_per_output_tokens: List[float]
|
|
time_e2e_requests: List[float]
|
|
|
|
|
|
class StatLogger:
|
|
"""StatLogger is used LLMEngine to log to Promethus and Stdout."""
|
|
|
|
def __init__(self, local_interval: float) -> None:
|
|
# Metadata for logging locally.
|
|
self.last_local_log = time.monotonic()
|
|
self.local_interval = local_interval
|
|
|
|
# Tracked stats over current local logging interval.
|
|
self.num_prompt_tokens: List[int] = []
|
|
self.num_generation_tokens: List[int] = []
|
|
|
|
def _get_throughput(self, tracked_stats: List[int], now: float) -> float:
|
|
return float(np.sum(tracked_stats) / (now - self.last_local_log))
|
|
|
|
def _local_interval_elapsed(self, now: float) -> bool:
|
|
elapsed_time = now - self.last_local_log
|
|
return elapsed_time > self.local_interval
|
|
|
|
def _log_prometheus(self, stats: Stats) -> None:
|
|
# Set system stat gauges.
|
|
gauge_scheduler_running.set(labels, stats.num_running)
|
|
gauge_scheduler_swapped.set(labels, stats.num_swapped)
|
|
gauge_scheduler_waiting.set(labels, stats.num_waiting)
|
|
gauge_gpu_cache_usage.set(labels, stats.gpu_cache_usage)
|
|
gauge_cpu_cache_usage.set(labels, stats.cpu_cache_usage)
|
|
|
|
# Add to token counters.
|
|
counter_prompt_tokens.add(labels, stats.num_prompt_tokens)
|
|
counter_generation_tokens.add(labels, stats.num_generation_tokens)
|
|
|
|
# Observe request level latencies in histograms.
|
|
for ttft in stats.time_to_first_tokens:
|
|
histogram_time_to_first_token.observe(labels, ttft)
|
|
for tpot in stats.time_per_output_tokens:
|
|
histogram_time_per_output_tokens.observe(labels, tpot)
|
|
for e2e in stats.time_e2e_requests:
|
|
histogram_e2e_request_latency.observe(labels, e2e)
|
|
|
|
def _log_prometheus_interval(self, prompt_throughput: float,
|
|
generation_throughput: float) -> None:
|
|
# Logs metrics to prometheus that are computed every logging_interval.
|
|
# Support legacy gauge metrics that make throughput calculations on the vLLM side.
|
|
# Moving forward, we should use counters like counter_prompt_tokens, counter_generation_tokens
|
|
# Which log raw data and calculate summaries using rate() on the grafana/prometheus side.
|
|
# See https://github.com/vllm-project/vllm/pull/2316#discussion_r1464204666
|
|
gauge_avg_prompt_throughput.set(labels, prompt_throughput)
|
|
gauge_avg_generation_throughput.set(labels, generation_throughput)
|
|
|
|
def log(self, stats: Stats) -> None:
|
|
"""Called by LLMEngine.
|
|
Logs to prometheus and tracked stats every iteration.
|
|
Logs to Stdout every self.local_interval seconds."""
|
|
|
|
# Log to prometheus.
|
|
self._log_prometheus(stats)
|
|
|
|
# Save tracked stats for token counters.
|
|
self.num_prompt_tokens.append(stats.num_prompt_tokens)
|
|
self.num_generation_tokens.append(stats.num_generation_tokens)
|
|
|
|
# Log locally every local_interval seconds.
|
|
if self._local_interval_elapsed(stats.now):
|
|
|
|
# Compute summary metrics for tracked stats (and log them to promethus if applicable).
|
|
prompt_throughput = self._get_throughput(self.num_prompt_tokens,
|
|
now=stats.now)
|
|
generation_throughput = self._get_throughput(
|
|
self.num_generation_tokens, now=stats.now)
|
|
self._log_prometheus_interval(
|
|
prompt_throughput=prompt_throughput,
|
|
generation_throughput=generation_throughput)
|
|
|
|
# Log to stdout.
|
|
logger.info(
|
|
f"Avg prompt throughput: {prompt_throughput:.1f} tokens/s, "
|
|
f"Avg generation throughput: {generation_throughput:.1f} tokens/s, "
|
|
f"Running: {stats.num_running} reqs, "
|
|
f"Swapped: {stats.num_swapped} reqs, "
|
|
f"Pending: {stats.num_waiting} reqs, "
|
|
f"GPU KV cache usage: {stats.gpu_cache_usage * 100:.1f}%, "
|
|
f"CPU KV cache usage: {stats.cpu_cache_usage * 100:.1f}%")
|
|
|
|
# Reset tracked stats for next interval.
|
|
self.num_prompt_tokens = []
|
|
self.num_generation_tokens = []
|
|
self.last_local_log = stats.now
|