Skip to content

Add KV cache operation observability - #410

Merged
RixinLiu merged 5 commits into
ovg-project:mainfrom
shipiyouniao:feature/operational-observability
Oct 8, 2026
Merged

RixinLiu merged 5 commits into
ovg-project:mainfrom
shipiyouniao:feature/operational-observability

Conversation

@shipiyouniao

@shipiyouniao shipiyouniao commented Jul 24, 2026 •

Copy link
Copy Markdown
Collaborator

Operation Accounting

Related to #375. Add exporter-neutral counters for manager operations and bounded error metadata, exposed through the existing vLLM and SGLang snapshot interfaces. Metrics backends remain outside the allocator.

Pool occupancy alone cannot distinguish successful allocation, recoverable capacity rejection, and a broken mapping transaction. A consumer attaching after an error also needs cumulative event counts, not a history entry created only when someone requests a snapshot.

Execution Path

The manager records requests before allocation, outcomes after allocation, and completed progress during free. The allocation decision and native mapping protocol are unchanged. State-consistency exceptions from #418 still propagate; they are not turned into ordinary capacity rejection.

The original accounting flow is shown in KVCacheManager at 23fbfb4. The r3 implementation inlines normal-path increments while preserving these outcomes:

indices = self._alloc_impl(need_size, _skip_wait=_skip_wait)
if indices is None:
    self._increment_operation_counter("allocation_failures_total")
    self._increment_operation_counter("capacity_exhausted_total")
else:
    self._increment_operation_counter("allocation_successes_total")
    self._increment_operation_counter("allocated_blocks_total", len(indices))

manager_page_allocations_total and manager_page_releases_total count manager-page handoffs, including reserved-page reuse. They do not claim to count CUDA physical map/unmap operations: native preallocation, trimming and resizing have a different accounting boundary. Caller-free block counts retain completed progress if a later page release fails. Internal allocation rollback does not inflate those counts. Rejected deferred resize records a resize error and does not count as completed resize. Deferred page releases count only after successful fenced release; clear counts each retired page once.

Before:

sequenceDiagram
    participant E as Engine
    participant M as KV manager
    participant A as Native allocator
    participant C as Metrics consumer
    E->>M: Allocate / free
    M->>A: Existing page operation
    A-->>M: Result or exception
    M-->>E: Existing result
    C->>M: Pool snapshot
    M-->>C: Current occupancy
Loading

After:

sequenceDiagram
    participant E as Engine
    participant M as KV manager
    participant A as Native allocator
    participant C as Metrics consumer
    E->>M: Allocate / free
    M->>M: Record request
    M->>A: Unchanged page operation
    A-->>M: Result or exception
    M->>M: Record outcome and completed progress
    M-->>E: Preserve result / exception
    C->>M: Operation snapshot
    M-->>C: Cumulative counters and bounded last-error metadata
Loading

Concurrency and Cost

Normal operation counters follow the allocator's existing writer contract: synchronous scheduling has one serialized logical writer, while asynchronous writers use the existing allocator RLock. Initialization hands page accounting over through its readiness event. Native background mapping callbacks do not update these Python operation counters. Compound Python counter increments are not assumed atomic because of the GIL.

Only shared error publication retains a separate cold-path RLock. Error code/time are published together in an immutable record; initialization errors do not suppress a distinct foreground free error. Operation snapshots copy the counters without the allocator or statistics lock and format the copy afterward. Individual counters remain cumulative; polling can observe in-flight requests and skew across fields. Coherent occupancy snapshots and native mapping/transaction locks retain their existing synchronization. This reasoning targets ordinary GIL-enabled CPython; free-threaded execution is not validated.

Counting still adds work without a collector: dictionary updates, result/error bookkeeping and operation wrappers. The measurements below quantify this cost; removing the hot statistics lock does not make observability free.

The capability API added by #474 now advertises operation counters and lists the actual cumulative counter names. The list is derived from the snapshot schema, excludes last-error metadata, and leaves the upstream backend and integration capability fields intact.

Validation

Current update: r3 and test-conflict integration

Performance commit: 9c5e8c7. Final integration head: eef9441, including main 06f04e02c3ac83c85e611101c90ac21b95e12f27.

The r3 source passed 1178 CPU tests on Python 3.12, pre-commit/C++ CPU checks, MyPy targets 3.10–3.13, and 61 native T4 tests with one pre-existing skipped kvctl resize test. Its dedicated local Codex review reported no actionable findings. The final integration resolved only a conflict in tests/test_alloc_rollback.py, preserving every r3 test and the upstream page-eviction regressions; no production conflict was resolved manually. On eef9441, the complete affected test file passed 69 tests, with Ruff, isort, whitespace and diff checks passing. The full suite and native benchmarks were not rerun locally after that integration. Subsequent GitHub Actions on this exact head passed all four Python CPU jobs (CPU Tests) and all four MyPy jobs plus pre-commit/C++ CPU checks (Pre-commit CI).

