docs: KVC v1-v4 debug journey + raise session soft_cap to 16

Document the iterative debugging from v1 (broken KVC) through v4
(routing fixed + session cap raised), with code-level analysis of
the two main bugs encountered:

1. v2 root cause (mis-diagnosed previously as `allow_local_prefill`):
   `--policy default` for KVC mechanism caused replay's round-robin
   policy and the PD router's round-robin to diverge, sending requests
   with `session_params` to a D worker that did not have the session
   open. Resulted in 56-61% truncation with finish_reason
   "session id X does not exist".
   Fix: use `--policy kv-aware` (sweep_tp1_v3_kvaware.sh) so replay
   emits `x-smg-target-worker` and PD router uses consistent_hashing.

2. v3 new bottleneck: `pd-router-fallback-large-append-session-cap`
   dominated 52-65% of requests. Root cause was hardcoded
   `min(4, ...)` in `_decode_session_soft_cap`. With 7 D workers x 4
   sessions = 28 slots for 52 trace sessions, ~24 sessions starved
   permanently (bimodal direct-to-D rate of 0% or 99%).
   Fix: raise the cap to 16 (replay.py).

Also includes the v3 finding that direct-to-d-session path P50=0.495s
and TTFT P50=0.043s already beats the 8-way DP baseline (0.65s/0.093s)
- the KVC core mechanism works when fallback paths are avoided.

Files:
- docs/KVC_DEBUG_JOURNEY_V1_TO_V4.md: full journey + code location index
- docs/SWEBENCH_EXPERIMENT_{PROGRESS,RESULTS}.md: prior session notes
- scripts/sweep_tp1_v{2,3,4}*.sh: experiment driver scripts
- src/agentic_pd_hybrid/replay.py: cap 4 -> 16, audit fields
- src/agentic_pd_hybrid/pd_router.py: strip session_params from prefill
- src/agentic_pd_hybrid/metrics.py: truncated_request_count

Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
kzlin
2026-04-28 21:10:41 +08:00
parent e9062b1d6e
commit c9d350b372
24 changed files with 1672 additions and 62 deletions

View File

