[V1][Metrics] Replace prefix cache hit rate with queries/hits counters

With a hit rate metric, we need to avoid the situation where if the hit
rate drops due to a sudden increase in misses, the change gets diluted
by the large accumulated totals.

With Prometheus, it is better to log monotonic counters and use
Prometheus queries to calculate rates according to whatever time
interval makes sense to the operator, also allowing them to easily
adjust the time interval in their PromQL queries.

With the logging logger, we can continue to aggregate across an
interval of (roughly) 1000 requests.

Signed-off-by: Mark McLoughlin <markmc@redhat.com>

Author: markmc

tests/entrypoints/openai/test_metrics.py

@@ -203,7 +203,8 @@ async def test_metrics_counts(server: RemoteOpenAIServer,
     "vllm:num_requests_running",
     "vllm:num_requests_waiting",
     "vllm:gpu_cache_usage_perc",
-    "vllm:gpu_prefix_cache_hit_rate_perc",
+    "vllm:gpu_prefix_cache_queries",
+    "vllm:gpu_prefix_cache_hits",
     "vllm:prompt_tokens_total",
     "vllm:generation_tokens_total",
     "vllm:request_success_total",

tests/v1/core/test_kv_cache_utils.py

@@ -9,6 +9,7 @@
                                          generate_block_hash_extra_keys,
                                          hash_block_tokens,
                                          hash_request_tokens)
+from vllm.v1.metrics.stats import PrefixCacheStats
 from vllm.v1.request import Request
 
 
@@ -283,28 +284,33 @@ def test_metrics():
     """
     Test the prefix caching metrics.
     """
+
+    def stats(requests, queries, hits):
+        return PrefixCacheStats(requests=requests, queries=queries, hits=hits)
+
     metrics = PrefixCachingMetrics(interval=5)
     assert metrics.hit_rate == 0.0
 
-    metrics.add_request_query(20, 9)
+    metrics.observe(stats(1, 20, 9))
     # 9 / 20 = 0.45
     assert metrics.hit_rate == 0.45
 
-    for _ in range(4):
-        metrics.add_request_query(20, 4)
+    metrics.observe(stats(4, 80, 16))
 
     # 25 / 100 = 0.25
     assert metrics.hit_rate == 0.25
 
-    metrics.add_request_query(10, 2)
+    metrics.observe(stats(1, 10, 2))
 
     # Remove (20, 9) and add (10, 2): 18 / 90 = 0.2
+    assert metrics.aggregated_requests == 5
     assert metrics.aggregated_query_total == 90
     assert metrics.aggregated_query_hit == 18
     assert metrics.hit_rate == 0.2
 
     metrics.reset()
     assert metrics.hit_rate == 0.0
+    assert metrics.aggregated_requests == 0
     assert metrics.aggregated_query_total == 0
     assert metrics.aggregated_query_hit == 0
     assert not metrics.query_queue

vllm/v1/core/kv_cache_manager.py

@@ -6,10 +6,11 @@
 from vllm.logger import init_logger
 from vllm.utils import cdiv
 from vllm.v1.core.kv_cache_utils import (BlockHashType, FreeKVCacheBlockQueue,
-                                         KVCacheBlock, PrefixCachingMetrics,
+                                         KVCacheBlock,
                                          generate_block_hash_extra_keys,
                                          hash_block_tokens,
                                          hash_request_tokens)
+from vllm.v1.metrics.stats import PrefixCacheStats
 from vllm.v1.request import Request, RequestStatus
 
 logger = init_logger(__name__)
@@ -72,8 +73,7 @@ def __init__(
         self.req_to_blocks: DefaultDict[str,
                                         List[KVCacheBlock]] = defaultdict(list)
 
-        # Prefix cache metrics. TODO: Make the interval configurable.
-        self.prefix_caching_metrics = PrefixCachingMetrics(interval=1000)
+        self.prefix_cache_stats = PrefixCacheStats()
 
     @property
     def usage(self) -> float:
@@ -85,14 +85,15 @@ def usage(self) -> float:
         return 1.0 - (self.free_block_queue.num_free_blocks /
                       self.num_gpu_blocks)
 
-    @property
-    def prefix_cache_hit_rate(self) -> float:
-        """Get the prefix caching hit rate.
+    def make_prefix_cache_stats(self) -> PrefixCacheStats:
+        """Get (and reset) the prefix cache query and hit counts.
 
         Returns:
-            The prefix caching hit rate.
+            The prefix caching stats - query count, and hit count.
         """
-        return self.prefix_caching_metrics.hit_rate
+        stats = self.prefix_cache_stats
+        self.prefix_cache_stats = PrefixCacheStats()
+        return stats
 
     def get_computed_blocks(
             self, request: Request) -> Tuple[List[KVCacheBlock], int]:
@@ -129,10 +130,9 @@ def get_computed_blocks(
             else:
                 break
 
-        self.prefix_caching_metrics.add_request_query(
-            num_queries=len(block_hashes),
-            num_hits=len(computed_blocks),
-        )
+        self.prefix_cache_stats.requests += 1
+        self.prefix_cache_stats.queries += len(block_hashes)
+        self.prefix_cache_stats.hits += len(computed_blocks)
 
         # NOTE(woosuk): Since incomplete blocks are not eligible for
         # sharing, `num_computed_tokens` is always a multiple of
@@ -298,8 +298,7 @@ def reset_prefix_cache(self) -> bool:
         for block in self.block_pool:
             block.reset_hash()
 
-        # Reset the prefix caching metrics.
-        self.prefix_caching_metrics.reset()
+        self.prefix_cache_stats.reset = True
 
         logger.info("Successfully reset prefix cache")
         return True

vllm/v1/core/kv_cache_utils.py

@@ -9,6 +9,7 @@
 from vllm.logger import init_logger
 from vllm.v1.kv_cache_interface import (KVCacheConfig, KVCacheSpec,
                                         KVCacheTensor)
+from vllm.v1.metrics.stats import PrefixCacheStats
 from vllm.v1.request import Request
 
 logger = init_logger(__name__)
@@ -40,33 +41,44 @@ class PrefixCachingMetrics:
     def __init__(self, interval: int = 1000):
         self.interval = interval
         # The current aggregated query total and hit.
+        self.aggregated_requests = 0
         self.aggregated_query_total = 0
         self.aggregated_query_hit = 0
-        # A deque of (num_queries, num_hits) for the most recent requests.
-        self.query_queue: deque[Tuple[int, int]] = deque()
+        # A deque of (requests, queries, hits) for the most recent requests.
+        self.query_queue: deque[Tuple[int, int, int]] = deque()
 
-    def add_request_query(self, num_queries: int, num_hits: int):
-        """Add a request to the metrics. This function is called when
-        a new request is being scheduled and is looking for computed blocks.
-        When there are more than `interval` requests, the oldest request
-        is removed from the metrics.
+    def observe(self, stats: PrefixCacheStats):
+        """Observe the prefix caching for a set of requests.
 
-        Args:
-            num_queries: The number of queries in the request.
-            num_hits: The number of hits in the request.
+        This function is called with information gathered when new requests
+        are being scheduled and are looking for computed blocks.
+
+        When there are more than `interval` requests, the oldest set of
+        requestsare removed from the metrics.
+
+        Stats:
+            reset: Whether reset_prefix_cache was invoked.
+            requests: The number of requests in this update.
+            queries: The number of queries in these requests.
+            hits: The number of hits in these requests.
         """
+        if stats.reset:
+            self.reset()
 
-        self.query_queue.append((num_queries, num_hits))
-        if len(self.query_queue) > self.interval:
-            old_num_queries, old_num_hits = self.query_queue.popleft()
-            self.aggregated_query_total -= old_num_queries
-            self.aggregated_query_hit -= old_num_hits
+        self.query_queue.append((stats.requests, stats.queries, stats.hits))
+        self.aggregated_requests += stats.requests
+        self.aggregated_query_total += stats.queries
+        self.aggregated_query_hit += stats.hits
 
-        self.aggregated_query_total += num_queries
-        self.aggregated_query_hit += num_hits
+        if self.aggregated_requests > self.interval:
+            old_requests, old_queries, old_hits = self.query_queue.popleft()
+            self.aggregated_requests -= old_requests
+            self.aggregated_query_total -= old_queries
+            self.aggregated_query_hit -= old_hits
 
     def reset(self):
         """Reset the metrics."""
+        self.aggregated_requests = 0
         self.aggregated_query_total = 0
         self.aggregated_query_hit = 0
         self.query_queue.clear()

vllm/v1/core/scheduler.py

@@ -553,8 +553,7 @@ def make_stats(self) -> SchedulerStats:
             num_running_reqs=len(self.running),
             num_waiting_reqs=len(self.waiting),
             gpu_cache_usage=self.kv_cache_manager.usage,
-            gpu_prefix_cache_hit_rate=self.kv_cache_manager.
-            prefix_cache_hit_rate,
+            prefix_cache_stats=self.kv_cache_manager.make_prefix_cache_stats(),
         )
 
 

vllm/v1/metrics/loggers.py

@@ -9,6 +9,7 @@
 
 from vllm.config import ModelConfig
 from vllm.logger import init_logger
+from vllm.v1.core.kv_cache_utils import PrefixCachingMetrics
 from vllm.v1.engine import RequestFinishedReason
 from vllm.v1.metrics.stats import IterationStats, SchedulerStats
 