Current allocator cost reference

The benchmarked r3 working-tree files and exact patch were verified against performance commit 9c5e8c7 before publication (patch SHA256 f71e1474c2ef7492ec20812003bad0b957c159b35d3179e61ab7065a5bc16e0f). These are measurements of r3 before the final upstream integration, not a new benchmark of eef9441.

One Tesla T4, CPython 3.12.13, PyTorch 2.13.0+cu129, the same existing native extension and runtime for all versions. One native VMM-backed pool, 2 MiB pages, non-contiguous layout, preallocation disabled and zero reserved pages. An anchor block keeps a page mapped; each timed iteration allocates and frees one other block. The unit below is microseconds per alloc/free pair, not model tokens or requests.

The no-collector comparison uses base 84b95c9e227c66f062e80c94e8a09aae8a4abe75, previous PR head 23fbfb4ceab2f1e786492b67129c7b7c621c8ac6, and r3. All six version-order permutations were run, with synchronous/asynchronous mode order alternated: 36 processes total, six processes per version/mode. Each process discards one 20,000-pair warmup and measures seven 20,000-pair rounds, giving 42 round averages per version/mode. P10–P90 below describes those round averages, not per-operation tail latency.

Mode Base median (P10–P90), us r3 median (P10–P90), us Added us Added cost
Synchronous 10.063 (9.964–10.210) 11.274 (11.085–11.705) 1.212 +12.04%
Asynchronous 10.164 (10.058–10.385) 11.422 (11.174–11.783) 1.258 +12.38%

The previous PR head measured 14.227 us synchronous and 14.431 us asynchronous in that same batch; r3 reduces those times by 20.75% and 20.85%. The remaining approximately 12% is an allocator microbenchmark cost, not a serving-throughput estimate.

Collector comparison

The base has no operation-snapshot API, so this comparison includes only the previous PR head and r3. A separate thread calls operation_snapshot_dict(), then waits 10 ms; actual observed rates were approximately 64–66 Hz under GIL/scheduling contention. Four balanced process repetitions per version/mode give 16 processes. Each discards one 20,000-pair warmup and measures five rounds of 20,000 pairs.

Mode Previous PR median, us/pair r3 median, us/pair Reduction
Synchronous 14.159 11.005 22.28%
Asynchronous 14.595 11.274 22.75%

Asynchronous snapshot-call P99 was 4.145 ms for the previous PR and 60.9 us for r3; maxima were 10.57 ms and 79.7 us. Separate, instrumented 50,000-pair diagnostics per process observed the previous PR's collector waiting on the allocator lock, while r3's collector never acquired that lock or the error lock. Those probes perturb timing and are not production tail-latency guarantees. Both versions still showed about 5.2 ms of sampling wake-up lateness, which includes OS/GIL scheduling rather than isolated mutex wait. The collector and no-collector batches are independent; their absolute differences are not used to attribute collector overhead.

Every benchmark process verified CUDA fill/readback, exact final block accounting and operation totals. Collector runs also checked monotonic samples and zero snapshot exceptions. These checks do not establish serving performance, multi-GPU behavior or free-threaded Python correctness; the historical serving data below remains tied to its older revisions.

Historical validation on 23fbfb4

Previous head: 23fbfb4ceab2f1e786492b67129c7b7c621c8ac6, incorporating main 84b95c9e227c66f062e80c94e8a09aae8a4abe75. The update preserves #478 lifecycle/fatal-state reporting alongside operation counters, #456 capacity-cache invalidation, and completed-only deferred-release accounting. Added regressions check that fatal allocation and deferred-release errors agree with wait_ready() and are not counted as capacity misses.

Validation on this exact head, on T4:

Check Result
CPU tests, Python 3.10–3.13 1155 passed per version
Four-version MyPy, pre-commit and C++ CPU tests Passed
Native CUDA/VMM, lifecycle and layout regressions 78 passed
vLLM 0.29 / 0.30 integration contracts 118 passed per version
Deferred release/reuse/clear, both layouts; native import isolation Passed; 20 import-isolation tests passed
vLLM 0.30 async MRV2 hybrid inference, dummy weights 12/12 requests; 192 output tokens
Dedicated Codex review No actionable findings