@@ -124,6 +124,9 @@ class ExecutionResult:
prefill_request_priority: int | None = None
decode_request_priority: int | None = None
error: str | None = None
actual_output_tokens: int | None = None
requested_output_tokens: int | None = None
finish_reason: str | None = None
async def replay_trace(config: ReplayConfig) -> list[RequestMetrics]:
@@ -274,6 +277,9 @@ async def _run_request(
prefill_request_priority=execution.prefill_request_priority,
decode_request_priority=execution.decode_request_priority,
error=execution.error,
actual_output_tokens=execution.actual_output_tokens,
requested_output_tokens=execution.requested_output_tokens,
finish_reason=execution.finish_reason,
)
@@ -286,7 +292,7 @@ async def _invoke_router(
session_id: str | None = None,
prefill_request_priority: int | None = None,
decode_request_priority: int | None = None,
) -> tuple[float, float | None, float | None, int]:
) -> GenerateResult:
headers = _build_headers(
request=request,
header_mode=config.header_mode,
@@ -414,6 +420,18 @@ async def _invoke_chat_completion(
return latency_s, ttft_s, tpot_s, cached_tokens
@dataclass(frozen=True)
class GenerateResult:
latency_s: float
ttft_s: float | None
tpot_s: float | None
cached_tokens: int
actual_output_tokens: int
requested_output_tokens: int
finish_reason: str | None
server_meta_info: dict | None
async def _invoke_generate(
*,
client: httpx.AsyncClient,
@@ -423,12 +441,16 @@ async def _invoke_generate(
timeout_s: float,
stream_idle_timeout_s: float | None,
stream: bool,
) -> tuple[float, float | None, float | None, int]:
) -> GenerateResult:
start = time.perf_counter()
ttft_s: float | None = None
cached_tokens = 0
sampling_params = payload.get("sampling_params", {})
generated_tokens = int(sampling_params.get("max_new_tokens", 1))
requested_output_tokens = int(sampling_params.get("max_new_tokens", 1))
actual_token_count = 0
finish_reason: str | None = None
last_meta_info: dict | None = None
if stream:
async with client.stream(
"POST",
@@ -452,8 +474,19 @@ async def _invoke_generate(
if isinstance(error, dict):
raise ValueError(error.get("message", json.dumps(error)))
cached_tokens = max(cached_tokens, _extract_generate_cached_tokens(parsed))
if _contains_generate_token(parsed) and ttft_s is None:
ttft_s = time.perf_counter() - start
if _contains_generate_token(parsed):
actual_token_count += 1
if ttft_s is None:
ttft_s = time.perf_counter() - start
meta_info = parsed.get("meta_info")
if isinstance(meta_info, dict):
last_meta_info = meta_info
completion_tokens = int(meta_info.get("completion_tokens", 0))
if completion_tokens > actual_token_count:
actual_token_count = completion_tokens
fr = meta_info.get("finish_reason")
if fr is not None:
finish_reason = str(fr)
if _is_generate_terminal_chunk(parsed):
break
else:
@@ -469,15 +502,33 @@ async def _invoke_generate(
if isinstance(error, dict):
raise ValueError(error.get("message", json.dumps(error)))
cached_tokens = _extract_generate_cached_tokens(parsed)
meta_info = parsed.get("meta_info")
if isinstance(meta_info, dict):
last_meta_info = meta_info
actual_token_count = int(meta_info.get("completion_tokens", 0))
finish_reason = meta_info.get("finish_reason")
latency_s = time.perf_counter() - start
if stream and ttft_s is None and generated_tokens > 0:
if stream and ttft_s is None and requested_output_tokens > 0:
raise RuntimeError("generate stream ended before producing any token")
# Use actual token count for TPOT (not requested count)
effective_tokens = max(1, actual_token_count) if actual_token_count > 0 else max(1, requested_output_tokens)
if ttft_s is None:
tpot_s = None
else:
tpot_s = max(0.0, latency_s - ttft_s) / max(1, generated_tokens)
return latency_s, ttft_s, tpot_s, cached_tokens
tpot_s = max(0.0, latency_s - ttft_s) / effective_tokens
return GenerateResult(
latency_s=latency_s,
ttft_s=ttft_s,
tpot_s=tpot_s,
cached_tokens=cached_tokens,
actual_output_tokens=actual_token_count,
requested_output_tokens=requested_output_tokens,
finish_reason=finish_reason,
server_meta_info=last_meta_info,
)
async def _open_streaming_session(
@@ -850,8 +901,8 @@ def _decode_session_soft_cap(
- residency.headroom_tokens.get(server_url, 0),
)
if usable_capacity_tokens <= 0:
return 4
return max(1, min(4, usable_capacity_tokens // target_tokens))
return 16
return max(1, min(16, usable_capacity_tokens // target_tokens))
def _should_admit_new_decode_session(
@@ -1587,7 +1638,7 @@ async def _invoke_plain_router(
config=config,
direct_to_d_predicted=False,
)
latency_s, ttft_s, tpot_s, cached_tokens = await _invoke_router(
gen = await _invoke_router(
client=client,
request=request,
config=config,
@@ -1598,13 +1649,16 @@ async def _invoke_plain_router(
execution_mode=execution_mode,
actual_kv_transfer_blocks=decision.kv_transfer_blocks,
effective_input_length=request.input_length,
cached_tokens=cached_tokens,
cached_tokens=gen.cached_tokens,
prefill_request_priority=prefill_priority,
session_reused=False,
session_reset=False,
latency_s=latency_s,
ttft_s=ttft_s,
tpot_s=tpot_s,
latency_s=gen.latency_s,
ttft_s=gen.ttft_s,
tpot_s=gen.tpot_s,
actual_output_tokens=gen.actual_output_tokens,
requested_output_tokens=gen.requested_output_tokens,
finish_reason=gen.finish_reason,
)
@@ -1676,7 +1730,7 @@ async def _invoke_kvcache_seeded_router(
decode_session.opened = True
decode_session_newly_opened = True
decode_session.active_requests += 1
latency_s, ttft_s, tpot_s, cached_tokens = await _invoke_router(
gen = await _invoke_router(
client=client,
request=request,
config=config,
@@ -1742,13 +1796,16 @@ async def _invoke_kvcache_seeded_router(
execution_mode=execution_mode,
actual_kv_transfer_blocks=decision.kv_transfer_blocks,
effective_input_length=request.input_length,
cached_tokens=cached_tokens,
cached_tokens=gen.cached_tokens,
prefill_request_priority=prefill_priority,
session_reused=False,
session_reset=False,
latency_s=latency_s,
ttft_s=ttft_s,
tpot_s=tpot_s,
latency_s=gen.latency_s,
ttft_s=gen.ttft_s,
tpot_s=gen.tpot_s,
actual_output_tokens=gen.actual_output_tokens,
requested_output_tokens=gen.requested_output_tokens,
finish_reason=gen.finish_reason,
)
@@ -1774,14 +1831,16 @@ async def _execute_request(
)
if config.mechanism_name == "pd-colo":
return await _invoke_direct(
if not config.router_url:
raise ValueError("router_url is required for pd-colo replay")
result = await _invoke_plain_router(
client=client,
request=request,
config=config,
decision=decision,
direct_sessions=direct_sessions,
direct_session_lock=direct_session_lock,
execution_mode="dp-colo-router",
)
return replace(result, actual_kv_transfer_blocks=0)
if config.mechanism_name == "kvcache-centric":
if not config.router_url:
@@ -2238,7 +2297,7 @@ async def _invoke_session_direct(
session.active_requests += 1
try:
latency_s, ttft_s, tpot_s, cached_tokens = await _invoke_generate(
gen = await _invoke_generate(
client=client,
base_url=session.server_url,
headers={"x-request-id": request.request_id},
@@ -2277,12 +2336,15 @@ async def _invoke_session_direct(
execution_mode=execution_mode,
actual_kv_transfer_blocks=0,
effective_input_length=len(input_ids),
cached_tokens=cached_tokens,
cached_tokens=gen.cached_tokens,
session_reused=session_reused,
session_reset=session_reset,
latency_s=latency_s,
ttft_s=ttft_s,
tpot_s=tpot_s,
latency_s=gen.latency_s,
ttft_s=gen.ttft_s,
tpot_s=gen.tpot_s,
actual_output_tokens=gen.actual_output_tokens,
requested_output_tokens=gen.requested_output_tokens,
finish_reason=gen.finish_reason,
)