Prevent stale CP HiCache tails from overlapping new page owners

CP HiCache owns KV at page granularity, but exact valid-tail extension and backed partial-tail split could leave an old sub-page tail child beside a new suffix that reuses the same physical page. That makes radix residency ambiguous across device, host, and draft mirrors. The insert/match split paths now prune stale floored tails when safe, and defer/fail through the existing pending-split path when the subtree is protected or has in-flight backup state.\n\nThis also keeps a temporary scheduler boundary warning for externally observed zero-output responses so future ETE runs can classify whether zero visible output reaches SGLang's output processor.\n\nConstraint: CP shared KV and HiCache manage physical KV by page, while radix keys retain valid-token lengths.\nRejected: Keep overlapping old tail nodes after page-floor split | leaves two independent cache states for one physical tail page.\nRejected: Force-prune protected or in-flight backup tails | can mutate cache state still used by active transfer or inference.\nConfidence: medium\nScope-risk: moderate\nDirective: Do not remove the stale-tail prune without replacing it with another page-granular ownership rule for CP HiCache radix splits.\nTested: Remote py_compile for hiradix_cache.py and scheduler_output_processor_mixin.py in g0034 container.\nTested: Remote PYTHONPATH=python python -m pytest -q test/registered/unit/mem_cache/test_cp_hicache_metadata.py -> 97 passed, 5 warnings.\nNot-tested: Full ETE recovery of EAGLE accept length; latest ETE still shows accept collapse, documented in C55.\nNot-tested: Router/client-side output_len=0 correlation when server-side OUTPUT_ZERO_DEBUG does not fire.
This commit is contained in:
laoyao0822
2026-05-30 05:51:53 +08:00
parent e9c341afe8
commit 10296a5fef
4 changed files with 326 additions and 13 deletions
@@ -2323,3 +2323,190 @@ Interpretation:
- Do not use this process to judge C48.
- If the earlier held-slot fix was active in this process, low accept length is not fully explained by missing EAGLE metadata lifetime alone; next investigation should compare a fresh C48 runtime and then inspect EAGLE state correctness/content, not just tensor presence.
### C50. 2026-05-30 output_len=0 is confirmed by router/client; server-side checked points
New user-provided fact:
- `output_len=0` has been confirmed from router/client logs. Treat it as a
real external symptom even if the currently inspected SGLang server logs do
not print full response bodies.
Server-side evidence checked so far:
- The latest valid decode logs around the previous failure window contain a
burst of `Decode transfer failed ... Aborted by AbortReq` at
`2026-05-29 21:01:40`, and the paired prefill log contains matching
`Prefill bootstrap failed` / `Prefill transfer failed` aborts at
`2026-05-29 21:01:41`.
- A request aborted before any decoded token can produce a zero-length final
output at the scheduler boundary (`stream_output_generation()` reports
`completion_tokens=len(req.output_ids_through_stop)`). The OpenAI serving
layer should normally convert scheduler abort finish reasons to HTTP errors,
so a client-observed successful empty response still needs a request-id/rid
correlation or a server-side zero-output warning to determine whether the
empty result is `abort`, `length=0`, stop-trimming, or router/client handling.
- The newer prefill process PID `2763878` started at `2026-05-30 05:01:46 CST`
from the synced code, but at the time of this check it was still in startup /
weight-load/warmup logs (`sglang_cp_hicache_20260529_210146.log`). It cannot
yet validate whether C48/C49 fixed or changed the output-len symptom.
Do-not-repeat:
- Do not conclude “server did not output zero” only because the SGLang log does
not contain `completion_tokens=0`; those bodies are usually not logged.
- Do not treat router `Prefill server failed (CRITICAL)` as an independent
router bug when it aligns with prefill/decode KV-transfer aborts.
Next useful evidence:
- Add a low-frequency/anomaly-only server warning at the scheduler output
boundary for finished generation responses with `completion_tokens == 0`,
including `rid`, `finish_reason`, `max_new_tokens`, `origin_len`, cached
tokens, disaggregation mode, and bootstrap room. This should fire only on the
confirmed anomalous path and should be removed or gated after root cause is
found.
### C51. 2026-05-30 split hypothesis for output_len=0
New user-provided hypothesis:
- `output_len=0` may be caused by a split path.
Checked points:
- There are two distinct split mechanisms in the current failure surface:
1. NSA in-seq CP split (`can_cp_split()` / `build_page_aligned_in_seq_split_list()`),
which affects forward compute distribution.
2. Radix/HiCache tree split (`HiRadixCache._split_node()`), which affects
device/host cache residency and prefix matching.
- C24 already disables NSA in-seq CP split for cache-hit suffixes with fewer
physical suffix pages than CP lanes. This removes the known `extend_len=65`
mostly-zero-lane split path, but it does not address long suffixes or radix
structural splits.
- Current radix exact-valid-tail extension handling floors the matched prefix
to the previous page boundary. During insertion it then splits the old
valid-tail node and can leave two children under the same page-boundary parent
whose keys start at the same logical tail page, e.g. with `page_size=4`:
old child `(4, 5)` and new longer child `(4, 5, 6, 7)`.
- This overlapping-child shape is not yet proven to produce `output_len=0`, but
it is a real radix invariant risk: two children can represent overlapping
logical token ranges with independent device/host/draft HiCache state. Under
eviction/load-back or EAGLE target/draft mirror pressure, that can create
target/draft cache-state divergence or unnecessary transfer/abort pressure.
- The latest inspected runtime did not include the new `OUTPUT_ZERO_DEBUG`
scheduler boundary warning, so server-side classification of confirmed
client/router `output_len=0` is still pending a fresh process. Existing logs
still show the direct zero-output-compatible server symptom as large bursts of
prefill/decode `KVTransferError(...): Aborted by AbortReq` followed by decode
losing the prefill connection.
Next checks:
- Add a focused radix regression that demonstrates the overlapping-child shape
for exact valid-tail extension and then replace it with a page-granular policy
that sacrifices the old sub-page tail instead of keeping two overlapping
children.
- Keep the scheduler `OUTPUT_ZERO_DEBUG` anomaly warning until a fresh runtime
confirms whether client/router `output_len=0` corresponds to abort,
max_new_tokens=0/length finish, stop trimming, or another finish reason.
### C52. 2026-05-30 exact valid-tail split currently preserves stale sub-page child
Finding:
- The existing focused unit test `test_cp_insert_extends_from_page_boundary_after_exact_valid_tail`
encodes the risky behavior from C51 as expected behavior: after an old valid-tail
CP node `(0..5)` is extended by a new request `(0..9)`, the radix tree keeps both
the stale old child `(4,5)` and the new longer child `(4,5,6,7,8,9)` under the
page-boundary parent `(0..3)`.
- This violates the page-granular cache contract we now want for CP HiCache: a
logical sub-page tail is not an independent cache-management unit once a request
extends beyond it. The old tail page should be sacrificed/freed, and the new
suffix should own that page from the boundary.
Next implementation guardrail:
- Add/adjust the regression first so the expected tree has only the new suffix
child after exact-valid-tail extension. Then implement a narrow CP-only prune
path for the stale tail child, with pending/in-flight backup split still fail-fast
or deferred instead of silently mutating an in-flight node.
### C53. 2026-05-30 stale-tail pruning must cover backed partial-tail splits too
Finding:
- The exact-valid-tail extension case is only one instance of the same bug.
`test_cp_insert_floors_backed_tail_split_to_page_boundary` shows a backed CP
HiCache node `(0..5)` split by a shorter/new partial request `(0..4)`. The old
test also preserved the stale child `(4,5)` beside the new child `(4)`, creating
the same overlapping-page state.
- Therefore the prune condition cannot be limited to exact valid-tail extension.
Whenever CP split length is floored from inside a valid/padded tail page to the
previous page boundary, the stale tail subtree created by `_split_node()` must
be pruned unless it is protected or has an in-flight backup.
Guardrail:
- Probe-only paths may continue to floor without mutating. Mutating match/insert
paths must prune stale tails after page-floor split; protected/in-flight tails
must defer/fail rather than silently keeping overlapping children.
### C54. 2026-05-30 stale CP tail pruning implemented and tested
Implemented:
- CP mutating radix match/insert paths now detect when a split length was floored
from inside a page to the previous page boundary.
- After `_split_node()` creates the page-boundary parent, the stale sub-page tail
subtree is pruned instead of being kept as an overlapping child. This applies
both to exact valid-tail extension and backed partial-tail split cases.
- The prune path first checks the stale subtree for lock refs, host refs, pending
backup, or ongoing write-through state. Such in-flight/protected tails defer
or fail via the existing pending-split path rather than silently mutating cache
state used by active work.
- Pruning frees device indices and CP host/draft metadata when the corresponding
cache-controller eviction hooks are available, then unlinks the stale subtree
and refreshes leaf state when the cache was fully initialized.
Verification:
- Remote py_compile passed for `python/sglang/srt/mem_cache/hiradix_cache.py` and
`python/sglang/srt/managers/scheduler_output_processor_mixin.py` in container
`/sgl-workspace/sglang-tai`.
- Remote targeted red tests first failed on the old overlapping-child behavior.
- Remote full focused suite passed after the fix:
`PYTHONPATH=python python -m pytest -q test/registered/unit/mem_cache/test_cp_hicache_metadata.py`
-> `97 passed, 5 warnings`.
Remaining risk:
- This removes one concrete split-induced overlapping-cache invariant violation,
but it does not yet prove the external `output_len=0` symptom is fixed. A fresh
ETE run still needs to check for `[OUTPUT_ZERO_DEBUG]`, decode accept length,
and router/client zero-output correlation.
### C55. 2026-05-30 latest split-prune runtime: zero-output not seen in server logs, EAGLE accept still collapsed
Runtime identity:
- New prefill process on `g0034` PID `2796105` started at `2026-05-30 05:36:48 CST`, after the split-prune and `OUTPUT_ZERO_DEBUG` source sync (`05:33-05:34 CST`).
- Decode processes on `g0035`/`g0036` started at `05:36:52/05:36:55 CST` and see the same synced source mtimes.
- Latest logs inspected:
- prefill: `/mnt/beegfs/cjy/log/sglang_cp_hicache_20260529_213648.log`
- decode0: `/mnt/beegfs/cjy/log/decode0_20260529_213652.log`
- decode1: `/mnt/beegfs/cjy/log/decode1_20260529_213656.log`
Checked result:
- No `[OUTPUT_ZERO_DEBUG]` line was found in prefill/decode logs, and no server-side `completion_tokens: 0` / `output_len=0` text was found in these logs. This does not prove the router/client symptom is gone, but the scheduler boundary did not observe a finished generation with zero visible tokens in the inspected log window.
- No current prefill/decode `KVTransferError`, transfer abort burst, traceback, health-check failure, or scheduler exception was found in this log window. The only `out of memory` text was warmup max_m reduction, not runtime OOM.
- EAGLE accept remains bad in the inspected decode logs:
- decode0: `17649` accept-debug rows, average `avg_accept=0.073`, median `0.0`, `15650` zero rows, `17544` rows at `<=1.05`; last 200 rows average `0.135`.
- decode1: `17541` accept-debug rows, average `avg_accept=0.065`, median `0.0`, `15569` zero rows, `17495` rows at `<=1.05`; last 200 rows average `0.030`.
- Metadata presence is not missing in the samples: `has_pd_hidden=True`, `pd_hidden_shape=(6144,)`, `pd_topk_shape=(16,)`, no `has_pd_hidden=False` / `pd_topk_shape=None` lines. `spec_topk_shape=(0,1)` appears occasionally but is not the dominant count; most rows have `(1,1)` or `(2,1)`.
Interpretation:
- Split-prune removes a real overlapping-radix invariant violation, but it did not recover EAGLE accept length in this run.
- The current accept collapse is more likely in the semantic correctness/content of EAGLE prebuilt state or draft/target KV alignment than in missing metadata lifetime or gross transfer failure. Next debugging should compare the actual prebuilt top-k token/content and draft input state against a non-HiCache or non-CP baseline, not just tensor shape/presence.
@@ -1140,6 +1140,28 @@ class SchedulerOutputProcessorMixin:
# Exclude the tokens after stop condition
output_ids_ = req.output_ids_through_stop
if req.finished() and len(output_ids_) == 0:
logger.warning(
"[OUTPUT_ZERO_DEBUG] finished generation with zero visible "
"tokens: rid=%s finish_reason=%s max_new_tokens=%s "
"origin_len=%s raw_output_len=%s finished_len=%s "
"send_token_offset=%s cached_tokens=%s disaggregation_mode=%s "
"bootstrap_room=%s",
getattr(req, "rid", None),
(
req.finished_reason.to_json()
if req.finished_reason is not None
else None
),
getattr(req.sampling_params, "max_new_tokens", None),
len(getattr(req, "origin_input_ids", []) or []),
len(getattr(req, "output_ids", []) or []),
getattr(req, "finished_len", None),
send_token_offset,
getattr(req, "cached_tokens", None),
getattr(self, "disaggregation_mode", None),
getattr(req, "bootstrap_room", None),
)
req.send_decode_id_offset = len(decode_ids)
read_offsets.append(read_offset)
+111 -2
View File
@@ -2157,6 +2157,98 @@ class HiRadixCache(RadixCache):
return prefix_len
return floor_to_page_len(prefix_len, self.page_size)
def _cp_subtree_has_unprunable_state(self, node: TreeNode) -> bool:
stack = [node]
while stack:
current = stack.pop()
if (
current.lock_ref > 0
or current.host_ref_counter > 0
or self._node_host_write_pending(current)
):
return True
stack.extend(current.children.values())
return False
def _cp_prune_stale_tail_after_page_floor(
self, parent: TreeNode, stale_tail: TreeNode
) -> None:
"""Drop a sub-page CP tail after flooring an extending request to a page.
CP HiCache owns KV at page granularity. If a cached key ends inside a
page and a later request extends past that valid tail, the old sub-page
child must not remain as an independent radix child beside the new
page-boundary suffix. Keeping both creates overlapping children for the
same physical page. We sacrifice the old tail page and let the new
request re-own that page from the boundary.
"""
if not self._uses_cp_hicache:
return
if stale_tail.parent is not parent:
raise RuntimeError(
"CP HiCache stale-tail prune saw a detached split child: "
f"parent_id={getattr(parent, 'id', None)} "
f"tail_id={getattr(stale_tail, 'id', None)}"
)
if self._cp_subtree_has_unprunable_state(stale_tail):
raise HiCachePendingBackupSplit(stale_tail)
self._cp_delete_stale_tail_subtree(stale_tail)
def _cp_delete_stale_tail_subtree(self, node: TreeNode) -> None:
for child in list(node.children.values()):
self._cp_delete_stale_tail_subtree(child)
parent = node.parent
if parent is None:
raise RuntimeError(
"CP HiCache stale-tail prune attempted to delete a root node"
)
device_resident_len = self._node_device_resident_len(node)
if hasattr(self, "evictable_leaves") and node in self.evictable_leaves:
self.evictable_leaves.remove(node)
if hasattr(self, "evictable_size_"):
self.evictable_size_ -= device_resident_len
if hasattr(self, "evictable_host_leaves") and node in self.evictable_host_leaves:
self.evictable_host_leaves.remove(node)
if node.value is not None:
self._record_remove_event(node)
cache_controller = getattr(self, "cache_controller", None)
if cache_controller is not None and hasattr(cache_controller, "evict_device"):
cache_controller.evict_device(node.value)
elif cache_controller is not None and hasattr(
cache_controller, "mem_pool_device_allocator"
):
cache_controller.mem_pool_device_allocator.free(node.value)
node.value = None
if node.cp_hicache is not None:
cache_controller = getattr(self, "cache_controller", None)
if cache_controller is not None and hasattr(cache_controller, "evict_cp_host"):
cache_controller.evict_cp_host(node.cp_hicache)
node.cp_hicache = None
node.host_len = 0
elif node.host_value is not None:
cache_controller = getattr(self, "cache_controller", None)
if cache_controller is not None and hasattr(cache_controller, "evict_host"):
cache_controller.evict_host(node.host_value)
node.host_value = None
node.host_len = 0
key = self.get_child_key_fn(node.key)
removed = parent.children.pop(key, None)
if removed is not node:
raise RuntimeError(
"CP HiCache stale-tail prune removed unexpected child: "
f"key={key} node_id={getattr(node, 'id', None)}"
)
if hasattr(self, "evictable_leaves"):
self._update_leaf_status(parent)
if hasattr(self, "evictable_host_leaves"):
self._update_host_leaf_status(parent)
def prepare_write_backup_for_req(self, req) -> None:
if self.disable or not self._uses_cp_hicache:
return
@@ -3552,10 +3644,12 @@ class HiRadixCache(RadixCache):
# Refresh pin TTL on cache hit
if self._is_pinned(child):
child.pin_expiry = time.monotonic() + child.pin_ttl
prefix_len = self.key_match_fn(child.key, key)
raw_prefix_len = self.key_match_fn(child.key, key)
prefix_len = self._cp_floor_exact_valid_tail_extension_len(
child, prefix_len, len(key)
child, raw_prefix_len, len(key)
)
stop_after_page_floor = prefix_len != raw_prefix_len
prune_stale_tail_after_split = stop_after_page_floor
if prefix_len <= 0:
break
if prefix_len < len(child.key):
@@ -3569,12 +3663,19 @@ class HiRadixCache(RadixCache):
and self.page_size > 1
and prefix_len % self.page_size != 0
):
unfloored_prefix_len = prefix_len
prefix_len = self._cp_floor_backed_partial_split_len(
child, prefix_len
)
prune_stale_tail_after_split = (
prune_stale_tail_after_split
or prefix_len != unfloored_prefix_len
)
if prefix_len == 0:
break
new_node = self._split_node(child.key, child, prefix_len)
if prune_stale_tail_after_split:
self._cp_prune_stale_tail_after_page_floor(new_node, child)
if not new_node.evicted:
value.append(new_node.value)
node = new_node
@@ -3688,12 +3789,20 @@ class HiRadixCache(RadixCache):
total_prefix_length += prefix_len
else:
# partial match, split the node
prune_stale_tail_after_split = stop_after_page_floor
unfloored_prefix_len = prefix_len
prefix_len = self._cp_floor_backed_partial_split_len(
node, prefix_len
)
prune_stale_tail_after_split = (
prune_stale_tail_after_split
or prefix_len != unfloored_prefix_len
)
if prefix_len <= 0:
break
new_node = self._split_node(node.key, node, prefix_len)
if prune_stale_tail_after_split:
self._cp_prune_stale_tail_after_page_floor(new_node, node)
# shared-prefix node should also reflect max priority
new_node.priority = max(new_node.priority, priority)
if new_node.evicted:
@@ -2646,11 +2646,7 @@ class TestHiRadixCacheCPLoadBack(CustomTestCase):
self.assertEqual(result.last_host_node.host_len, 4)
self.assertEqual(result.last_host_node.cp_hicache.logical_len, 4)
self.assertEqual(result.last_host_node.cp_hicache.padded_len, 4)
child = result.last_host_node.children[(4, 5)]
self.assertEqual(child.key.token_ids, [4, 5])
self.assertEqual(child.host_len, 2)
self.assertEqual(child.cp_hicache.logical_len, 2)
self.assertEqual(child.cp_hicache.padded_len, 4)
self.assertNotIn((4, 5), result.last_host_node.children)
def test_cp_backed_tail_split_before_first_page_returns_root_match(self):
cache = HiRadixCache.__new__(HiRadixCache)
@@ -2790,6 +2786,8 @@ class TestHiRadixCacheCPLoadBack(CustomTestCase):
cache.maybe_bigram_convert = lambda key: (key, None)
cache._update_leaf_status = lambda node: None
cache._update_host_leaf_status = lambda node: None
cache.enable_storage = False
cache.enable_kv_cache_events = False
root = TreeNode()
root.key = RadixKey([])
root.value = torch.empty((0,), dtype=torch.int64)
@@ -2811,7 +2809,7 @@ class TestHiRadixCacheCPLoadBack(CustomTestCase):
self.assertEqual(result.device_indices.tolist(), [0, 1, 2, 3])
self.assertEqual(result.host_hit_length, 0)
self.assertEqual(result.last_device_node.key.token_ids, [0, 1, 2, 3])
self.assertEqual(result.last_device_node.children[(4, 5)].key.token_ids, [4, 5])
self.assertNotIn((4, 5), result.last_device_node.children)
def test_cp_insert_floors_backed_tail_split_to_page_boundary(self):
cache = HiRadixCache.__new__(HiRadixCache)
@@ -2869,10 +2867,7 @@ class TestHiRadixCacheCPLoadBack(CustomTestCase):
self.assertEqual(parent.key.token_ids, [0, 1, 2, 3])
self.assertEqual(parent.cp_hicache.logical_len, 4)
self.assertEqual(parent.cp_hicache.padded_len, 4)
old_tail = parent.children[(4, 5)]
self.assertEqual(old_tail.key.token_ids, [4, 5])
self.assertEqual(old_tail.cp_hicache.logical_len, 2)
self.assertEqual(old_tail.cp_hicache.padded_len, 4)
self.assertNotIn((4, 5), parent.children)
new_tail = parent.children[(4,)]
self.assertEqual(new_tail.key.token_ids, [4])
self.assertEqual(new_tail.value.tolist(), [4])
@@ -2937,7 +2932,7 @@ class TestHiRadixCacheCPLoadBack(CustomTestCase):
self.assertEqual(result.prefix_len, 4)
parent = root.children[(0, 1, 2, 3)]
self.assertEqual(parent.key.token_ids, [0, 1, 2, 3])
self.assertEqual(parent.children[(4, 5)].key.token_ids, [4, 5])
self.assertNotIn((4, 5), parent.children)
new_tail = parent.children[(4, 5, 6, 7)]
self.assertEqual(new_tail.key.token_ids, [4, 5, 6, 7, 8, 9])
self.assertTrue(prepared.attached)