At that previous head, a T4 allocation/free microbenchmark (no scraping, 10,000 pairs per round, one warmup and five measured rounds per process, baseline/candidate/candidate/baseline) measured approximately 10.2 → 14.6 μs per pair, about 4.4 μs additional cost. CUDA readback passed after every run. This is hot-loop overhead, not a serving-throughput comparison; the older serving measurements below are still historical.

The earlier two-engine vLLM serving regression on 740c74d completed 64/64 requests and 8192/8192 output tokens with 1241 samples and zero collection errors. That is retained evidence from the previous head, not a rerun of vLLM serving on this rebase.

Historical Allocation Microbenchmark

The performance measurements in this and the following section were collected on the pre-rebase candidate 5a4b3ae99f51365a85d5cc0ae906c6e970509859 against 944ed53399f989afc1317734e689c406cde2b097. Those measurements predate #456's physical-capacity TTL cache. The current rebase preserves that upstream optimization, so the old timings must not be presented as measurements of the current head. No new matched performance comparison is claimed here.

Real VMM-backed managers on one T4, preallocation and reserved pages disabled. An anchor block keeps the current page mapped, so each timed iteration allocates and frees one other block without paying for a new CUDA mapping. There are 50,000 iterations per round, one discarded warmup and five measured rounds; runs are ordered baseline/candidate/candidate/baseline. The table reports the median of ten measured round averages per configuration. Every run ends with CUDA readback verification.

Pools Snapshot rate Baseline alloc/free pair This PR
1 None 21.469 us 26.729 us
1 1 Hz 21.704 us 26.610 us
1 10 Hz 21.846 us 26.725 us
8 None 21.592 us 26.422 us
8 1 Hz 21.799 us 27.081 us
8 10 Hz 22.156 us 26.485 us

The counters add about 5 us per alloc/free pair in this tight loop, roughly 22-25% without sampling. This is a measurable hot-path cost, not a claim of free observability. Periodic sampling does not materially amplify it in these tests. It also does not follow that model serving loses the same percentage: the serving comparison below measures that separately.

Historical Serving Comparison

One T4 runs two independent TP1 vLLM 0.28.0 V1 engines, Qwen2.5-0.5B-Instruct FP16, Triton attention, CUDA graph capture size 64, synchronous scheduling and prefix caching. Both revisions use 2 MiB pages, preallocation off, zero reserved pages, a 4096-token prefix cap, KVCACHED_GPU_UTILIZATION=0.9, and the same explicit 10 GiB logical KV capacity per engine. Engine limits are 8192 model tokens, 2048 batched tokens and 64 sequences. MPS is not enabled.

Each engine uses three warmups, fixed random-dataset seeds, temperature 0 and ignore_eos:

  • Ordinary load: I256/O128, N32/C4, 4 requests/s.
  • Memory pressure: I4096/O128, N64/C32, unlimited arrival rate. A separate fixed CUDA allocation leaves about 3.1 GiB device free before the workload on both revisions.

Runs are baseline/candidate/candidate/baseline, with 768/768 successful benchmark requests and all expected output tokens produced. Health and normal chat probes pass before and after each run. Combined throughput below is total output tokens divided by the longer of the two engines' timed benchmark intervals, averaged over the two runs of each revision.

Workload Baseline combined tok/s This PR combined tok/s Change Baseline / PR mean TPOT
Ordinary 537.04 534.71 -0.43% 13.760 / 13.814 ms
Memory pressure 80.883 80.508 -0.46% 364.643 / 367.866 ms

These runs show a small end-to-end difference, not the roughly 25% difference in the isolated tight loop. They do not establish zero overhead or statistical equivalence. Sampling runs are reported below separately.

Two further runs sampled live pool and operation snapshots at 1 Hz and 10 Hz. These are single-run sampling checks, not another repeated A/B experiment:

This PR sampling rate Ordinary combined tok/s Pressure combined tok/s Samples / errors across both engines
None, two-run mean 534.71 80.508 Not sampled
1 Hz 537.43 80.850 500 / 0
10 Hz 534.00 80.764 4974 / 0

Including those checks, all 1152 benchmark requests produced the full 147456 output tokens. No CUDA error, OOM, illegal memory access or EngineCore failure was found in the serving logs. Services were stopped by the test harness after their recovery probes; the T4 returned to idle.

The T4 tests cover single-GPU accounting, readback, error propagation and sampling. They do not establish multi-GPU transaction safety or large-model TP/MPS performance.

Copilot AI review requested due to automatic review settings July 24, 2026 05:12
@gemini-code-assist

Copy link
Copy Markdown
Contributor

