Skip to content

Fix HiCache transfer timing and enable_metrics threading#2

Open
ishandhanani wants to merge 21 commits into
hxieustc:add-data-xfer-fine-grain-statisticsfrom
sgl-project:idhanani/fix-26974-transfer-timing
Open

Fix HiCache transfer timing and enable_metrics threading#2
ishandhanani wants to merge 21 commits into
hxieustc:add-data-xfer-fine-grain-statisticsfrom
sgl-project:idhanani/fix-26974-transfer-timing

Conversation

@ishandhanani

@ishandhanani ishandhanani commented Jun 4, 2026

Copy link
Copy Markdown

Follow-up to sgl-project#26974 — re-tested the updated branch on 1x L40S (Qwen3-0.6B, HiCache, write_through, page_size 64, --enable-metrics --log-level debug). All previously-flagged issues are fixed: the decode-side ack consumers work, write-back paths record, the redundant counters are gone, and counters are exact (bytes/token = 114688 = 2 x 28 layers x 8 KV heads x 128 dim x 2B for Qwen3-0.6B). Two remaining issues found, fixed here.

1. Transfer durations were always host wall-clock, never device time

Every event pair fed to elapsed_time() is created without enable_timing=True, so on CUDA elapsed_time() raises

ValueError: Both events must be created with argument 'enable_timing=True'.

and _transfer_elapsed_us silently falls into its except fallback on every transfer. The fallback measures enqueue -> ack-poll latency, not DMA time: an idle onboard of 161 MB logged xfer_us=5751205 (5.75 s, 0.03 GB/s) for a ~7 ms transfer, because the ack sat in ack_load_queue until the next request triggered loading_check. The "prefer device timing" path was dead code.

Fix: create the pairs actually used for timing with enable_timing=True (write start/finish in both controllers, LayerLoadingEvent.start_event + last layer event, which doubles as finish_event). The host fallback remains for backends without elapsed_time().

2. enable_metrics only reached HiRadixCache's controller

decode_kvcache_offload_manager.py and all five HybridCacheController construction sites in hybrid_pool_assembler.py left enable_metrics defaulted to False, so the disagg-decode / hybrid / unified stacks emitted DEBUG logs but never Prometheus, even with --enable-metrics. Threaded enable_metrics + extra_metric_labels through.

Also reverts the unrelated docs_new/index.mdx blog-card rotation (same change already removed from sibling PR sgl-project#26976).

Verification (same box/config)

Check Before fix After fix
Idle onboard duration (161 MB load-back, ack polled seconds later) xfer_us=5751205 (5.75 s, 0.03 GB/s) xfer_us=6781 (6.8 ms, 25.98 GB/s)
Offload per-op duration 6.5-7 ms (wall-clock incl. poll latency) 4.8 ms consistent, ~25.9 GB/s
Cumulative bandwidth under aiperf load (c=16, 256 reqs) offload 1.97 GB/s offload 9.81 GB/s, onboard 24.92 GB/s
DEBUG cumulative vs Prometheus _count/_sum equal equal (542 ev / 2832 blk / 20786970624 B / 2118621 us, both channels)
Unified stack Prometheus (SGLANG_ENABLE_UNIFIED_RADIX_TREE=1 + HiCache) 0 series (collector never created) full series, exact counts (offload 160 blocks, onboard 24 blocks for a 1536-token load-back)
Disagg ack mock tests (test_specv2_kvcache_offloading.py) 13 passed 13 passed
Unified radix cache load/load-back unit tests 58 passed 58 passed
Gating without --enable-metrics (INFO level, load-back traffic) 0 DEBUG lines, 0 series 0 DEBUG lines, 0 series
Block/byte counters exact exact (unchanged)

hi_mamba / SWA hybrid stacks need hybrid models this box cannot run; the threading change there is identical to the unified path verified above.

github-actions Bot and others added 21 commits May 5, 2026 02:43
1. Transfer durations were always host wall-clock, never device time.
   Every event pair fed to elapsed_time() was created without
   enable_timing=True, so on CUDA elapsed_time() raises
   'Both events must be created with enable_timing=True' and
   _transfer_elapsed_us silently falls into its except-fallback. The
   fallback measures enqueue -> ack-poll latency, not DMA time: an idle
   onboard logged xfer_us=5751205 (5.75 s, 0.03 GB/s) for a 161 MB
   transfer that takes ~25 ms, because the ack sat until the next
   request triggered loading_check. Create the pairs used for timing
   (write start/finish, LayerLoadingEvent start + last layer event)
   with enable_timing=True so the device path actually runs.

2. enable_metrics was only threaded into HiRadixCache's controller.
   The decode-side offload manager and all five HybridCacheController
   construction sites in hybrid_pool_assembler.py left it defaulted to
   False, so disagg-decode / hybrid / unified stacks recorded DEBUG
   logs but never Prometheus, even with --enable-metrics. Pass
   enable_metrics and extra_metric_labels through.

3. Drop the unrelated docs_new/index.mdx blog-card rotation (same
   change was already removed from the sibling PR #26976).
@github-actions github-actions Bot added the documentation Improvements or additions to documentation label Jun 4, 2026
@hxieustc hxieustc force-pushed the add-data-xfer-fine-grain-statistics branch 2 times, most recently from 694bd4a to 45ac1b0 Compare June 11, 2026 00:23
@hxieustc hxieustc force-pushed the add-data-xfer-fine-grain-statistics branch 5 times, most recently from aa6964d to 7d2dbed Compare June 12, 2026 22:40
@hxieustc hxieustc force-pushed the add-data-xfer-fine-grain-statistics branch 4 times, most recently from 39dc35a to e90f3e3 Compare June 22, 2026 15:24
@hxieustc hxieustc force-pushed the add-data-xfer-fine-grain-statistics branch 3 times, most recently from be53ff3 to 169c7ad Compare June 26, 2026 21:09
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

documentation Improvements or additions to documentation

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants