mirror of
https://github.com/kvcache-ai/Mooncake.git
synced 2026-11-05 01:17:55 +00:00
[GH-ISSUE #4757] [Bug]: [Store] BatchGet returns TRANSFER_FAIL at the 60 s wait while RDMA READs are still in flight; caller reuses the destination GPU buffers and gets corrupted KV #1212
Labels
No labels
ascend
auto-closed
bug
bug
CI/Build
Common
documentation
enhancement
feature request
good first issue
help wanted
high priority
MetaX
nightly-failure
pull-request
PyTorch Backend
question
RFC
Roadmap
stale
Store
Tests
Transfer Engine
No milestone
No project
No assignees
1 participant
Notifications
Due date
No due date set.
Dependencies
No dependencies set.
Reference
kvcache-ai/Mooncake#1212
Loading…
Add table
Add a link
Reference in a new issue
No description provided.
Delete branch "%!s()"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Originally created by @ThisFat on GitHub (Oct 19, 2026).
Original GitHub issue: https://github.com/kvcache-ai/Mooncake/issues/4757
Bug Report
Environment
mooncake-transfer-engine0.3.13.post1 (PyPI wheel). Log linetransfer_task.cpp:891matches tagv0.3.13.post1(commit719735896c86), i.e. the non-event-driven polling branch ofwait_for_completion()MooncakeStoreConnector;{"kv_connector":"MooncakeStoreConnector","kv_role":"kv_both","kv_load_failure_policy":"recompute","kv_connector_extra_config":{"lookup_async":true}}kv cache group sizes [640, 4, 640, 640, 640, 640]), TP=8,--max-model-len 262144,--enable-prefix-caching,--enable-chunked-prefill,--max-num-batched-tokens 8192,--prefix-match-unit 128nvidia_peermemloaded, MLNX_OFED 24.10-5.1.6.1mlx5_0, 400 Gb/s NDR), netdev MTU 9000 / active MTU 4096, GID index 3mooncake_masteron A:--default_kv_lease_ttl=60s --eviction_high_watermark_ratio=0.85 --eviction_ratio=0.02. Onemooncake_clientStore per node:--protocol=rdma --device_names=mlx5_0 --global_segment_size=1099511627776 --local_buffer_size=8589934592 --metadata_server=P2PHANDSHAKE. vLLM on each node uses the store as a client. Pool ~84% used, eviction continuously activeMC_*set (defaults:MC_SLICE_TIMEOUT=-1,MC_RETRY_CNT=9)Description
TransferEngineOperationState::wait_for_completion()gives up after a hard-coded 60 s, setsTRANSFER_FAILand returns, without cancelling or draining the batch.Client::BatchGetthen returns to the caller. vLLM'sMooncakeStoreConnectortreats the failure as "these blocks are invalid": the scheduler reschedules the request and the GPU KV blocks are freed and reallocated (to other requests, or to the same request for recompute). The RDMA READs of the timed-out batch that are still queued or in flight keep the old local destination addresses. When they complete later, they write stale KV into GPU blocks that now hold other data.This is the read-side counterpart of #4491 (timed-out put overwrites the next object).
Expected: after
BatchGetreturns an error for a key, Mooncake no longer writes into that key's destination buffer, or the API tells the caller the buffer is not yet safe to reuse.Actual:
TRANSFER_FAILis returned while transfers targeting the buffer may still complete. The batch'sfreeBatchID()fails silently, and nothing in the logs shows that transfers were left behind.Observed behavior
After node C's Store joined the pool (2 → 3 TiB), all three vLLM processes started logging bursts of:
Over ~3.3 days: node A 8,825 timed-out batches, node B 5,849, node C 35,166. Nodes A and B had zero of these in the preceding 3 days with a 1- and then 2-Store pool (including ~18 h of A↔B cross-node reads). Load does not explain it: a day peaking at ~1.2 TB/h of
load_gethad none; a later day peaking at ~0.33 TB/h still had >1,000 timed-out batches per hour on node A.No RDMA-level errors in the same logs: no
Process failed for slice, noCannot redispatch slice, noBatchID cannot be freed.LEASE_EXPIREDoutnumbersTRANSFER_FAILabout 3:1, so many of these transfers did finish, just after 60 s.Output corruption correlates with the timeouts. Over two days we matched every
Recovered from KV load failureevent (tokens > 0) to gateway requests on the same node (arrived before the event, first token after it, prompt ≥ affected tokens). An output counts as broken if it is garbled from the first token or runs away (hitsmax_tokensor ends in endless repetition):The second row was never touched by the scheduler's recovery path, yet breaks ~5× more often than baseline. That points to memory being overwritten, not to a scheduling bug. Example: one request (49,713-token prompt, clean conversation history) waited 81.7 s for its first token. About 60 s after it arrived, the log on that node shows
Failed to get 65 Mooncake keys→rescheduled (49152 tokens affected), and the response was garbage from the first token.Mitigation in progress: we stopped node C's Store (back to 2 Stores). The timeout and reschedule counters on A and B have not increased since.
Steps to reproduce
A. How it happened in production (reproduces for us, but not on demand)
mooncake_masteron node A with the flags above, and onemooncake_clientStore (1 TiB, RDMA) on each of A, B, C.MooncakeStoreConnectorconfig above (kv_load_failure_policy=recompute,lookup_async=true).Failed to complete transfers after 60000 millisecondsfollowed byRecovered from KV load failure. Compare the responses of the rescheduled requests, and of other requests on the same node in the same minute, against the same prompts on a node without Mooncake.We do not yet know what makes reads stall for 60 s on our fabric (see question 4), so we cannot trigger the stall on demand.
B. Minimal reproduction of the corruption (derived from the code; we have not run it)
The corruption does not depend on why the transfer is slow, only on a READ completing after
wait_for_completion()has returned. A deterministic test needs:Don the reading client.PutkeyKwith payload patternP1.Ktake longer than 60 s. Any of these should work: delay completion in the RDMA/transport layer in a test build (similar to the reproduction being prepared for #4491); or block RoCE traffic between the two nodes for ~65 s (switch ACL or port shutdown) and then restore it, so the queued/redispatched slices complete late.BatchGet/batch_get_into_multi_buffersforKintoD. ExpectTRANSFER_FAIL(-800) after 60 s.Dwith patternP2(this is what vLLM does when it reuses the block).D. If any part of it readsP1again, the late READ overwrote a buffer the caller had already reused.Code path (tag v0.3.13.post1)
mooncake-store/src/transfer_task.cpp,TransferEngineOperationState::wait_for_completion():timeout_milliseconds = 60 * 1000. On timeout the polling branch callsset_result_internal(ErrorCode::TRANSFER_FAIL)and returns. The comment incheck_task_status()says it waits for all tasks to reach a terminal state so the caller does not see completion while background transfers are still running; the timeout branch bypasses that.mooncake-store/include/transfer_task.h:226:~TransferEngineOperationState() { engine_.freeBatchID(batch_id_); }ignores the return value.mooncake-transfer-engine/src/multi_transport.cpp:108,MultiTransport::freeBatchID(): returnsBatchBusyfor unfinished tasks without logging.mooncake-store/src/client_service.cpp,Client::BatchGet: waits on each future, then returns; keys that succeeded after the lease getLEASE_EXPIRED.MC_RETRY_CNT, default 9) to the samedest_addr;MC_SLICE_TIMEOUTis disabled by default.Related issues (searched before filing)
BatchDesc. It protects the engine's metadata, but as far as we can tell does not stop late completions from writing into the caller's buffers.Questions
TRANSFER_FAIL? For example, a distinct error code for "timed out, transfers may still be in flight", or an option to block until the batch drains.Client::BatchGet/batch_get_into_multi_buffers, not only the scatter API?roce_adp_retrans~850–1,400,implied_nak_seq_err~6,500–8,300,roce_adp_retrans_to1–2.rx_prio0_buf_discardis in the tens of millions since boot. The numbers are similar across nodes.We can share more log excerpts and our analysis scripts.
Before submitting...
@github-actions[bot] commented on GitHub (Oct 19, 2026):
Thanks for opening this issue, @ThisFat!
134714568A maintainer will triage this when possible. To help us respond faster, please include:
Useful links: Documentation · Contributing guide
@he-yufeng commented on GitHub (Oct 19, 2026):
Thanks for the unusually well-instrumented report — the matched cohort table (rescheduled 3.55% vs same-node baseline 0.17%, and the overlapping-prefill row at 0.85% that the scheduler never touched) is about as close to proof of stray writes as black-box evidence gets.
This is the read-side twin of #4491, which @apex-mochen is already working on for the engine half (dropping unposted slices of a timed-out batch so they can't land later). The read side needs the same discipline plus one extra step: when
wait_for_completion()gives up at the hard-coded 60 s, the batch is abandoned without cancel/drain,freeBatchID()fails silently, and the caller gets no signal that the destination buffers are still being written.TRANSFER_FAILis treated by callers (vLLM's connector here) as "buffers free to reuse", which is precisely the wrong contract while RDMA READs are still queued.For the fix shape I'd expect the engine half of #4491 to cover most of this: on timeout, drain or cancel the batch's remaining slices and only return failure once no worker can still touch the destinations; until that lands, a stopgap worth considering is logging the leftover-slice count when
freeBatchID()fails so the silent part at least becomes visible. #4580 (configurable wait timeout) reduces how often the path triggers but does not change the contract — the stray-write window exists at any timeout value.Tagging this for the transfer-engine owners; it belongs to the same fix arc as #4491 and #3792.