diff --git a/backends/exllamav3/model.py b/backends/exllamav3/model.py index a0902327..f64a3d75 100644 --- a/backends/exllamav3/model.py +++ b/backends/exllamav3/model.py @@ -37,6 +37,7 @@ from common.health import HealthManager from common.errors import ContextLengthExceededError, validate_context_requirements from common.logger import xlogger +from common.metrics import MetricsManager from common.multimodal import MultimodalEmbeddingWrapper from common.networking import DisconnectHandler from common.optional_dependencies import check_package_version @@ -351,6 +352,12 @@ async def create(cls, model_directory: pathlib.Path, hf_model: HFModel, **kwargs self.max_seq_len = max_seq_len self.cache_size = cache_size + # Size the /metrics token histograms to this model's context length. + # Their buckets are meaningless until the range they have to cover is + # known, and a ladder that overshoots it reports percentiles above any + # request the server can even accept. + MetricsManager.configure_token_buckets(max_seq_len) + # Max batch size default_mbs = 4 if self.model.caps.get("recurrent_states") else 128 self.max_batch_size = unwrap(kwargs.get("max_batch_size"), default_mbs) @@ -1065,7 +1072,8 @@ def handle_finish_chunk(self, result: dict, request_id: str, full_text: str): # Prompt prompt_tokens = result.get("prompt_tokens") cached_tokens = round(result.get("cached_tokens"), 2) - prompt_time = round(result.get("time_prefill"), 2) + raw_prompt_time = result.get("time_prefill") + prompt_time = round(raw_prompt_time, 2) prompt_ts = ( "Indeterminate" if prompt_time == 0 @@ -1111,6 +1119,20 @@ def handle_finish_chunk(self, result: dict, request_id: str, full_text: str): } ) + # Accumulate server-wide metrics for the /metrics endpoint + MetricsManager.record_generation( + prompt_tokens=prompt_tokens, + cached_tokens=cached_tokens, + gen_tokens=gen_tokens, + # Unrounded, so the aggregate rates are not skewed by the 0.01s + # display rounding on short prefills. + prompt_time=raw_prompt_time, + gen_time=gen_time, + queue_time=queue_time, + accepted_draft_tokens=accepted_draft_tokens, + rejected_draft_tokens=rejected_draft_tokens, + ) + return finish_chunk async def generate_gen( diff --git a/common/config_models.py b/common/config_models.py index fb0db10e..0528a5ee 100644 --- a/common/config_models.py +++ b/common/config_models.py @@ -81,6 +81,14 @@ class NetworkConfig(BaseConfigModel): ), ge=0, ) + enable_metrics: Optional[bool] = Field( + False, + description=( + "Enable the Prometheus-compatible /metrics endpoint (default: False).\n" + "Exposes aggregate inference stats in the text exposition format.\n" + "NOTE: This endpoint is not protected by API key authentication." + ), + ) # Converts all strings in the api_servers list to lowercase # NOTE: Expand if more models need this validator diff --git a/common/metrics.py b/common/metrics.py new file mode 100644 index 00000000..64b114a8 --- /dev/null +++ b/common/metrics.py @@ -0,0 +1,974 @@ +"""Global inference metrics for the Prometheus-compatible /metrics endpoint. + +Modeled after llama.cpp's `/metrics` exporter: process-lifetime counters are +accumulated as generations finish, while gauges (throughput, in-flight and +queued requests, KV-cache usage) are computed live at scrape time. Per-request +latency and size distributions are recorded as histograms, following the +conventional metric set for an inference server. All access happens on the +single asyncio event loop, so plain attributes are safe without locking. +""" + +import time + + +# Bucket boundaries are the ones inference-server dashboards conventionally +# expect, so they keep working after a prefix swap. Seconds-valued latency +# histograms share one coarse set; the +# time-to-first-token histogram gets a finer sub-second set since prefill is +# often fast. Per-request token counts use a 1-2-5 progression. +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, + 40.0, + 50.0, + 60.0, + 120.0, + 240.0, + 480.0, + 960.0, + 1920.0, + 7680.0, +] +TTFT_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, +] +# Token-count buckets are built from the loaded model's context length rather +# than fixed, which is the conventional approach. A fixed ladder to 1M was the +# source of a +# real misreading: with a 256k context the top boundaries were 200k and 500k, so +# a server answering 200k-token prompts put every sample a few thousand above +# the floor of a 300k-wide bucket, and histogram_quantile -- which assumes +# samples are spread across the bucket they landed in -- reported a p99 of 493k +# against a largest-ever prompt of 206k. +# +# One boundary beyond the 1-2-5 ladder is added at max_seq_len itself. Stopping +# at the last mantissa value below the limit, as the usual construction does, +# leaves everything between there and the real limit in +Inf: at 262144 the +# ladder ends at 200000 and the top 24% of the usable range has no bucket. +DEFAULT_MAX_TOKENS = 1_000_000 + + +def build_1_2_5_buckets(max_value: int) -> list[int]: + """Increasing powers of 10 times 1, 2 and 5, up to and including max_value. + + >>> build_1_2_5_buckets(100) + [1, 2, 5, 10, 20, 50, 100] + """ + + buckets: list[int] = [] + exponent = 0 + while True: + for mantissa in (1, 2, 5): + value = mantissa * 10**exponent + if value > max_value: + if buckets and buckets[-1] < max_value: + buckets.append(max_value) + return buckets + buckets.append(value) + exponent += 1 + + +# Per-request draft acceptance is a ratio in [0, 1], so it gets its own evenly +# spaced buckets rather than the token or latency sets. +ACCEPTANCE_BUCKETS = [ + 0.05, + 0.1, + 0.2, + 0.3, + 0.4, + 0.5, + 0.6, + 0.7, + 0.8, + 0.9, + 0.95, + 1.0, +] + + +class _Histogram: + """A minimal cumulative-bucket histogram for the Prometheus text format.""" + + def __init__(self, buckets: list[float]): + # Upper bounds in ascending order. observe() tallies each value into the + # first bucket it fits; render sums them cumulatively, as Prometheus + # histogram buckets are "less than or equal" and cumulative. + self.buckets = buckets + self.counts = [0] * len(buckets) + self.sum = 0.0 + self.count = 0 + + def observe(self, value: float): + self.sum += value + self.count += 1 + for i, upper in enumerate(self.buckets): + if value <= upper: + self.counts[i] += 1 + return + # A value above the last bucket is reflected only in +Inf / _count. + + +class MetricsManagerClass: + """Tracks process-lifetime inference stats for the /metrics endpoint.""" + + def __init__(self): + self.process_start_time = time.time() + + # Counters (monotonic over the process lifetime) + # prompt_tokens_total counts only tokens actually processed, matching + # llama.cpp's counter of the same name. Tokens served from the prefix + # cache are tracked separately, so the full prompt length over the + # process lifetime is prompt_tokens_total + cached_tokens_total. + self.prompt_tokens_total = 0 + self.cached_tokens_total = 0 + self.gen_tokens_total = 0 + self.prompt_seconds_total = 0.0 + self.gen_seconds_total = 0.0 + self.requests_total = 0 + # Largest prompt and largest completion seen. The request_prompt_tokens + # and request_generation_tokens histograms describe the distribution but + # cannot report an extreme: the top sample sits above every percentile, + # and once it lands in the final bucket its magnitude is lost. These + # keep the peaks readable. Both only ever rise, so they are counters. + self.n_tokens_max = 0 + self.tokens_predicted_max = 0 + + # No prefill throughput gauge is derived from the two counters above, + # deliberately. The backend times prefill as one span per request, and + # that span cannot be split into time spent on cached versus newly + # processed tokens: a prefix cache hit takes tokens out of + # prompt_tokens_total while the lookup, page allocation and per-chunk + # overhead it still paid for stay in prompt_seconds_total. Their ratio + # therefore reads low and keeps sinking as reuse accumulates. Measured + # on a 27B model, a warm request contributing 12 tokens in 37ms drags a + # lifetime average towards ~320 T/s against a real rate of ~1646 T/s. + # + # Restricting the sample to requests that computed enough tokens for the + # ~30ms of fixed per-request overhead to vanish does fix the bias, but a + # server fronting a harness with a stable system prefix may never see + # more than one such request, and the first one carries the autotuning + # pass (measured 1.6% slow), so the estimator is pinned to its single + # worst sample. Prefill speed is a benchmark quantity; measure it with + # exllamav3's eval/perf.py or from the per-request log line. + # + # What is well defined here is the rate of work over wall clock, which + # rate(prompt_tokens_total[5m]) gives without any of this reasoning. + + # Speculative decoding counters, using the conventional spec-decode + # metric names. A "draft token" is one the drafter proposed; it is accepted + # when the target model samples the same token, otherwise it and every + # draft position after it are rejected, so accepted + rejected is the + # number of tokens drafted. Only requests served with drafting enabled + # contribute, tracked by draft_requests_total so the acceptance rate is + # not diluted by non-drafted requests. + self.draft_tokens_accepted_total = 0 + self.draft_tokens_rejected_total = 0 + self.draft_requests_total = 0 + # Decode steps over drafted requests only. exllamav3 does not count + # draft rounds, but every decode step emits exactly one token from the + # target model and the accepted drafts ride along on top of it, so + # (gen_tokens - accepted) recovers the step count exactly. + self.draft_decode_steps_total = 0 + + # Per-request distributions, as histograms. Latency is split + # into the queue / prefill / decode phases the backend already times, + # plus derived time-to-first-token (queue + prefill) and end-to-end + # totals; token counts cover the full prompt and the generation. + self.hist_queue_time = _Histogram(LATENCY_BUCKETS) + self.hist_prefill_time = _Histogram(LATENCY_BUCKETS) + self.hist_decode_time = _Histogram(LATENCY_BUCKETS) + self.hist_ttft = _Histogram(TTFT_BUCKETS) + self.hist_e2e = _Histogram(LATENCY_BUCKETS) + self.token_buckets = build_1_2_5_buckets(DEFAULT_MAX_TOKENS) + self.hist_prompt_tokens = _Histogram(self.token_buckets) + self.hist_gen_tokens = _Histogram(self.token_buckets) + self.hist_draft_acceptance = _Histogram(ACCEPTANCE_BUCKETS) + + def configure_token_buckets(self, max_seq_len: int): + """Size the token histograms for the loaded model's context length. + + Called on model load, when max_seq_len is finally known. Changing the + boundaries discards whatever those two histograms had accumulated, + since counts against a different ladder cannot be carried over, so this + is a no-op when the buckets come out unchanged. + """ + + if not max_seq_len or max_seq_len < 1: + return + buckets = build_1_2_5_buckets(max_seq_len) + if buckets == self.token_buckets: + return + self.token_buckets = buckets + self.hist_prompt_tokens = _Histogram(buckets) + self.hist_gen_tokens = _Histogram(buckets) + + def record_generation( + self, + prompt_tokens: int, + cached_tokens: float, + gen_tokens: int, + prompt_time: float, + gen_time: float, + queue_time: float = 0.0, + accepted_draft_tokens: int = None, + rejected_draft_tokens: int = None, + ): + """Accumulate stats from a single finished generation. + + `prompt_tokens` is the full prompt length and `cached_tokens` the part + of it served from the prefix cache; only the difference was processed. + `queue_time`, `prompt_time` and `gen_time` are the queue, prefill and + decode phase durations in seconds. + + `accepted_draft_tokens` / `rejected_draft_tokens` are the speculative + decoding tallies, and are None when the request ran without a drafter. + """ + + prompt_tokens = prompt_tokens or 0 + cached_tokens = cached_tokens or 0 + gen_tokens = gen_tokens or 0 + prompt_time = prompt_time or 0.0 + gen_time = gen_time or 0.0 + queue_time = queue_time or 0.0 + + self.prompt_tokens_total += prompt_tokens - cached_tokens + self.cached_tokens_total += cached_tokens + self.gen_tokens_total += gen_tokens + self.prompt_seconds_total += prompt_time + self.gen_seconds_total += gen_time + self.requests_total += 1 + self.n_tokens_max = max(self.n_tokens_max, prompt_tokens) + self.tokens_predicted_max = max(self.tokens_predicted_max, gen_tokens) + + # Time to first token is the wait in queue plus prefill; end-to-end adds + # the decode phase on top. + self.hist_queue_time.observe(queue_time) + self.hist_prefill_time.observe(prompt_time) + self.hist_decode_time.observe(gen_time) + self.hist_ttft.observe(queue_time + prompt_time) + self.hist_e2e.observe(queue_time + prompt_time + gen_time) + self.hist_prompt_tokens.observe(prompt_tokens) + self.hist_gen_tokens.observe(gen_tokens) + + # Drafting stats are absent when no drafter is configured; a request + # that ran with one but happened to draft nothing still counts, so the + # None check has to stay distinct from a zero tally. + if accepted_draft_tokens is not None: + accepted = accepted_draft_tokens or 0 + rejected = rejected_draft_tokens or 0 + drafted = accepted + rejected + + self.draft_tokens_accepted_total += accepted + self.draft_tokens_rejected_total += rejected + self.draft_requests_total += 1 + self.draft_decode_steps_total += max(gen_tokens - accepted, 0) + + if drafted > 0: + self.hist_draft_acceptance.observe(accepted / drafted) + + def _live_request_counts(self) -> tuple[int, int]: + """Read (processing, deferred) request counts from the generator. + + Returns zeros if no model is loaded or the backend does not expose + job counts. + """ + + # Imported lazily to avoid a circular import (common.model pulls in the + # backends, which import this module). + from common import model + + container = model.container + generator = getattr(container, "generator", None) if container else None + sync_generator = getattr(generator, "generator", None) if generator else None + + if sync_generator is None: + return 0, 0 + + try: + return sync_generator.num_active_jobs(), sync_generator.num_pending_jobs() + except Exception: + return 0, 0 + + def _live_kv_cache(self) -> tuple[int, int]: + """Read (used_tokens, max_tokens) of the paged KV cache from the generator. + + Usage is measured over pages currently referenced by in-flight jobs, the + instantaneous KV load. Unreferenced pages may still hold reusable prompt + prefixes but are free to be evicted, so they count as headroom rather than + usage (matching llama.cpp's kv_cache_usage_ratio). Returns zeros if no + model is loaded or the backend does not expose a page table. + """ + + # Imported lazily to avoid a circular import (common.model pulls in the + # backends, which import this module). + from common import model + + container = model.container + generator = getattr(container, "generator", None) if container else None + sync_generator = getattr(generator, "generator", None) if generator else None + pagetable = getattr(sync_generator, "pagetable", None) if sync_generator else None + + if pagetable is None: + return 0, 0 + + try: + max_pages = pagetable.max_pages + max_tokens = sync_generator.max_total_tokens + page_size = max_tokens // max_pages if max_pages else 0 + used_tokens = len(pagetable.referenced_pages) * page_size + return used_tokens, max_tokens + except Exception: + return 0, 0 + + def _live_kv_offload(self) -> dict: + """Read the state of the CPU page cache (pages evicted to system RAM). + + Returns a zero-filled dict when offloading is disabled or no model is + loaded, so the series exist unconditionally rather than appearing and + disappearing across scrapes. + + The counters here live in the generator's page cache, not in this + object, so they restart from zero whenever the generator is recreated + (model reload, or recovery from a backend error). Prometheus detects + counter resets, so rate() over them stays correct across a reload; + absolute values are only meaningful within one generator's lifetime. + """ + + from common import model + + empty = { + "tokens": 0, + "max_tokens": 0, + "usage_ratio": 0.0, + "bytes": 0, + "max_bytes": 0, + "restored_tokens": 0, + "stores": 0, + "deduped_stores": 0, + "evictions": 0, + "cold_allocs": 0, + "bytes_read": 0, + "bytes_written": 0, + } + + container = model.container + generator = getattr(container, "generator", None) if container else None + sync_generator = getattr(generator, "generator", None) if generator else None + cpu_cache = getattr(sync_generator, "cpu_page_cache", None) if sync_generator else None + + if cpu_cache is None: + return empty + + try: + counters = cpu_cache.metrics + pages = len(cpu_cache) + max_pages = cpu_cache.max_slots + # One slot holds the whole per-layer page image across the attached + # caches, so it is also the size of a single transfer in either + # direction. + slot_size = cpu_cache.slot_size + + # Page-granular counts are converted to tokens so they read on the + # same axis as kv_cache_tokens. The number of tokens per page is + # fixed by the generator's page size, which the page cache does not + # carry, so it is taken from the page table. + pagetable = getattr(sync_generator, "pagetable", None) + pt_max_pages = getattr(pagetable, "max_pages", 0) if pagetable else 0 + tokens_per_page = sync_generator.max_total_tokens // pt_max_pages if pt_max_pages else 0 + + return { + "tokens": pages * tokens_per_page, + "max_tokens": max_pages * tokens_per_page, + "usage_ratio": pages / max_pages if max_pages else 0.0, + "bytes": pages * slot_size, + "max_bytes": max_pages * slot_size, + # A restore reads back a whole page, which is one page of prompt + # that did not have to be prefilled again. These tokens are + # already counted in cached_tokens_total, which does not + # distinguish a page found in VRAM from one read back over + # PCIe; this series is that breakdown, and the ratio against + # cached_tokens_total says how much of the prefix cache is + # actually being served out of RAM. + "restored_tokens": counters["restores"] * tokens_per_page, + "stores": counters["pushes"], + "deduped_stores": counters["dedup_hits"], + "evictions": counters["evictions"], + "cold_allocs": counters["cold_allocs"], + # Every transfer moves exactly one slot, in whole, so the byte + # totals are exact rather than an estimate. + "bytes_read": counters["restores"] * slot_size, + "bytes_written": counters["pushes"] * slot_size, + } + except Exception: + return empty + + def _live_recurrent(self) -> dict: + """Read the state of the recurrent checkpoint cache on hybrid models. + + Hybrid architectures interleave full-attention layers, whose state is + the paged K/V cache, with linear-attention layers, whose state is a + single evolving tensor that cannot be indexed by position. The generator + checkpoints the latter to system RAM at page boundaries, and prompt + reuse is capped at the longest prefix that has *both* valid K/V pages + and a matching recurrent checkpoint. + + That cap is why these series matter: if the checkpoint for a prefix is + evicted, its K/V pages are unusable however well the KV cache held them, + and with offloading enabled they will have been read back over PCIe + first. recurrent_capped_tokens_total counts exactly that waste. + + Returns zeros on non-hybrid models, where there is no recurrent state. + """ + + from common import model + + empty = { + "checkpoints": 0, + "bytes": 0, + "max_bytes": 0, + "usage_ratio": 0.0, + "checkpoint_bytes": 0, + "evictions": 0, + "stranded_evictions": 0, + "live_kv_evictions": 0, + "pruned": 0, + "stranded_by_kv": 0, + "capped_tokens": 0, + } + + container = model.container + generator = getattr(container, "generator", None) if container else None + sync_generator = getattr(generator, "generator", None) if generator else None + if sync_generator is None: + return empty + + recurrent_cache = getattr(sync_generator, "recurrent_cache", None) + pagetable = getattr(sync_generator, "pagetable", None) + + out = dict(empty) + + # Read in two stages, so a cache object in an unexpected state does not + # take the page table's figures down with it. The cap is the series + # these exist for, and losing it would hide the failure it reports. + try: + if pagetable is not None: + pt_counters = pagetable.metrics + max_pages = pagetable.max_pages + tokens_per_page = sync_generator.max_total_tokens // max_pages if max_pages else 0 + out.update( + { + "capped_tokens": (pt_counters["alloc_kv_only_pages"] * tokens_per_page), + "stranded_by_kv": pt_counters["stashes_stranded"], + } + ) + except Exception: + pass + + if recurrent_cache is None: + return out + + try: + counters = recurrent_cache.metrics + checkpoints = len(recurrent_cache) + current_size = recurrent_cache.current_size + max_size = recurrent_cache.max_size + out.update( + { + "checkpoints": checkpoints, + "bytes": current_size, + "max_bytes": max_size, + "usage_ratio": current_size / max_size if max_size else 0.0, + # Published because it is the unit the budget is spent in: a + # checkpoint is indivisible, so max_bytes / checkpoint_bytes + # is how many prefixes can be resumed at all. + "checkpoint_bytes": (current_size // checkpoints if checkpoints else 0), + "evictions": counters["stash_evictions"], + "stranded_evictions": counters["stash_evictions_stranded"], + "live_kv_evictions": counters["stash_evictions_live_kv"], + "pruned": counters["stash_pruned"], + } + ) + except Exception: + # The dict above is built whole before it is applied, so a failed + # read leaves the page table's figures in place rather than a + # half-updated mix of the two. + pass + + return out + + def render_prometheus(self) -> str: + """Render all metrics in the Prometheus text exposition format.""" + + requests_processing, requests_deferred = self._live_request_counts() + kv_cache_tokens, kv_cache_max_tokens = self._live_kv_cache() + offload = self._live_kv_offload() + recurrent = self._live_recurrent() + kv_cache_usage_ratio = ( + kv_cache_tokens / kv_cache_max_tokens if kv_cache_max_tokens > 0 else 0.0 + ) + + # Prefix-cache effectiveness is exposed as the raw queries/hits token + # counters, leaving the hit ratio to be computed at query + # time with rate() so it reflects recent behavior rather than a + # lifetime average. + prefix_cache_queries = self.prompt_tokens_total + self.cached_tokens_total + prefix_cache_hits = self.cached_tokens_total + + # There is no prefill counterpart to this gauge on purpose; see the + # counter definitions. Decode time has no cached-token analogue to skew + # it, so generation tokens over decode seconds is what it claims to be. + predicted_tokens_seconds = ( + self.gen_tokens_total / self.gen_seconds_total if self.gen_seconds_total > 0 else 0.0 + ) + + # Speculative decoding effectiveness. The two raw counters are the + # primitives to rate() over; these gauges are the lifetime + # summary, cheap to read without a query language. Acceptance rate is + # per drafted token, mean accepted length is per decode step (how many + # drafts a step gets for free), and tokens per step adds the target + # model's own token, so it is the decode speedup factor over no drafter. + draft_tokens_total = self.draft_tokens_accepted_total + self.draft_tokens_rejected_total + draft_acceptance_rate = ( + self.draft_tokens_accepted_total / draft_tokens_total if draft_tokens_total > 0 else 0.0 + ) + draft_mean_accepted_len = ( + self.draft_tokens_accepted_total / self.draft_decode_steps_total + if self.draft_decode_steps_total > 0 + else 0.0 + ) + draft_tokens_per_step = ( + 1.0 + draft_mean_accepted_len if self.draft_decode_steps_total else 0.0 + ) + + # (type, name, help, value) + # Names and help text of the shared metrics are kept verbatim from + # llama.cpp's exporter so its dashboards work after a prefix swap. + # tabbyAPI-only metrics follow the ones they relate to. The one + # deliberate omission from that set is prompt_tokens_seconds; see the + # counter definitions for why it is not a quantity worth publishing. + metrics = [ + # Published so the phase-time counters below can be read against + # wall clock. Without it prompt_seconds_total and + # tokens_predicted_seconds_total give the split between prefill and + # decode but not what either costs against a real interval, and the + # standard name means the usual process dashboards pick it up. + ( + "gauge", + "process_start_time_seconds", + "Start time of the process since the Unix epoch, in seconds.", + self.process_start_time, + ), + ( + "counter", + "prompt_tokens_total", + "Number of prompt tokens processed.", + self.prompt_tokens_total, + ), + ( + "counter", + "cached_tokens_total", + "Number of prompt tokens skipped via the prefix cache.", + self.cached_tokens_total, + ), + ( + "counter", + "prefix_cache_queries", + "Prefix cache queries, in terms of number of queried tokens.", + prefix_cache_queries, + ), + ( + "counter", + "prefix_cache_hits", + "Prefix cache hits, in terms of number of cached tokens.", + prefix_cache_hits, + ), + ( + "counter", + "prompt_seconds_total", + "Prompt process time", + self.prompt_seconds_total, + ), + ( + "counter", + "tokens_predicted_total", + "Number of generation tokens processed.", + self.gen_tokens_total, + ), + ( + "counter", + "tokens_predicted_seconds_total", + "Predict process time", + self.gen_seconds_total, + ), + ( + "counter", + "n_tokens_max", + "Largest observed n_tokens.", + self.n_tokens_max, + ), + ( + "counter", + "tokens_predicted_max", + "Largest observed number of generation tokens in one request.", + self.tokens_predicted_max, + ), + ( + "counter", + "requests_total", + "Number of finished generation requests.", + self.requests_total, + ), + ( + "gauge", + "predicted_tokens_seconds", + "Average generation throughput in tokens/s.", + predicted_tokens_seconds, + ), + ( + "counter", + "spec_decode_num_draft_tokens_total", + "Number of tokens proposed by the drafter.", + draft_tokens_total, + ), + ( + "counter", + "spec_decode_num_accepted_tokens_total", + "Number of drafted tokens accepted by the target model.", + self.draft_tokens_accepted_total, + ), + ( + "counter", + "spec_decode_num_decode_steps_total", + "Number of decode steps over requests served with a drafter.", + self.draft_decode_steps_total, + ), + ( + "counter", + "spec_decode_requests_total", + "Number of finished requests served with a drafter.", + self.draft_requests_total, + ), + ( + "gauge", + "spec_decode_draft_acceptance_rate", + "Fraction of drafted tokens accepted. 1 means every draft was accepted.", + draft_acceptance_rate, + ), + ( + "gauge", + "spec_decode_mean_accepted_length", + "Average drafted tokens accepted per decode step.", + draft_mean_accepted_len, + ), + ( + "gauge", + "spec_decode_tokens_per_step", + "Average tokens emitted per decode step, including the target model's own.", + draft_tokens_per_step, + ), + ( + "gauge", + "requests_processing", + "Number of requests processing.", + requests_processing, + ), + ( + "gauge", + "requests_deferred", + "Number of requests deferred.", + requests_deferred, + ), + ( + "gauge", + "kv_cache_usage_ratio", + "KV-cache usage. 1 means 100 percent usage.", + kv_cache_usage_ratio, + ), + ( + "gauge", + "kv_cache_tokens", + "KV-cache tokens.", + kv_cache_tokens, + ), + ( + "gauge", + "kv_cache_max_tokens", + "Total KV-cache token capacity.", + kv_cache_max_tokens, + ), + # KV offload cache. Deliberately no bytes-per-second gauge: a + # lifetime average of transfer rate is as misleading here as it is + # for prefill, since it divides by wall clock that includes every + # scrape interval with no transfers at all. The bytes counters below + # give the real thing under rate(), and PCIe bandwidth is a constant + # of the machine rather than something to watch drift. + ( + "gauge", + "kv_offload_usage_ratio", + "KV offload cache usage. 1 means 100 percent usage.", + offload["usage_ratio"], + ), + ( + "gauge", + "kv_offload_tokens", + "Tokens of KV cache currently held in system RAM.", + offload["tokens"], + ), + ( + "gauge", + "kv_offload_max_tokens", + "Total KV offload cache token capacity.", + offload["max_tokens"], + ), + ( + "gauge", + "kv_offload_bytes", + "System RAM currently holding cache pages, in bytes.", + offload["bytes"], + ), + # The backend pins the whole configured capacity up front, in the + # background, so this is the RAM cost of the feature whatever the + # usage gauge above reads. + ( + "gauge", + "kv_offload_max_bytes", + "Configured size of the KV offload cache, in bytes.", + offload["max_bytes"], + ), + # Taken against cached_tokens_total this is the share of prefix + # cache hits that came back over PCIe rather than being found in + # VRAM, in the same raw-counter form as prefix_cache_queries/hits so + # rate() gives recent behavior rather than a lifetime average. + ( + "counter", + "kv_offload_restored_tokens_total", + "Prompt tokens read back from system RAM instead of being prefilled again.", + offload["restored_tokens"], + ), + # Evictions climbing towards stores means the cache is too small for + # the working set and pages are being written out only to be + # discarded before anyone reads them back. + ( + "counter", + "kv_offload_stores_total", + "Pages copied from VRAM into the KV offload cache.", + offload["stores"], + ), + ( + "counter", + "kv_offload_deduped_stores_total", + "Page stores skipped because the page was already held in system RAM.", + offload["deduped_stores"], + ), + ( + "counter", + "kv_offload_evictions_total", + "Pages dropped from the KV offload cache to make room.", + offload["evictions"], + ), + # The backend pins slabs ahead of demand on a background thread. A + # store that outruns it has to pin synchronously, at roughly + # 2.5 GB/s, on the generator's own thread. Nonzero early in a + # process is expected; nonzero later is a stall worth seeing. + ( + "counter", + "kv_offload_cold_allocs_total", + "Page stores that had to pin system memory synchronously.", + offload["cold_allocs"], + ), + ( + "counter", + "kv_offload_read_bytes_total", + "Bytes transferred from system RAM to VRAM restoring cache pages.", + offload["bytes_read"], + ), + ( + "counter", + "kv_offload_written_bytes_total", + "Bytes transferred from VRAM to system RAM evicting cache pages.", + offload["bytes_written"], + ), + # Recurrent checkpoint cache (hybrid models only). Zero everywhere on + # a pure transformer, which has no recurrent layers to checkpoint. + ( + "gauge", + "recurrent_cache_usage_ratio", + "Recurrent checkpoint cache usage. 1 means 100 percent usage.", + recurrent["usage_ratio"], + ), + ( + "gauge", + "recurrent_checkpoints", + "Recurrent state checkpoints currently held in system RAM.", + recurrent["checkpoints"], + ), + ( + "gauge", + "recurrent_cache_bytes", + "System RAM currently holding recurrent checkpoints, in bytes.", + recurrent["bytes"], + ), + ( + "gauge", + "recurrent_cache_max_bytes", + "Configured size of the recurrent checkpoint cache, in bytes.", + recurrent["max_bytes"], + ), + ( + "gauge", + "recurrent_checkpoint_bytes", + "Mean size of one recurrent checkpoint, in bytes.", + recurrent["checkpoint_bytes"], + ), + ( + "counter", + "recurrent_cache_evictions_total", + "Recurrent checkpoints dropped to make room.", + recurrent["evictions"], + ), + # The eviction breakdown is what says whether the budget is actually + # too small. A stranded checkpoint had already lost the K/V pages it + # anchors and could never have been resumed, so dropping it costs + # nothing; the same for one pruned while idle. A checkpoint dropped + # while its anchor page was still cached is the one that hurts, and + # is the direct precursor of recurrent_capped_tokens_total below. + ( + "counter", + "recurrent_cache_stranded_evictions_total", + "Recurrent checkpoints dropped that were already unresumable.", + recurrent["stranded_evictions"], + ), + ( + "counter", + "recurrent_cache_live_kv_evictions_total", + "Recurrent checkpoints dropped while their anchor KV page was still cached.", + recurrent["live_kv_evictions"], + ), + ( + "counter", + "recurrent_cache_pruned_total", + "Unresumable recurrent checkpoints reclaimed while the generator was idle.", + recurrent["pruned"], + ), + # The mirror of live_kv_evictions, and the reason the two budgets + # have to be sized against each other rather than independently: + # here the KV cache is the one under pressure, and evicting a page + # stranded the checkpoint anchored to it. + ( + "counter", + "recurrent_stranded_by_kv_total", + "Recurrent checkpoints stranded by eviction of the KV page anchoring them.", + recurrent["stranded_by_kv"], + ), + # The cost of an undersized recurrent cache, and the one series that + # ties the two caches together: these tokens had valid K/V in the + # cache and were still re-prefilled, because the recurrent state that + # goes with them was gone. With offloading on, they were also read + # back over PCIe before being discarded. + ( + "counter", + "recurrent_capped_tokens_total", + "Tokens with valid KV that were re-prefilled anyway, for lack of recurrent state.", + recurrent["capped_tokens"], + ), + ] + + # (name, help, histogram) + histograms = [ + ( + "request_queue_time_seconds", + "Histogram of time spent in the queue before prefill, in seconds.", + self.hist_queue_time, + ), + ( + "request_prefill_time_seconds", + "Histogram of prefill (prompt processing) time in seconds.", + self.hist_prefill_time, + ), + ( + "request_decode_time_seconds", + "Histogram of decode (generation) time in seconds.", + self.hist_decode_time, + ), + ( + "time_to_first_token_seconds", + "Histogram of time to first token in seconds.", + self.hist_ttft, + ), + ( + "e2e_request_latency_seconds", + "Histogram of end to end request latency in seconds.", + self.hist_e2e, + ), + ( + "request_prompt_tokens", + "Histogram of number of prompt tokens per request.", + self.hist_prompt_tokens, + ), + ( + "request_generation_tokens", + "Histogram of number of generation tokens per request.", + self.hist_gen_tokens, + ), + ( + "spec_decode_acceptance_rate", + "Histogram of per-request draft acceptance rate.", + self.hist_draft_acceptance, + ), + ] + + lines = [] + for metric_type, name, help_text, value in metrics: + full_name = f"tabbyapi:{name}" + lines.append(f"# HELP {full_name} {help_text}") + lines.append(f"# TYPE {full_name} {metric_type}") + lines.append(f"{full_name} {value}") + + for name, help_text, hist in histograms: + full_name = f"tabbyapi:{name}" + lines.append(f"# HELP {full_name} {help_text}") + lines.append(f"# TYPE {full_name} histogram") + cumulative = 0 + for upper, count in zip(hist.buckets, hist.counts, strict=True): + cumulative += count + lines.append(f'{full_name}_bucket{{le="{upper}"}} {cumulative}') + lines.append(f'{full_name}_bucket{{le="+Inf"}} {hist.count}') + lines.append(f"{full_name}_sum {hist.sum}") + lines.append(f"{full_name}_count {hist.count}") + + return "\n".join(lines) + "\n" + + +# Create an instance of the global metrics manager +MetricsManager = MetricsManagerClass() diff --git a/config_sample.yml b/config_sample.yml index 7b16b06b..8dea751e 100644 --- a/config_sample.yml +++ b/config_sample.yml @@ -36,6 +36,11 @@ network: # connections from dropping during long prefills. Set to 0 to disable. sse_ping_interval: 15 + # Enable the Prometheus-compatible /metrics endpoint (default: False). + # Exposes aggregate inference stats in the text exposition format. + # NOTE: This endpoint is not protected by API key authentication. + enable_metrics: false + # Options for logging logging: # Enable prompt logging (default: False). diff --git a/endpoints/core/router.py b/endpoints/core/router.py index ffbab464..6bf82c3c 100644 --- a/endpoints/core/router.py +++ b/endpoints/core/router.py @@ -15,6 +15,7 @@ handle_request_error, run_with_request_disconnect, ) +from common.metrics import MetricsManager from common.tabby_config import config from common.templating import PromptTemplate, get_all_templates from common.utils import unwrap @@ -69,6 +70,25 @@ async def healthcheck(response: Response) -> HealthCheckResponse: return HealthCheckResponse(status="healthy" if healthy else "unhealthy", issues=issues) +# Prometheus-compatible metrics endpoint (no auth, opt-in via config) +@router.get("/metrics") +async def metrics(): + """Exposes aggregate inference stats in the Prometheus text format.""" + + if not config.network.enable_metrics: + raise HTTPException( + 404, + "The metrics endpoint is disabled. " + "Set network.enable_metrics to true in config.yml to enable it.", + ) + + return Response( + content=MetricsManager.render_prometheus(), + media_type="text/plain; version=0.0.4", + headers={"Process-Start-Time-Unix": str(int(MetricsManager.process_start_time))}, + ) + + @router.get("/.well-known/serviceinfo") async def service_info(): return JSONResponse( diff --git a/tests/test_metrics_kv_offload.py b/tests/test_metrics_kv_offload.py new file mode 100644 index 00000000..c6abccb5 --- /dev/null +++ b/tests/test_metrics_kv_offload.py @@ -0,0 +1,162 @@ +import types +import unittest + +from common import model as model_module +from common.metrics import MetricsManagerClass + + +PAGE_SIZE = 256 +SLOT_BYTES = 16 * 1024 * 1024 + + +class FakeCPUPageCache: + """Stand-in for exllamav3's CPUPageCache, with the surface the reader uses.""" + + def __init__(self, pages=100, max_slots=400, **overrides): + self.pages = pages + self.max_slots = max_slots + self.slot_size = SLOT_BYTES + self.metrics = { + "pushes": 500, + "dedup_hits": 40, + "restores": 390, + "evictions": 100, + "cold_allocs": 3, + } + self.metrics.update(overrides) + + def __len__(self): + return self.pages + + +def install_container(cpu_cache, max_pages=1000, max_total_tokens=1000 * PAGE_SIZE): + """Point common.model.container at a stand-in generator exposing a CPU page cache.""" + + pagetable = types.SimpleNamespace(max_pages=max_pages, referenced_pages={}) + sync_generator = types.SimpleNamespace( + pagetable=pagetable, + max_total_tokens=max_total_tokens, + cpu_page_cache=cpu_cache, + ) + model_module.container = types.SimpleNamespace( + generator=types.SimpleNamespace(generator=sync_generator) + ) + + +class KVOffloadMetricsTests(unittest.TestCase): + """The /metrics view of the CPU page cache. + + The counters behind these series live in the generator's page cache rather + than in the metrics manager, so the reader has to tolerate a generator that + is missing, has offloading disabled, or reports something unexpected, + without dropping the series or raising through a scrape. + """ + + def setUp(self): + self.metrics = MetricsManagerClass() + self.original_container = model_module.container + + def tearDown(self): + model_module.container = self.original_container + + def test_page_counts_are_reported_as_tokens(self): + install_container(FakeCPUPageCache()) + + live = self.metrics._live_kv_offload() + + self.assertEqual(live["tokens"], 100 * PAGE_SIZE) + self.assertEqual(live["max_tokens"], 400 * PAGE_SIZE) + self.assertAlmostEqual(live["usage_ratio"], 0.25) + + def test_restored_tokens_measure_prefill_avoided(self): + # Every restore reads back one whole page, which is one page of prompt + # that did not have to be prefilled again. + install_container(FakeCPUPageCache()) + + live = self.metrics._live_kv_offload() + + self.assertEqual(live["restored_tokens"], 390 * PAGE_SIZE) + + def test_byte_counters_are_derived_from_whole_slot_transfers(self): + # A transfer in either direction always moves exactly one slot, so the + # byte totals follow from the transfer counts rather than being an + # estimate. + install_container(FakeCPUPageCache()) + + live = self.metrics._live_kv_offload() + + self.assertEqual(live["bytes"], 100 * SLOT_BYTES) + self.assertEqual(live["max_bytes"], 400 * SLOT_BYTES) + self.assertEqual(live["bytes_read"], 390 * SLOT_BYTES) + self.assertEqual(live["bytes_written"], 500 * SLOT_BYTES) + + def test_synchronous_pinning_is_visible(self): + # A store that outruns the background pinning thread pins on the + # generator's own thread at roughly 2.5 GB/s. That has to be observable. + install_container(FakeCPUPageCache(cold_allocs=17)) + + self.assertEqual(self.metrics._live_kv_offload()["cold_allocs"], 17) + + def test_series_are_published_when_offloading_is_disabled(self): + # Series that appear and disappear across scrapes are awkward to alert + # on, so a disabled cache reports zeros rather than nothing. + install_container(None) + + rendered = self.metrics.render_prometheus() + + for name in ( + "tabbyapi:kv_offload_usage_ratio", + "tabbyapi:kv_offload_tokens", + "tabbyapi:kv_offload_max_tokens", + "tabbyapi:kv_offload_bytes", + "tabbyapi:kv_offload_max_bytes", + "tabbyapi:kv_offload_restored_tokens_total", + "tabbyapi:kv_offload_stores_total", + "tabbyapi:kv_offload_deduped_stores_total", + "tabbyapi:kv_offload_evictions_total", + "tabbyapi:kv_offload_cold_allocs_total", + "tabbyapi:kv_offload_read_bytes_total", + "tabbyapi:kv_offload_written_bytes_total", + ): + self.assertIn(f"{name} 0", rendered) + + def test_no_model_loaded_does_not_raise(self): + model_module.container = None + + self.assertEqual(self.metrics._live_kv_offload()["tokens"], 0) + + def test_a_broken_cpu_cache_does_not_break_the_scrape(self): + install_container(types.SimpleNamespace(metrics={})) + + self.assertEqual(self.metrics._live_kv_offload()["tokens"], 0) + self.assertIn("tabbyapi:kv_offload_tokens 0", self.metrics.render_prometheus()) + + def test_no_throughput_gauge_is_published(self): + # A lifetime average of transfer rate divides by wall clock that + # includes every interval with no transfers at all. The bytes counters + # are exposed so a windowed rate can be taken at query time instead. + install_container(FakeCPUPageCache()) + + rendered = self.metrics.render_prometheus() + + for name in ( + "tabbyapi:kv_offload_bytes_seconds", + "tabbyapi:kv_offload_read_bytes_seconds", + "tabbyapi:kv_offload_written_bytes_seconds", + "tabbyapi:kv_offload_hit_ratio", + ): + self.assertNotIn(name, rendered) + + def test_rendered_values_match_the_live_read(self): + install_container(FakeCPUPageCache()) + + rendered = self.metrics.render_prometheus() + + self.assertIn(f"tabbyapi:kv_offload_tokens {100 * PAGE_SIZE}", rendered) + self.assertIn("tabbyapi:kv_offload_usage_ratio 0.25", rendered) + self.assertIn(f"tabbyapi:kv_offload_restored_tokens_total {390 * PAGE_SIZE}", rendered) + self.assertIn("tabbyapi:kv_offload_evictions_total 100", rendered) + + +if __name__ == "__main__": + unittest.main() diff --git a/tests/test_metrics_peak_sizes.py b/tests/test_metrics_peak_sizes.py new file mode 100644 index 00000000..8e1baa80 --- /dev/null +++ b/tests/test_metrics_peak_sizes.py @@ -0,0 +1,67 @@ +import unittest + +from common.metrics import MetricsManagerClass + + +class PeakSizeCounterTests(unittest.TestCase): + def setUp(self): + self.metrics = MetricsManagerClass() + + def record(self, prompt_tokens: int, gen_tokens: int): + self.metrics.record_generation( + prompt_tokens=prompt_tokens, + cached_tokens=0, + gen_tokens=gen_tokens, + prompt_time=1.0, + gen_time=1.0, + ) + + def test_peaks_track_the_largest_request(self): + self.record(1000, 20) + self.record(500, 8000) + self.record(9000, 15) + + self.assertEqual(self.metrics.n_tokens_max, 9000) + self.assertEqual(self.metrics.tokens_predicted_max, 8000) + + rendered = self.metrics.render_prometheus() + self.assertIn("tabbyapi:n_tokens_max 9000", rendered) + self.assertIn("tabbyapi:tokens_predicted_max 8000", rendered) + + def test_peaks_never_fall(self): + self.record(9000, 8000) + for _ in range(50): + self.record(20, 15) + + self.assertEqual(self.metrics.n_tokens_max, 9000) + self.assertEqual(self.metrics.tokens_predicted_max, 8000) + + def test_peak_survives_where_percentiles_cannot(self): + # The reason this counter exists: one large completion among many small + # ones sits above every percentile the histogram can report, so the + # distribution alone cannot show it. + self.record(100, 8000) + for _ in range(344): + self.record(100, 15) + + gen_hist = self.metrics.hist_gen_tokens + self.assertEqual(gen_hist.count, 345) + # The outlier is one sample in 345, i.e. above the 99th percentile. + self.assertLess(gen_hist.count * 0.99, 344) + self.assertEqual(self.metrics.tokens_predicted_max, 8000) + + def test_missing_counts_do_not_break_the_peaks(self): + self.metrics.record_generation( + prompt_tokens=None, + cached_tokens=None, + gen_tokens=None, + prompt_time=None, + gen_time=None, + ) + + self.assertEqual(self.metrics.n_tokens_max, 0) + self.assertEqual(self.metrics.tokens_predicted_max, 0) + + +if __name__ == "__main__": + unittest.main() diff --git a/tests/test_metrics_prefill_series.py b/tests/test_metrics_prefill_series.py new file mode 100644 index 00000000..2a244f09 --- /dev/null +++ b/tests/test_metrics_prefill_series.py @@ -0,0 +1,72 @@ +import unittest + +from common.metrics import MetricsManagerClass + + +class NoPrefillThroughputGaugeTests(unittest.TestCase): + """/metrics must not publish a prefill throughput gauge. + + Prefill is timed as one span per request and that span cannot be split into + time spent on cached versus newly processed tokens, so any lifetime average + of tokens over prefill seconds decays as prefix cache reuse accumulates. + Restricting the sample to requests that computed enough tokens to swamp the + fixed overhead fixes the bias but leaves too few samples to be worth + publishing on a workload with a stable system prefix. The counters are + exposed instead, so a windowed rate can be taken at query time. + """ + + def setUp(self): + self.metrics = MetricsManagerClass() + + def test_no_prefill_throughput_series_is_published(self): + self.metrics.record_generation( + prompt_tokens=4000, + cached_tokens=0, + gen_tokens=10, + prompt_time=2.0, + gen_time=1.0, + ) + + rendered = self.metrics.render_prometheus() + + for name in ( + "tabbyapi:prompt_tokens_seconds", + "tabbyapi:prompt_compute_tokens_seconds", + "tabbyapi:prompt_cold_tokens_total", + "tabbyapi:prompt_cold_seconds_total", + ): + self.assertNotIn(name, rendered) + + def test_the_counters_a_windowed_rate_needs_are_published(self): + self.metrics.record_generation( + prompt_tokens=10000, + cached_tokens=9900, + gen_tokens=10, + prompt_time=0.5, + gen_time=1.0, + ) + + rendered = self.metrics.render_prometheus() + + # Tokens actually processed, the time prefill took, and the cache hits + # that explain the difference. + self.assertIn("tabbyapi:prompt_tokens_total 100", rendered) + self.assertIn("tabbyapi:prompt_seconds_total 0.5", rendered) + self.assertIn("tabbyapi:cached_tokens_total 9900", rendered) + + def test_decode_throughput_gauge_is_kept(self): + # Decode time has no cached-token analogue, so this one measures what + # it claims to and stays. + self.metrics.record_generation( + prompt_tokens=4000, + cached_tokens=0, + gen_tokens=100, + prompt_time=2.0, + gen_time=4.0, + ) + + self.assertIn("tabbyapi:predicted_tokens_seconds 25.0", self.metrics.render_prometheus()) + + +if __name__ == "__main__": + unittest.main() diff --git a/tests/test_metrics_recurrent_cache.py b/tests/test_metrics_recurrent_cache.py new file mode 100644 index 00000000..41452f09 --- /dev/null +++ b/tests/test_metrics_recurrent_cache.py @@ -0,0 +1,174 @@ +import types +import unittest + +from common import model as model_module +from common.metrics import MetricsManagerClass + + +PAGE_SIZE = 256 +CHECKPOINT_BYTES = 155 * 1024**2 + + +class FakeRecurrentCache: + """Stand-in for exllamav3's RecurrentCache, with the surface the reader uses.""" + + def __init__(self, checkpoints=60, max_size=16 * 1024**3, **overrides): + self.checkpoints = checkpoints + self.current_size = checkpoints * CHECKPOINT_BYTES + self.max_size = max_size + self.metrics = { + "stash_evictions": 40, + "stash_evictions_stranded": 25, + "stash_evictions_live_kv": 12, + "stash_pruned": 8, + } + self.metrics.update(overrides) + + def __len__(self): + return self.checkpoints + + +def install_hybrid(recurrent_cache=None, capped_pages=0, stranded_by_kv=0): + pagetable = types.SimpleNamespace( + max_pages=1000, + referenced_pages={}, + metrics={ + "alloc_kv_only_pages": capped_pages, + "stashes_stranded": stranded_by_kv, + }, + ) + sync_generator = types.SimpleNamespace( + pagetable=pagetable, + max_total_tokens=1000 * PAGE_SIZE, + cpu_page_cache=None, + recurrent_cache=recurrent_cache, + ) + model_module.container = types.SimpleNamespace( + generator=types.SimpleNamespace(generator=sync_generator) + ) + + +class RecurrentCacheMetricsTests(unittest.TestCase): + """The recurrent checkpoint cache, and its coupling to the KV cache. + + On a hybrid model, prompt reuse is capped at the longest prefix that has + both valid K/V pages and a matching recurrent checkpoint. An undersized + recurrent cache therefore silently defeats the KV cache, and with offloading + enabled it wastes PCIe bandwidth doing so. + """ + + def setUp(self): + self.metrics = MetricsManagerClass() + self.original_container = model_module.container + + def tearDown(self): + model_module.container = self.original_container + + def test_checkpoint_accounting(self): + install_hybrid(FakeRecurrentCache()) + + live = self.metrics._live_recurrent() + + self.assertEqual(live["checkpoints"], 60) + self.assertEqual(live["checkpoint_bytes"], CHECKPOINT_BYTES) + self.assertEqual(live["max_bytes"], 16 * 1024**3) + self.assertAlmostEqual(live["usage_ratio"], (60 * CHECKPOINT_BYTES) / (16 * 1024**3)) + + def test_an_empty_cache_reports_no_checkpoint_size(self): + # checkpoint_bytes is a mean, so it has no value before the first store. + install_hybrid(FakeRecurrentCache(checkpoints=0)) + + live = self.metrics._live_recurrent() + + self.assertEqual(live["checkpoints"], 0) + self.assertEqual(live["checkpoint_bytes"], 0) + self.assertEqual(live["usage_ratio"], 0.0) + + def test_capped_pages_are_reported_as_tokens(self): + # The waste metric: valid KV that was re-prefilled for lack of recurrent state. + install_hybrid(FakeRecurrentCache(), capped_pages=120) + + self.assertEqual(self.metrics._live_recurrent()["capped_tokens"], 120 * PAGE_SIZE) + + def test_eviction_breakdown_separates_harmless_from_costly(self): + # A stranded checkpoint could never have been resumed, so dropping it is + # free. One dropped while its anchor page was still cached is the drop + # that turns into capped tokens later. + install_hybrid(FakeRecurrentCache(), stranded_by_kv=17) + + live = self.metrics._live_recurrent() + + self.assertEqual(live["evictions"], 40) + self.assertEqual(live["stranded_evictions"], 25) + self.assertEqual(live["live_kv_evictions"], 12) + self.assertEqual(live["pruned"], 8) + # The mirror case, counted by the page table: KV eviction stranding a + # checkpoint rather than the other way round. + self.assertEqual(live["stranded_by_kv"], 17) + + def test_capping_is_reported_without_a_recurrent_cache(self): + # The page table counts the cap even if the cache object is unavailable; + # losing the waste figure would hide the very failure it exists to show. + install_hybrid(None, capped_pages=50) + + live = self.metrics._live_recurrent() + self.assertEqual(live["capped_tokens"], 50 * PAGE_SIZE) + self.assertEqual(live["checkpoints"], 0) + + def test_non_hybrid_model_reports_zeros(self): + install_hybrid(None) + + live = self.metrics._live_recurrent() + self.assertEqual(live["checkpoints"], 0) + self.assertEqual(live["capped_tokens"], 0) + + def test_a_broken_cache_does_not_take_the_cap_with_it(self): + # The cap is counted by the page table, not the cache, and it is the + # figure these series exist for. A cache in an unexpected state must not + # cost it. + install_hybrid(None, capped_pages=50) + model_module.container.generator.generator.recurrent_cache = types.SimpleNamespace( + metrics={} + ) + + live = self.metrics._live_recurrent() + + self.assertEqual(live["capped_tokens"], 50 * PAGE_SIZE) + self.assertEqual(live["checkpoints"], 0) + + def test_series_are_published_and_survive_a_broken_cache(self): + install_hybrid(None) + model_module.container.generator.generator.recurrent_cache = types.SimpleNamespace( + metrics={} + ) + + rendered = self.metrics.render_prometheus() + for name in ( + "tabbyapi:recurrent_cache_usage_ratio", + "tabbyapi:recurrent_checkpoints", + "tabbyapi:recurrent_cache_bytes", + "tabbyapi:recurrent_cache_max_bytes", + "tabbyapi:recurrent_checkpoint_bytes", + "tabbyapi:recurrent_cache_evictions_total", + "tabbyapi:recurrent_cache_stranded_evictions_total", + "tabbyapi:recurrent_cache_live_kv_evictions_total", + "tabbyapi:recurrent_cache_pruned_total", + "tabbyapi:recurrent_stranded_by_kv_total", + "tabbyapi:recurrent_capped_tokens_total", + ): + self.assertIn(f"{name} 0", rendered) + + def test_rendered_values_match_the_live_read(self): + install_hybrid(FakeRecurrentCache(), capped_pages=120, stranded_by_kv=17) + + rendered = self.metrics.render_prometheus() + + self.assertIn("tabbyapi:recurrent_checkpoints 60", rendered) + self.assertIn(f"tabbyapi:recurrent_capped_tokens_total {120 * PAGE_SIZE}", rendered) + self.assertIn("tabbyapi:recurrent_cache_evictions_total 40", rendered) + self.assertIn("tabbyapi:recurrent_cache_live_kv_evictions_total 12", rendered) + self.assertIn("tabbyapi:recurrent_stranded_by_kv_total 17", rendered) + + +if __name__ == "__main__": + unittest.main() diff --git a/tests/test_metrics_token_buckets.py b/tests/test_metrics_token_buckets.py new file mode 100644 index 00000000..a5625bdb --- /dev/null +++ b/tests/test_metrics_token_buckets.py @@ -0,0 +1,90 @@ +import unittest + +from common.metrics import MetricsManagerClass, build_1_2_5_buckets + + +class TokenBucketTests(unittest.TestCase): + """Token histogram boundaries, built from the model's context length. + + A fixed ladder is not merely imprecise, it produces percentiles above any + request the server can accept: histogram_quantile interpolates across the + bucket a sample landed in, so a 300k-wide bucket holding prompts clustered + at its floor reports a p99 near its ceiling. + """ + + def test_ladder_is_a_1_2_5_progression(self): + self.assertEqual(build_1_2_5_buckets(100), [1, 2, 5, 10, 20, 50, 100]) + self.assertEqual(build_1_2_5_buckets(1), [1]) + # 9 is off the ladder, so it becomes the final boundary itself + self.assertEqual(build_1_2_5_buckets(9), [1, 2, 5, 9]) + + def test_limit_is_always_a_boundary(self): + # Stopping at the last mantissa below the limit strands everything + # between there and the real limit in +Inf. At 262144 that is the top + # 24% of the usable range. + buckets = build_1_2_5_buckets(262144) + self.assertEqual(buckets[-1], 262144) + self.assertEqual(buckets[-2], 200000) + + def test_no_bucket_exceeds_the_limit(self): + for limit in (4096, 32768, 131072, 262144, 344064, 1_000_000): + self.assertLessEqual(max(build_1_2_5_buckets(limit)), limit) + self.assertEqual(sorted(set(build_1_2_5_buckets(limit))), build_1_2_5_buckets(limit)) + + def test_configure_resizes_the_histograms(self): + metrics = MetricsManagerClass() + metrics.configure_token_buckets(262144) + + self.assertEqual(metrics.token_buckets[-1], 262144) + self.assertEqual(metrics.hist_prompt_tokens.buckets, metrics.token_buckets) + self.assertEqual(metrics.hist_gen_tokens.buckets, metrics.token_buckets) + + def test_reconfiguring_to_the_same_length_keeps_the_samples(self): + # Rebuilding drops accumulated counts, so an unchanged ladder must not. + metrics = MetricsManagerClass() + metrics.configure_token_buckets(262144) + metrics.record_generation( + prompt_tokens=1000, cached_tokens=0, gen_tokens=10, prompt_time=1.0, gen_time=1.0 + ) + metrics.configure_token_buckets(262144) + + self.assertEqual(metrics.hist_prompt_tokens.count, 1) + + def test_a_different_length_resets_the_histograms(self): + # Counts against a different ladder cannot be carried over. + metrics = MetricsManagerClass() + metrics.record_generation( + prompt_tokens=1000, cached_tokens=0, gen_tokens=10, prompt_time=1.0, gen_time=1.0 + ) + metrics.configure_token_buckets(4096) + + self.assertEqual(metrics.hist_prompt_tokens.count, 0) + + def test_nonsense_lengths_are_ignored(self): + metrics = MetricsManagerClass() + before = list(metrics.token_buckets) + for bad in (0, -1, None): + metrics.configure_token_buckets(bad) + self.assertEqual(metrics.token_buckets, before) + + def test_percentiles_stay_inside_the_context_limit(self): + # The regression this exists for: every reported percentile must be a + # length the server could actually have been asked for. + metrics = MetricsManagerClass() + metrics.configure_token_buckets(262144) + for _ in range(31): + metrics.record_generation( + prompt_tokens=203000, cached_tokens=0, gen_tokens=1, prompt_time=1.0, gen_time=1.0 + ) + + rendered = metrics.render_prometheus() + boundaries = [ + float(line.split('le="')[1].split('"')[0]) + for line in rendered.splitlines() + if line.startswith("tabbyapi:request_prompt_tokens_bucket") and "+Inf" not in line + ] + self.assertLessEqual(max(boundaries), 262144) + + +if __name__ == "__main__": + unittest.main()