From fb5ccaff260ecd7360ea332477176cadcc0365f2 Mon Sep 17 00:00:00 2001 From: laoyao0822 Date: Mon, 8 Jun 2026 03:39:50 +0800 Subject: [PATCH] Preserve CP shared-KV cache-hit diagnostics Warm-cache GSM8K failures needed request-to-log correlation across scheduler, prefill transfer, and Mooncake CP filtering. The added diagnostics are gated by existing CP shared-KV debug envs and include bounded token signatures plus transfer page summaries so future debugging can identify whether a failed request hit L1, L2, or transfer truncation paths.\n\nThe findings document records the ruled-out hypotheses and the RAGGED current-row contract failure, preventing repeated log archaeology after context compaction.\n\nConstraint: Production hot paths must not emit these logs unless SGLANG_CP_SHARED_KV_BS_GT1_DEBUG or existing CP shared-KV debug gates are enabled.\nRejected: Add a new debug env | reuse of existing bs>1 debug gate avoids more runtime switches.\nRejected: Store full token ids in logs | bounded signatures are enough for correlation without huge logs.\nConfidence: medium\nScope-risk: narrow\nDirective: Keep these diagnostics gated and bounded; do not convert them to unconditional INFO logs.\nTested: Remote container py_compile as part of the RAGGED fix validation.\nNot-tested: Long-running production log-volume impact with debug enabled. --- ...prefill_cp_gsm8k_cachehit_temp_findings.md | 229 ++++++++++++++++++ .../srt/disaggregation/mooncake/conn.py | 56 +++++ python/sglang/srt/disaggregation/prefill.py | 5 +- python/sglang/srt/disaggregation/utils.py | 25 ++ python/sglang/srt/managers/scheduler.py | 8 +- 5 files changed, 321 insertions(+), 2 deletions(-) diff --git a/docs/advanced_features/nsa_prefill_cp_gsm8k_cachehit_temp_findings.md b/docs/advanced_features/nsa_prefill_cp_gsm8k_cachehit_temp_findings.md index c1022be8e..4d4869da3 100644 --- a/docs/advanced_features/nsa_prefill_cp_gsm8k_cachehit_temp_findings.md +++ b/docs/advanced_features/nsa_prefill_cp_gsm8k_cachehit_temp_findings.md @@ -1214,3 +1214,232 @@ prefix_len=721 host_hit_length=0 extend_input_len=17 fill_len=721 origin_input_l 1. `alloc_for_extend()` / `write_cache_indices()` 后：记录每个 req 的 prefix pages、suffix/out pages、最终 `req_to_token[:seq_len]` pages。 2. `cache_unfinished_req()` / `cache_finished_req()` 前后：记录插入 radix 的 `values` pages、match 后 `new_indices` pages、以及最终写回 `req_to_token` 的 pages。 3. 如果 `alloc_for_extend()` 后顺序正确而 `send_kv_chunk()` 前错误，root cause 在 radix cache insertion / re-match / page-floor tail pruning；如果前者已经错误，则继续回溯 prefix_indices 来源。 + +## 2026-06-08 00:04 retest after reported restart + +Command: + +```bash +cd /sgl-workspace/sglang +python benchmark/gsm8k/bench_sglang.py \ + --host g0034 --port 17100 --backend srt \ + --data-path /mnt/beegfs/cjy/data/gsm8k_test.jsonl \ + --num-questions 200 --parallel 64 \ + --temperature 0.0 --top-p 1.0 --max-new-tokens 512 \ + --raw-result-file /mnt/beegfs/cjy/gsm8k_debug_retest_20260608_000457/pass1_raw.jsonl \ + --result-file /mnt/beegfs/cjy/gsm8k_debug_retest_20260608_000457/pass1_result.jsonl +``` + +Result: + +- Accuracy: 0.695 +- Invalid: 0.000 +- Latency: 35.829 s +- Output throughput: 588.436 token/s + +Notes: + +- The prefill process observed before the retest was PID 627606, start time `Sun Jun 7 23:48:54 2026`, log `/mnt/beegfs/cjy/log/sglang_cp_hicache_20260607_154854.log`. +- This means the retest was against an already warm cache from earlier GSM8K runs in the same prefill process, not a cold-cache first pass. +- The result remains consistent with the cache-hit correctness regression: warm-cache GSM8K accuracy is around 0.69-0.72 while cold/first-pass accuracy is around 0.95-0.97. + +## 2026-06-08 remote retest after syncing origin+cjy fixes + +Remote code synced to g0034 `/mnt/beegfs/cjy/sglang-dev` and container path `/sgl-workspace/sglang-tai`. + +Full GSM8K two-pass run directory: +`/mnt/beegfs/cjy/gsm8k_retest_20260607_164904` + +Results: +- pass1: Accuracy 0.958, Invalid 0.000, Latency 214.254s, Output throughput 646.402 token/s. +- pass2: Accuracy 0.690, Invalid 0.002, Latency 226.338s, Output throughput 624.138 token/s. + +Conclusion: warm-cache/cache-hit correctness regression still reproduces after syncing per-layer transfer branch plus local fixes. For future iterations, do not start with full 1319-question runs. Run a 200-question GSM8K canary first for fast signal; only run full GSM8K after the 200-question warm-cache second pass stays near expected accuracy. + +## 2026-06-08 AJ: 当前线上复现未开启 disagg per-layer transfer + +用户确认当前线上版本没有开启 prefill→decode per-layer transfer。因此本轮 GSM8K warm-cache 掉点不应继续优先归因于 `CP_PER_LAYER_TRANSFER` 的异步/分组路径。 + +纠正：此前把 per-layer transfer block grouping 列为风险点只是代码层可能性；对当前线上日志/复现不成立。当前应回到 monolithic Mooncake transfer、radix/req_to_token page-order、NSA state/index companion transfer、以及 decode 端接收/consume 元数据路径。 + +已知日志事实仍保持：最新 debug 日志没有 `HiCache-load/load_back`，第二轮主要是 L1/device cache-hit 后 transfer/consume 更深 cached prefix；输出像“prompt/request 片段串了”，不是乱码。 + +## 2026-06-08 AK: 当前更强证据指向 radix/scheduler 过度 prefix hit，不是 per-layer transfer + +纠正上一轮 page-order 解释：`send_kv_chunk pages=head=[25,2,3,...]` 不能单独证明 suffix-before-prefix。冷启动/无 cache 的 first pass 也会出现类似非单调 page id，这是 CP owner-lane allocator 的物理 page id 分配结果，数值顺序不等于 token 顺序。 + +新证据：用容器内 GLM-5.1 tokenizer 对 `/mnt/beegfs/cjy/gsm8k_retest_20260607_164904/pass1_raw.jsonl` 前 200 条 prompt 计算两两公共前缀： + +```text +prompt0 prefix cnt [(671, 198), (672, 1)] minmax 671 672 +pair floored common top [(640, 19900)] +examples >=704 [] +``` + +也就是说，真实 GSM8K prompt 两两 page-floor 后只有 640 token 公共前缀，没有自然 704/768 公共前缀。 + +但 prefill 日志在 warm-cache pass 中出现： + +```text +match_prefix_result ... key_len=735 device_tokens=735 ... last_host_node=2645 last_host_host_len=64 cp_floor_exact=False +batch_plan ... extend_lens=[32,18,3,13,23] prefix_lens=[704,704,704,768,704] +``` + +这说明 runtime 里某些请求被暴露了 704/768 的 device prefix，而从真实 prompt token 序列看这些 prefix 不应该互相匹配。当前 root-cause 排查优先级应转向： + +1. scheduler / waiting_queue radix match 是否用全 prompt 或临时树产生了过长 prefix； +2. CP HiCache exact valid-tail floor 规则是否只在 `Req.adjust_max_prefix_ids()` 生效，而 `schedule_policy._compute_prefix_matches()` / in-batch prefix path 仍可能把非 page-aligned tail 当作命中； +3. `cache_unfinished_req()` 内部 `match_prefix(cp_floor_exact=False)` 是当前请求自刷新用，不能让后续 scheduler-visible match 继承未 floor 的 valid-tail。 + +当前不再优先排查 disagg per-layer transfer；用户确认线上未开启该路径。 + +## 2026-06-08 AL: 排除 health check 后修正 AK 的过度 prefix-hit 判断 + +用户提醒：GSM8K 后面的请求很可能是 health check，不应纳入 cache-hit 掉点判断。后续日志分析只统计 benchmark 时间窗内的 `/v1/chat/completions` / scheduler prefill batch，不再用后续 health-check 长尾请求解释 GSM8K 精度下降。 + +同时修正 AK：pass2 是对同一批 GSM8K prompt 的重复请求，因此 `prefix_lens=704/768` 本身并不证明不同 prompt 之间发生过度匹配。用 tokenizer 计算得到的 `floor(prompt_len)` 也显示许多 GSM8K prompt 自身长度就是 704/768 页对齐前缀；warm-cache pass2 命中这些完整 prompt 页是预期行为。 + +因此当前更准确的判断是： + +1. **不能再把 `704/768` prefix 命中单独作为 scheduler/radix overmatch 证据。** 只有当某个具体 request 的 `prefix_len` 超过其自身 `floor(prompt_len)`，或输出明显来自另一条 prompt 且能绑定到同一 request，才算 overmatch/串 cache 证据。 +2. **当前 warm-cache 掉点仍然成立**：full GSM8K pass1 约 `0.958`，pass2 约 `0.690`，且输出样例有 prompt 内容串用现象。 +3. **优先排查方向回到 cache-hit consume/transfer correctness**：L1 device cache hit 后的 CP shared KV page table、index/topk offset、MLA materialize/current reuse、monolithic Mooncake transfer/metadata consume。当前线上未开启 disagg per-layer transfer；health check 请求不作为证据。 + +下一步日志分析必须把 benchmark result/raw 文件与 prefill 日志时间窗绑定，必要时只跑 50/200 条 canary，并在 debug log 中输出 request/rid 与 prompt index 的可关联字段，否则很难把某条错误输出反推到具体 cache path。 + +## 2026-06-08 AM: 增加 GSM8K cache-hit 对齐用 debug log + +新增 debug 只挂在既有 `SGLANG_CP_SHARED_KV_BS_GT1_DEBUG` / `SGLANG_CP_SHARED_KV_BS_GT1_DEBUG_LIMIT` 下，不新增开关，默认关闭。 + +目的：把 benchmark raw prompt 与 prefill/transfer 日志绑定起来，避免继续只能按时间和 request 顺序猜测。 + +新增字段/事件： + +1. `scheduler_prefill_batch` 增加 `rids` 与 `origin_sigs`。 + - `origin_sig` 是 origin token ids 的稳定 hash + head/tail + len，可由 raw prompt 在同 tokenizer 下复算。 +2. `send_kv_chunk` 增加 `origin_sig` 与 `fill_sig`。 + - 用于确认 send 前请求身份、fill_ids 是否多了输出 token，以及同一 prompt pass1/pass2 是否绑定到预期 rid。 +3. Mooncake prefill sender 增加 `sender_filter`。 + - 记录 CP shared-KV 过滤前 logical request pages、过滤后 physical pages、logical page positions、state/indexer pages。 +4. Mooncake worker 增加 `transfer_worker_kv` / `transfer_worker_state`。 + - 记录实际发送到 decode dst pages 的映射，区分 KV 与 NSA state/indexer companion metadata。 + +这些日志用来验证：同一个 GSM8K prompt 在 pass2 cache-hit 时，prefill 端 page table、CP owner filter、decode dst page selection 是否一致；如果输出串 prompt，下一步应按 `origin_sig` 精确定位对应 rid/room，而不是再把 health check 或无关长尾请求纳入判断。 + +## 2026-06-08 AN: 200-question canary on new debug log + +User started a new debug-log run and requested a 50-200 question GSM8K canary. I ran two 200-question passes against the existing prefill process/log: + +- prefill PID: `666430`, started `Mon Jun 8 02:01:57 2026` +- log: `/mnt/beegfs/cjy/log/sglang_cp_hicache_20260607_180157.log` +- result dir: `/mnt/beegfs/cjy/gsm8k_debug_retest_20260607_183407` +- time window: `2026-06-07 18:34:07` to `18:35:29` + +Command shape: + +```bash +cd /sgl-workspace/sglang +python benchmark/gsm8k/bench_sglang.py \ + --host g0034 --port 17100 --backend srt \ + --data-path /mnt/beegfs/cjy/data/gsm8k_test.jsonl \ + --num-questions 200 --parallel 64 \ + --temperature 0.0 --top-p 1.0 --max-new-tokens 512 \ + --raw-result-file /mnt/beegfs/cjy/gsm8k_debug_retest_20260607_183407/pass${PASS}_raw.jsonl \ + --result-file /mnt/beegfs/cjy/gsm8k_debug_retest_20260607_183407/pass${PASS}_result.jsonl +``` + +Results: + +- pass1: Accuracy `0.725`, Invalid `0.000`, Latency `35.364s`, Output throughput `601.398 token/s`. +- pass2: Accuracy `0.710`, Invalid `0.000`, Latency `34.390s`, Output throughput `606.721 token/s`. + +Important interpretation: this process/log was already warm before the canary, so pass1 is not a cold baseline. Both passes are warm-cache and both are already bad. This confirms the warm-cache correctness failure remains, but this particular canary does not measure cold→warm drop. + +Bound scheduler/raw correlation through `origin_sigs`: + +- 200 prompt IDs mapped to scheduler log entries. +- Each prompt appeared exactly twice in the benchmark window. +- CP0 scheduler batches: `bs=5` for 78 batches, `bs=4` for 2 batches, `bs=1` for 4 batches. +- Prefix top counts: `704` x334, `640` x34, `768` x32, `0` x2. +- Extend range: min `2`, max `65`, average `28.1` tokens. +- `prefix_floor_bad=0`: no scheduler occurrence had `prefix_len > floor(prompt_len/page_size)*page_size`, and `extend_len == prompt_len - prefix_len` for all mapped prompts. +- No `CP_SHARED_KV_FAIL_FAST`, `CP_SHARED_KV_FALLBACK`, `Traceback`, `RuntimeError`, or `Health check failed` in the benchmark window. + +Accuracy by prompt tail length (`prompt_len % 64`) on this warm-cache process: + +```text +pass1: + 00-16: 63/70 = 0.900 + 17-32: 49/62 = 0.790 + 33-48: 16/34 = 0.471 + 49-63: 17/34 = 0.500 +pass2: + 00-16: 61/70 = 0.871 + 17-32: 47/62 = 0.758 + 33-48: 15/34 = 0.441 + 49-63: 19/34 = 0.559 +``` + +Current evidence-based direction: + +1. Do not re-open the earlier `704/768 overmatch` hypothesis for this window: prompt-to-log matching shows no over-prefix relative to each prompt's own page floor. +2. Do not prioritize L2 load-back for this window: there were no `HiCache-load/load_back` markers in the canary window, and every mapped request was already L1/device cache-hit plus short current suffix. +3. The strongest current signal is tail-size correlation under warm L1 cache hit: failures rise sharply when the current suffix tail is larger. This points to cache-hit current-tail consume/compose, especially FP8/RAGGED MLA or index partial-current handling under compute padding, rather than radix overmatch or monolithic Mooncake transfer. +4. Next code reading should focus on whether the FP8/RAGGED `nsa_backend` path materializes current tail tokens from persistent KV before they are actually stored, or otherwise omits the explicit partial-current compose used by the PAGED path. + +## 2026-06-08 AO: RAGGED FP8 MLA cache-hit path can read current suffix through full materialize + +New code-reading finding after the 200-question warm-cache canary: + +- Current launch uses FP8 + `flashmla_sparse` RAGGED prefill path for CP shared KV. +- `nsa_backend.forward_extend()` only enters the existing MLA current/partial-current compose block when `topk_transform_method == TopkTransformMethod.PAGED`. +- The RAGGED branch later handles prefix sharing by calling `materialize_shared_token_kv_buffer(kv_cache, logical_locs=page_table_1_flattened, ...)` and then `dequantize_k_cache_paged(...)`. +- For cache-hit requests, `page_table_1_flattened` includes both cached prefix tokens and the just-computed current suffix tokens. The current suffix was direct-written into each CP rank's persistent KV earlier in the layer. +- If TAI IPC materialize is enabled, full materialize can read current suffix pages directly from peer ranks without an inter-rank ordering point proving those peer direct-write kernels have completed. The old collective materialize path incidentally provided such ordering; IPC gather removes it. + +This matches the observed shape: cold/current-only first-pass can be correct, but warm L1 cache-hit requests with short current suffixes lose accuracy, and failure rate correlates with current tail size. It also explains why no L2 load-back markers or radix over-prefix evidence appeared in the canary window. + +Planned test/fix direction: + +1. Add a regression/source-contract test showing the RAGGED CP shared-KV prefix-hit path must use page-slot partial-current compose, not full materialize of prefix+current through IPC. +2. Update RAGGED path to materialize prefix slots and fill/reduce current slots via `materialize_prefix_and_reuse_current_kv_page_slots`, mirroring the PAGED partial-current contract, then dequantize the resulting dense page-slot buffer. +3. Keep the test narrow; if this does not recover GSM8K warm-cache accuracy, add bounded RAGGED materialize debug under existing `SGLANG_CP_SHARED_KV_BS_GT1_DEBUG`. + +## 2026-06-08 AP: RAGGED fix exposed wrong current-row selector assumption + +Remote 200-question canary after the first RAGGED partial-current fix killed prefill before accuracy could be measured. + +Observed prefill exception in `/mnt/beegfs/cjy/log/sglang_cp_hicache_20260607_192001.log`: + +```text +RuntimeError: [CP_SHARED_KV_FAIL_FAST][cache_write_valid_selector_shape] +CP shared-KV cache write tensor must contain local compute rows before valid-row selection. +local_rows=473 expected_compute_rows=320 valid_rows=13 +``` + +and on another rank: + +```text +local_rows=473 expected_compute_rows=320 valid_rows=140 +``` + +Call stack: + +```text +nsa_backend.forward_extend -> RAGGED cache-hit compose -> +select_cp_local_valid_rows_for_cache_write(forward_batch, k/k_rope) +``` + +Interpretation: + +- `select_cp_local_valid_rows_for_cache_write()` is only valid for tensors whose first dimension is the CP-local compute-padded row count (`expected_compute_rows`). +- In the `flashmla_sparse` RAGGED attention branch, `k/k_rope` can have a different row contract (`local_rows=473` in the crash), so blindly reusing the cache-write selector there is wrong. +- The actual direct KV write path in `forward_mla._maybe_write_cp_shared_local_mla_kv()` has already performed the compute-padding valid-row selection before writing to persistent KV. The RAGGED attention compose path only needs a current-row source for attention materialization; it must select rows based on the actual tensor contract, not assume cache-write local compute rows. + +Next fix direction: + +1. Factor a helper for RAGGED/PAGED current-row source selection that accepts either: + - already local valid rows (`rows == local_out_cache_loc.numel()`), or + - CP-local compute-padded rows (`rows == expected_compute_rows`), using `select_cp_local_valid_rows_for_cache_write()`, or + - global valid current rows (`rows == current_extend_kv_rows_for_reuse(...)`), using `cp_split_and_rebuild_data()`. +2. Add a unit/source-contract test covering the `rows == local_out_cache_loc.numel()` fast path before production code change. diff --git a/python/sglang/srt/disaggregation/mooncake/conn.py b/python/sglang/srt/disaggregation/mooncake/conn.py index bc379c6ea..67d4b9e97 100644 --- a/python/sglang/srt/disaggregation/mooncake/conn.py +++ b/python/sglang/srt/disaggregation/mooncake/conn.py @@ -64,6 +64,21 @@ def _cp_draft_shared_kv_debug(message: str, *args, limit: int = 64) -> None: logger.info("[CP_DRAFT_SHARED_KV] " + message, *args) +def _cp_shared_kv_bs_gt1_mooncake_debug( + key: str, message: str, *args, limit: Optional[int] = None +) -> None: + if not envs.SGLANG_CP_SHARED_KV_BS_GT1_DEBUG.get(): + return + if limit is None: + limit = int(envs.SGLANG_CP_SHARED_KV_BS_GT1_DEBUG_LIMIT.get()) + count_key = "bs_gt1:" + key + count = _CP_SHARED_DEBUG_COUNTS.get(count_key, 0) + if limit > 0 and count >= limit: + return + _CP_SHARED_DEBUG_COUNTS[count_key] = count + 1 + logger.info("[CP_SHARED_KV_BS_GT1_DEBUG] event=%s " + message, key, *args) + + def _mooncake_transfer_stats_enabled() -> bool: return envs.SGLANG_DISAGGREGATION_TRANSFER_STATS.get() @@ -1211,6 +1226,19 @@ class MooncakeKVManager(CommonKVManager): _np_summary(chunked_dst_kv_indice), kv_chunk.is_last_chunk, ) + _cp_shared_kv_bs_gt1_mooncake_debug( + "transfer_worker_kv", + "cp_rank=%s room=%s prefill_pages=%s " + "logical_positions=%s dst_pages=%s is_last=%s " + "session=%s", + self.attn_cp_rank, + kv_chunk.room, + _np_summary(kv_chunk.prefill_kv_indices), + _np_summary(kv_chunk.logical_page_positions), + _np_summary(chunked_dst_kv_indice), + kv_chunk.is_last_chunk, + req.mooncake_session_id, + ) if envs.SGLANG_DEBUG_CP_SHARED_KV.get(): _cp_shared_debug_log( "transfer_worker_kv", @@ -1326,6 +1354,18 @@ class MooncakeKVManager(CommonKVManager): ), _np_summary(dst_state_indices), ) + _cp_shared_kv_bs_gt1_mooncake_debug( + "transfer_worker_state", + "cp_rank=%s room=%s prefill_state_pages=%s " + "state_positions=%s dst_state_pages=%s " + "session=%s", + self.attn_cp_rank, + kv_chunk.room, + _np_summary(kv_chunk.state_indices), + _np_summary(kv_chunk.state_logical_page_positions), + _np_summary(dst_state_indices), + req.mooncake_session_id, + ) self.maybe_send_extra( req, kv_chunk.state_indices, @@ -1706,6 +1746,22 @@ class MooncakeKVSender(CommonKVSender): is_last_chunk, getattr(self.kv_mgr.kv_args, "draft_kv_buffer_count", None), ) + _cp_shared_kv_bs_gt1_mooncake_debug( + "sender_filter", + "cp_rank=%s room=%s page_start=%s orig_kv_pages=%s " + "filtered_kv_pages=%s kv_positions=%s orig_state_pages=%s " + "filtered_state_pages=%s state_positions=%s is_last=%s", + self.kv_mgr.attn_cp_rank, + self.bootstrap_room, + chunk_page_start, + _np_summary(orig_kv_indices), + _np_summary(kv_indices), + _np_summary(logical_page_positions), + _np_summary(orig_state_indices), + _np_summary(state_indices), + _np_summary(state_logical_page_positions), + is_last_chunk, + ) # Special handling for cp elif self.kv_mgr.enable_all_cp_ranks_for_transfer: kv_indices, index_slice = filter_kv_indices_for_cp_rank( diff --git a/python/sglang/srt/disaggregation/prefill.py b/python/sglang/srt/disaggregation/prefill.py index 15881b4f0..c379a4324 100644 --- a/python/sglang/srt/disaggregation/prefill.py +++ b/python/sglang/srt/disaggregation/prefill.py @@ -43,6 +43,7 @@ from sglang.srt.disaggregation.utils import ( kv_to_page_num, poll_and_all_reduce_attn_cp_tp_group, prepare_abort, + token_ids_debug_signature, ) from sglang.srt.managers.schedule_batch import ( FINISH_ABORT, @@ -1304,7 +1305,7 @@ class SchedulerDisaggregationPrefillMixin: "rid=%s room=%s start_idx=%s end_idx=%s last_chunk=%s " "page_size=%s pages=%s state_pages=%s prefix_len=%s " "host_hit_length=%s extend_input_len=%s fill_len=%s " - "origin_input_len=%s has_draft_pool=%s", + "origin_input_len=%s has_draft_pool=%s origin_sig=%s fill_sig=%s", req.rid, req.bootstrap_room, start_idx, @@ -1319,6 +1320,8 @@ class SchedulerDisaggregationPrefillMixin: len(req.fill_ids), len(req.origin_input_ids), has_draft_pool, + token_ids_debug_signature(getattr(req, "origin_input_ids", None)), + token_ids_debug_signature(getattr(req, "fill_ids", None)), ) if has_draft_pool and draft_prefix_overlap > 0: _cp_draft_shared_kv_debug( diff --git a/python/sglang/srt/disaggregation/utils.py b/python/sglang/srt/disaggregation/utils.py index 49a524609..756e17d35 100644 --- a/python/sglang/srt/disaggregation/utils.py +++ b/python/sglang/srt/disaggregation/utils.py @@ -67,6 +67,31 @@ def _cp_shared_kv_poll_debug_enabled() -> bool: return envs.SGLANG_CP_SHARED_KV_BS_GT1_DEBUG.get() +def token_ids_debug_signature(token_ids: Any, *, sample: int = 6) -> str: + """Return a stable, bounded signature for request-token correlation logs.""" + + if token_ids is None: + return "None" + if isinstance(token_ids, torch.Tensor): + values = token_ids.detach().reshape(-1).cpu().tolist() + elif isinstance(token_ids, np.ndarray): + values = token_ids.reshape(-1).tolist() + else: + values = list(token_ids) + + mask = (1 << 63) - 1 + digest = 1469598103934665603 + for value in values: + item = int(value) & 0xFFFFFFFFFFFFFFFF + for shift in (0, 8, 16, 24, 32, 40, 48, 56): + digest ^= (item >> shift) & 0xFF + digest = (digest * 1099511628211) & mask + + head = values[:sample] + tail = values[-sample:] if len(values) > sample else values[:] + return f"len={len(values)} hash={digest} head={head} tail={tail}" + + def _poll_queue_debug_hash(debug_ids: Optional[list[str]]) -> int: if not debug_ids: return 0 diff --git a/python/sglang/srt/managers/scheduler.py b/python/sglang/srt/managers/scheduler.py index cf945ffdb..23ab5817d 100644 --- a/python/sglang/srt/managers/scheduler.py +++ b/python/sglang/srt/managers/scheduler.py @@ -60,6 +60,7 @@ from sglang.srt.disaggregation.utils import ( ReqToMetadataIdxAllocator, TransferBackend, prepare_abort, + token_ids_debug_signature, ) from sglang.srt.distributed import get_pp_group, get_world_group from sglang.srt.distributed.parallel_state import get_tp_group @@ -2584,7 +2585,7 @@ class Scheduler( "scheduler_prefill_batch", "bs=%s extend_lens=%s prefix_lens=%s seq_lens=%s " "out_cache_tokens=%s chunked_req=%s enable_bs_gt1=%s " - "max_batch_reqs=%s max_total_extend=%s", + "max_batch_reqs=%s max_total_extend=%s rids=%s origin_sigs=%s", len(can_run_list), list(getattr(new_batch, "extend_lens", []) or []), list(getattr(new_batch, "prefix_lens", []) or []), @@ -2603,6 +2604,11 @@ class Scheduler( "cp_shared_kv_prefill_max_total_extend_tokens", None, ), + [getattr(req, "rid", None) for req in can_run_list], + [ + token_ids_debug_signature(getattr(req, "origin_input_ids", None)) + for req in can_run_list + ], ) # Record prefill stats for logging after forward