[metrics] KV age at hit and eviction, lifetime and reuse count at eviction, for RadixCache and HiRadixCache - #38559
gilfordting wants to merge 7 commits into
Conversation
…adixCache
Add sglang:kv_age_seconds{event,tier,outcome} and its token-weighted
companion sglang:kv_age_tokens_total{...,age_le}: seconds since a radix node
was last matched, observed when it is matched again (event=hit, tier=device
or host) and when it leaves a tier (event=evict; device demoted/dropped,
host dropped). Comparing the hit and evict curves per tier shows whether
a tier evicts content shortly before the traffic reuses it.
Observability only, no eviction behaviour change. CPU unit tests included.
Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
…e eviction hook Record TreeNode.creation_time age and hit_count when a node leaves a tier, under the same tier/outcome labels as kv_age_seconds, so the series cover the quantities proposed in sgl-project#28507 (lifetime, idle, reuses, host eviction) with one label schema. RadixCache._observe_kv_eviction is the single call site helper; HiRadixCache inherits it. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
…ree core UnifiedRadixCache is the default tree cache, and its nodes live in the tree core with logical (counter) timestamps, so the RadixCache hooks never fired there. Add wall-clock twins of last_access_time / creation_time on UnifiedTreeNode, an optional kv_age_observer slot on the tree-core interface (no-op unless installed; the Rust core inherits the default), and emit from the Python core at the match chain refresh and at the four removal sites: device drop, device demote, host leaf eviction, and write-back subtree drop. UnifiedRadixCache installs the observer when metrics are enabled and forwards to the same collector methods RadixCache uses. Verified negatively first: a HiCache server on this branch's previous commit (UnifiedRadixCache, write_through) evicted 367k tokens with no kv_age samples; the CPU test now exercises the unified path too. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Live validation showed two artifacts: cache_unfinished_req re-matches a request right after inserting it, so every prompt registered as a device hit at age ~0, and waiting requests are re-matched every scheduling round, so queue time showed up as reuse age. Gate the hit observation on a per-Req flag (take_kv_age_hit_observation) so only a request's first match_prefix records ages; request-less matches never do. Eviction ages are unaffected. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
…o never-reused reads 2 Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
The hooks run once per node on the scheduler thread. Resolving the label children once per label combination instead of calling labels() on every observation takes the match hook from ~7.3 us to ~3.0 us per node on a CPU micro-benchmark (128-node chain, real prometheus_client series). Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
|
/rerun-group unit/mem_cache |
|
/rerun-group unit/observability |
|
/rerun-test test_metrics.py test_radix_cache_hit.py test_unified_radix_cache_kl_full.py test_hicache_variants.py test_hicache_storage.py |
|
Results for 🚀 🚀 🚀 🚀 ⛔ |
|
Results for 🚀 |
|
Results for 🚀 🚀 🚀 |
|
/tag-and-rerun-ci |
|
/tag-and-rerun-ci |
The memoized label children for the eviction observer were stored in the instance __dict__ under "_kv_eviction_children", the same name as the helper method that fills them. After the first eviction the attribute shadowed the method, so the second eviction on a collector raised "TypeError: 'dict' object is not callable" and took the scheduler down (seen in test_basic_sanity_eagle3 on CI). Initialize the three caches in __init__ under names distinct from the helper methods, and add a regression test that observes repeated evictions and hits on one collector and checks each label child is resolved exactly once. Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
Motivation
Today the radix cache reports how much it evicts (
sglang:evicted_tokens_total) and how long a pass takes (sglang:eviction_duration_seconds), but not how old the evicted content was, how long it had lived, whether it was ever reused, and nothing at all about how old content is when it gets re-used. Those distributions together are what tells an operator whether a cache tier is thrashing:hit_count. Answers "are we evicting content that was never reused" (the LFU question).If the eviction-age curve sits to the right of the hit-age curve, evictions land on content the traffic had finished with. If the two overlap, pages are evicted shortly before they would have been reused, and each of those is a miss paid for with capacity. With HiCache the same comparison per tier separates "L1 is too small for the reuse window" from "L2 is too small for the session length", which pick different fixes (
--hicache-size,--hicache-write-policy,--max-running-requests).Observability only, no behaviour change.
Modifications
Four new series on
RadixCacheMetricsCollector, next to the existing eviction metrics (gated by--enable-metrics). All sharetier(device|host) andoutcomelabels so one PromQL template covers every tier:sglang:kv_age_seconds{event,tier,outcome}(histogram, 1s–2h): seconds since last match, one observation per node.event="hit",outcome="hit": recorded once per request, on its firstmatch_prefix, for every node on the matched path, before the timestamps are refreshed.tier=hostmeans the node was matched via its host copy.event="evict",tier="device",outcome="demoted": device copy freed, host copy kept.event="evict",tier="device",outcome="dropped": data destroyed (write-through unbacked, or write-back drop under host pressure).event="evict",tier="host",outcome="dropped": host tier end of life.sglang:kv_age_tokens_total{event,tier,outcome,age_le}(counter): the same events weighted by tokens, bucketed by the same edges. Node counts over-weight small leaves; this answers "how many tokens did we evict at age > 30 min".sglang:kv_lifetime_seconds{tier,outcome}(histogram):now - creation_timeat removal.sglang:kv_reuses{tier,outcome}(histogram, 0..100):hit_countat removal. One request lifecycle inserts twice (end of prefill, at finish), so a node cached once and never reused reads 2. Reads 0 underwrite_back, which does not maintainhit_count; the docstring says so.Why once per request. The scheduler re-matches waiting requests every round, and
cache_unfinished_reqre-matches right after inserting. Observing every match put every prompt into the ≤1s bucket as a "device hit" (first live run below). A per-Reqflag consumed bytake_kv_age_hit_observation()inbase_prefix_cache.pymakes only the request's first match observe; request-less matches never do. Eviction ages are unaffected.Caches covered.
UnifiedRadixCache(the default tree cache) with the Python tree core, plus the legacyRadixCacheandHiRadixCache. The unified tree core keeps a logical clock inlast_access_time, soUnifiedTreeNodegains wall-clock twins (last_access_wall,creation_wall) refreshed at the same sites; the interface gains an optionalkv_age_observerslot thatUnifiedRadixCachefills when metrics are on, and the Python core emits at the match-chain refresh and at the four removal sites (_delete_unbacked_device_leaf,_demote,_evict_host_leaf, the write-backdrop_subtree_no_hostdescendants). The Rust core inherits the no-op default. The pass counter #28507 proposed is not added:sglang:eviction_duration_seconds_countalready is that number.Files:
python/sglang/srt/observability/metrics_collector.py: buckets,kv_age_bucket(), the four series,observe_kv_age(),observe_kv_eviction().python/sglang/srt/mem_cache/base_prefix_cache.py:take_kv_age_hit_observation().python/sglang/srt/managers/schedule_batch.py:Req.kv_age_hit_observed.python/sglang/srt/mem_cache/unified_cache/unified_tree_core_interface.py,unified_tree_core.py,unified_radix_cache.py: unified path.python/sglang/srt/mem_cache/radix_cache.py,hiradix_cache.py: legacy path (_observe_kv_eviction()helper, match hooks).test/registered/unit/observability/test_kv_age_metrics.py: 9 CPU tests: bucket labels, label routing, eviction fan-out, and end-to-end insert / match / re-match / evict on both a CPURadixCacheand a CPUUnifiedRadixCache, asserting one hit per request and the right token weights.Example queries:
Test process (live, HiCache, UnifiedRadixCache)
Server: this branch on
lmsysorg/sglang:nightly-dev-cu13-20260908, Qwen2.5-3B-Instruct, 1×H100,--enable-metrics --enable-hierarchical-cache --hicache-size 1 --hicache-write-policy write_through --max-total-tokens 16384 --page-size 32(16k-token L1, ~29k-token host pool). Startup log:Tree cache initialized: source=default impl=UnifiedRadixCache … hicache_attached=True. Metrics scraped into Mimir and read back through Grafana; Grafana and the direct/metricsscrape agreed on every count.Workload (~1,070-token prompts): A1 12 cold → A2 same 12 → 60s → B1 10 new → 60s → C1 A again → 30s → B2 240 new → C2 A again.
cached_tokens_total{cache_source="device"}= 12,640 and{cache_source="host"}= 12,640, matching the two hit series exactly. C2 reported 0% cached and added no hit samples (host flushed by B2, visible as the 16 host drops aged 30–60s).hicache_dropped_tokens_totalstayed 0.Negative check first. The same server on the branch before the unified-core commit evicted 367k tokens and demoted 358k with zero
kv_agesamples, which is how the default-cache gap was found. A run before the once-per-request gate recorded 386,784 device-hit tokens, equal to the total prompt tokens of all phases including cold ones, from the post-insert re-match.Relation to existing work
[metrics] Add cache eviction lifetime/frequency metrics (L1 + L2), open since June, currently conflicting) proposes eviction age since creation, idle since last access, reuse count, L2 eviction age and a pass counter, as separate metric names per tier, forRadixCache/HiRadixCacheonly. This PR covers the same quantities under one label schema, also on the defaultUnifiedRadixCache, and adds the hit-age series, the demoted/dropped split, and token weighting. Happy to coordinate with its author on which lands, or to fold the hit-age half into [metrics] Add cache eviction lifetime/frequency metrics (L1 + L2) #28507 if maintainers prefer its metric names.update_eviction_metrics. Review on [metrics] Add cache eviction lifetime/frequency metrics (L1 + L2) #28507 asked for its eviction-age hook to move intoupdate_eviction_metrics. That hook runs once per eviction pass with two scalars (tokens freed, pass duration). Age, lifetime and reuse count are per node, and one pass removes anywhere from one to hundreds of nodes with different ages, so recording them there would need the pass to collect a list of per-node samples and hand it up, which is the same amount of plumbing with an extra allocation per pass. This PR instead observes at the four node-removal sites (_delete_unbacked_device_leaf,_demote,_evict_host_leaf, the write-back subtree drop) through one helper, and leavesupdate_eviction_metricsuntouched so the existing pass-level metrics are unaffected. The same helper shape is used in the legacy caches (RadixCache._observe_kv_eviction).evicted_tokens_totalinto backuped vs regular; theoutcomelabel here carries the same distinction on the age series. No code conflict.Cost
Measured with a CPU micro-benchmark (page size 1, one chain of K nodes x 64 tokens, real
prometheus_clientseries, medians of 300 matches / 20 evictions; script in the PR discussion on request):UnifiedRadixCache.match_prefixUnifiedRadixCache.match_prefixRadixCache.match_prefixevict(both caches)The match hook fires once per request (first
match_prefixonly) for each node on the matched path, so a 100k-token prompt matching 30 radix nodes adds ~90 µs to that request's scheduling, once. Label children are resolved once per label combination and cached on the collector (_kv_age_childetc.); before that the same hook cost ~7.3 µs per node, almost all of it inlabels(). Eviction adds three histogram observations and one counter increment per removed node; the eviction pass is dominated by freeing KV slots and the delta did not separate from noise at these sizes.Limitations
SWARadixCache,MambaRadixCache,HiMambaRadixCache,RadixCacheCpp,LMCRadixCache, and the Rust tree core (SGLANG_UNIFIED_RADIX_TREE_CORE_BACKEND=rust) are not instrumented; thecache_typelabel makes the gap visible.--*-bucketsserver arg viagenerate_buckets; can follow if wanted.kv_reusesreads 0 underwrite_back.Accuracy Tests
N/A, no model output change.
Speed Tests and Profiling
Not benchmarked; see Cost. No visible change in step time on the validation server at this scale.
Checklist
ruff format,ruff check --select=F401,F821,UP037,isortat the pinned versions).test/registered/unit/observability/test_kv_age_metrics.py, CPU, 9 tests).🤖 Generated with Claude Code
CI States
Latest PR Test (Base): 🚫 Run #34326152544
Latest PR Test (Extra): ❌ Run #34326152466
Latest PR Test (AMD ROCm 10): ❌ Run #34326152766