@@ -37,6 +38,9 @@ def _reset(self, now):
         self.num_prompt_tokens: List[int] = []
         self.num_generation_tokens: List[int] = []
 
+        # Prefix cache metrics. TODO: Make the interval configurable.
+        self.prefix_caching_metrics = PrefixCachingMetrics()
+
     def _local_interval_elapsed(self, now: float) -> bool:
         # Log every _LOCAL_LOGGING_INTERVAL_SEC.
         elapsed_time = now - self.last_log_time
@@ -58,6 +62,8 @@ def log(self, scheduler_stats: SchedulerStats,
 
         self._track_iteration_stats(iteration_stats)
 
+        self.prefix_caching_metrics.observe(scheduler_stats.prefix_cache_stats)
+
         now = time.monotonic()
         if not self._local_interval_elapsed(now):
             return
@@ -74,13 +80,13 @@ def log(self, scheduler_stats: SchedulerStats,
             "Avg generation throughput: %.1f tokens/s, "
             "Running: %d reqs, Waiting: %d reqs, "
             "GPU KV cache usage: %.1f%%, "
-            "GPU prefix cache hit rate: %.1f%%",
+            "Prefix cache hit rate: %.1f%%",
             prompt_throughput,
             generation_throughput,
             scheduler_stats.num_running_reqs,
             scheduler_stats.num_waiting_reqs,
             scheduler_stats.gpu_cache_usage * 100,
-            scheduler_stats.gpu_prefix_cache_hit_rate * 100,
+            self.prefix_caching_metrics.hit_rate * 100,
         )
 
 
@@ -109,10 +115,16 @@ def __init__(self, model_config: ModelConfig):
             documentation="GPU KV-cache usage. 1 means 100 percent usage.",
             labelnames=labelnames).labels(*labelvalues)
 
-        self.gauge_gpu_prefix_cache_hit_rate = prometheus_client.Gauge(
-            name="vllm:gpu_prefix_cache_hit_rate_perc",
+        self.counter_gpu_prefix_cache_queries = prometheus_client.Counter(
+            name="vllm:gpu_prefix_cache_queries",
+            documentation=
+            "GPU prefix cache queries, in terms of number of queried blocks.",
+            labelnames=labelnames).labels(*labelvalues)
+
+        self.counter_gpu_prefix_cache_hits = prometheus_client.Counter(
+            name="vllm:gpu_prefix_cache_hits",
             documentation=
-            "GPU prefix cache hit rate. 1 means 100 percent hit rate.",
+            "GPU prefix cache hits, in terms of number of cached blocks.",
             labelnames=labelnames).labels(*labelvalues)
 
         self.counter_prompt_tokens = prometheus_client.Counter(
@@ -177,8 +189,11 @@ def log(self, scheduler_stats: SchedulerStats,
         self.gauge_scheduler_waiting.set(scheduler_stats.num_waiting_reqs)
 
         self.gauge_gpu_cache_usage.set(scheduler_stats.gpu_cache_usage)
-        self.gauge_gpu_prefix_cache_hit_rate.set(
-            scheduler_stats.gpu_prefix_cache_hit_rate)
+
+        self.counter_gpu_prefix_cache_queries.inc(
+            scheduler_stats.prefix_cache_stats.queries)
+        self.counter_gpu_prefix_cache_hits.inc(
+            scheduler_stats.prefix_cache_stats.hits)
 
         self.counter_prompt_tokens.inc(iteration_stats.num_prompt_tokens)
         self.counter_generation_tokens.inc(

vllm/v1/metrics/stats.py

@@ -1,14 +1,23 @@
 # SPDX-License-Identifier: Apache-2.0
 
 import time
-from dataclasses import dataclass
+from dataclasses import dataclass, field
 from typing import TYPE_CHECKING, List
 
 if TYPE_CHECKING:
     from vllm.outputs import RequestOutput
     from vllm.v1.engine import EngineCoreOutput, RequestFinishedReason
 
 
+@dataclass
+class PrefixCacheStats:
+    """Stores prefix cache hit statistics."""
+    reset: bool = False
+    requests: int = 0
+    hits: int = 0
+    queries: int = 0
+
+
 @dataclass
 class SchedulerStats:
     """Stats associated with the scheduler."""
@@ -17,7 +26,9 @@ class SchedulerStats:
     num_waiting_reqs: int = 0
 
     gpu_cache_usage: float = 0.0
-    gpu_prefix_cache_hit_rate: float = 0.0
+
+    prefix_cache_stats: PrefixCacheStats = field(
+        default_factory=PrefixCacheStats)
 
 
 @dataclass