Caution

The consumer version of Gemini Code Assist on GitHub has been sunset. All code review activity has officially ceased.

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Adds a read-only observability surface for kvcached KV cache pools, including per-manager operation counters and integration-facing snapshot helpers so external collectors can retrieve stable, structured state without relying on engine internals.

Changes:

  • Introduces kvcached.observability dataclasses + registry helpers for pool/runtime snapshots and operation counter snapshots.
  • Adds monotonic operation counters + error metadata to KVCacheManager, and exposes snapshot/snapshot_dict helpers.
  • Wires vLLM/SGLang integration interfaces to register pools, clear registration on shutdown, and expose snapshot forwarding; labels SGLang pool types (mha/mla/mamba).

Reviewed changes

Copilot reviewed 6 out of 6 changed files in this pull request and generated 2 comments.

Show a summary per file
File Description
tests/test_observability.py Adds unit tests covering operation counters, snapshot serialization, weakref registry behavior, and integration forwarding.
kvcached/observability.py Implements snapshot dataclasses, capability discovery, and a weakref-based registry for live pools.
kvcached/kv_cache_manager.py Adds operation counter tracking, error recording, and snapshot helper methods on the manager.
kvcached/integration/vllm/interfaces.py Registers vLLM managers in the pool registry and exposes runtime/pool snapshot helpers.
kvcached/integration/sglang/interfaces.py Registers SGLang managers in the pool registry and exposes runtime/pool snapshot helpers.
kvcached/integration/sglang/patches.py Passes stable pool_name labels when creating managers so collectors can distinguish pool types.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread kvcached/observability.py Resolved
Comment thread kvcached/kv_cache_manager.py Resolved
@shipiyouniao
shipiyouniao force-pushed the feature/operational-observability branch 3 times, most recently from e9d92a5 to e6a7c54 Compare August 1, 2026 02:31
@shipiyouniao
shipiyouniao force-pushed the feature/operational-observability branch from e6a7c54 to 1166d4d Compare August 3, 2026 17:14
@shipiyouniao
shipiyouniao force-pushed the feature/operational-observability branch 2 times, most recently from 20ca3dc to 6ce65a1 Compare August 17, 2026 06:39
@shipiyouniao
shipiyouniao force-pushed the feature/operational-observability branch from 6ce65a1 to ce54ef8 Compare August 25, 2026 04:42
Comment thread kvcached/kv_cache_manager.py Resolved
@shipiyouniao

Copy link
Copy Markdown
Collaborator Author

Rebased on #474 and connected the capability flag/name list to the actual operation-counter schema. Allocation behavior and the native mapping protocol are unchanged.

I also filled the performance-evidence gap. The tight VMM-backed alloc/free loop has a real cost: about 5 us per pair. The matched two-engine T4 serving runs were -0.43% at ordinary load and -0.46% under memory pressure; 1 Hz and 10 Hz snapshot checks had no collection errors. That supports a small serving difference in this setup, not zero overhead or a multi-GPU performance guarantee.

The description now separates the measured pre-rebase SHA from the current SHA. Full CI, native GPU fault/accounting tests and a bounded vLLM serving/sampling regression were rerun after the rebase. No need to infer performance from unit tests alone.

@shipiyouniao

Copy link
Copy Markdown
Collaborator Author

Rebased onto current main, including #456 and #480. The physical-capacity cache invalidations are preserved; a regression test also checks cache invalidation when page initialization fails after a successful allocation.

On 8fb5d2c, full pre-commit, C++ CPU tests, all five Python CPU/MyPy jobs, and 88 native T4 tests passed. The live allocation-failure, unknown-peer-result and reserved-page-reuse checks passed too. The description separates these new checks from the older performance measurements, which have not been rerun against the new base.

@RixinLiu, could you take another look when you have time? #421 is rebased on this commit and still needs this one to land first.

@shipiyouniao
shipiyouniao force-pushed the feature/operational-observability branch from 8fb5d2c to 0ee71ec Compare October 4, 2026 09:17
@RixinLiu
RixinLiu self-requested a review October 6, 2026 14:15
shipiyouniao and others added 3 commits October 7, 2026 03:15
- Use existing allocator writer ownership for cumulative counters.
- Serialize error publication and allow approximate operation snapshots.
- Retain operation-accounting and page-eviction regression coverage.
ovg-project#507 added pack_pages to _alloc() for alloc_packed(). Pass it through to
_alloc_impl(), so that packed allocations are counted like alloc().
@RixinLiu
RixinLiu merged commit 65bbe66 into ovg-project:main Oct 8, 2026
9 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants