Make the host-side dispatch timeout self-attributing - #708
Conversation
The two host-side CPU-wait timeouts in csrc/legacy/buffer.hpp report the
symptom but not its origin. On a stall the only signal is a count of -1,
which says nothing about which counter never became ready, how long the
wait actually was, or where in the file the throw came from.
buffer.hpp:596 (intranode dispatch) is the worse of the two: it throws
"DeepEP error: CPU recv timeout" with no diagnostics at all -- no rank,
no counters, no elapsed time.
buffer.hpp:1105 (internode dispatch) prints the total and per-expert
counters, but the exception text itself carries nothing, so once the
printf output is separated from the exception (a common case with
multi-rank log interleaving, or when only the Python traceback is
captured) the attribution is lost.
Diagnostics only -- no behaviour change. Both sites now include, in the
exception text:
- the resolved source location via __FILE__ and __LINE__
- waited vs limit seconds
- rank and num_local_experts
- an explicit list of exactly which counters were still negative
(total / rdma / each per-expert index), or a note that all counters
were ready at throw time, which would indicate a race rather than a
stalled transport
The existing printf lines at the internode site are preserved verbatim,
and both error strings keep their original prefixes ("DeepEP error: CPU
recv timeout" and "DeepEP error: timeout (dispatch CPU)"), with the new
detail appended after. Downstream log scanners that match on those
prefixes keep matching; a silently blinded scanner would turn a real
timeout into a false pass, so that property was verified rather than
assumed.
Verification:
- The inserted logic was extracted verbatim and compiled standalone with
g++ -std=c++17 -Wall -Wextra: clean, no warnings.
- Ran it with a representative stall state (total=-1, rdma=-1, experts
{-1, 0, -1, 5}) and confirmed the message names experts 0 and 2 as
stalled while omitting the two that were ready.
- Log-scanner regression: the legacy "Global rank: ..." line, all four
per-expert lines, and the error-string prefix all still match their
original patterns; pre-patch logs from an existing failure also still
match the same scanner.
- Brace and paren balance re-checked across the file (197/197, 1378/1378).
- Added #include <string>, which was not previously included directly,
rather than relying on a transitive include for std::string and
std::to_string.
Motivation: on AWS EFA we hit this exact timeout across a batch of
384-expert runs. The failure turned out to be a build-configuration
regression in our own image, but the log could not have told us that --
recovering the cause needed source archaeology and a bisect against a
known-good image. With this patch the exception alone distinguishes "no
counter ever arrived" from "some experts arrived and others did not",
which separates a dead transport from a partial-routing problem.
Signed-off-by: Anton Alexander <dmvevents@gmail.com>
🤖 ds-review-bot Code Reviewv6新增诊断会并发读取持续由 GPU 更新的计数器，却未形成稳定快照，因此在关键的超时竞态场景下可能给出自相矛盾或错误归因的信息。 v4v7Diagnostics-only change to the two host-side CPU-wait timeouts in csrc/legacy/buffer.hpp (intranode dispatch ~L597, internode dispatch ~L1122). The intent is sound and the value is real: the intranode site previously threw a context-free string, and the internode site kept all of its context in printf output that is easily separated from the exception. What I confirmed statically: the timeout predicate is unchanged ( Two notes that need no action. First, the added What I could not re-execute: this environment restricts bash to git commands, so no compilation and no clang-format run were possible. The description's Files reviewed: 1 |
Review found a real defect in the first revision: the stall-attribution
string re-read the counters while building the message. They are
volatile int* and the GPU can publish a value between the timeout check
and the format, so the message could contradict the printf lines emitted
immediately above it, or list an already-ready counter as stalled.
Both sites now take a single snapshot -- total, rdma (internode only),
and a std::vector<int> of the per-expert counters -- and format
exclusively from that snapshot. The printf lines and the timeout
predicate are untouched.
Also from review:
- The all-ready branch previously read "all counters ready at throw time
-- suspect a race", which was self-contradictory in a message whose
purpose is to name what stalled. With a real snapshot the case has a
precise meaning, so it now says the GPU published between the timeout
check and the format.
- Split the two trailing explanation strings so no added line exceeds
ColumnLimit=140; the format gate was the realistic CI failure.
- Added <vector> for the snapshot.
Note on the earlier commit message: it framed the <string> include as
necessary. It is hygiene only -- exception.cuh already includes <string>
transitively. Recording that rather than leaving the overstatement.
Re-verified: the inserted logic was extracted verbatim with volatile
sources and compiled standalone under g++ -std=c++17 -Wall -Wextra,
clean; with the stall state {total=-1, rdma=-1, experts={-1,0,-1,5}} the
message names experts 0 and 2 and omits the two that were ready; no
added line exceeds 140 columns; brace/paren balance 197/197, 1382/1382.
Signed-off-by: Anton Alexander <dmvevents@gmail.com>
|
Thanks — the v6 finding is correct and I've fixed it in You're right that re-reading the counters while formatting is a real defect, and specifically in the scenario the patch exists to explain. They're Both sites now take a single snapshot — Also addressed from the inline comments:
Two I'm not changing, and why:
One correction to my own earlier commit message: it framed the Re-verified after the change: the inserted logic extracted verbatim with |
Review follow-ups on the remaining four threads: - The ~15 lines of stall-string construction duplicated at both throw sites are extracted into build_cpu_timeout_detail(), shared by the intranode and internode paths. This follows the precedent the review pointed at: the elastic path already centralizes its diagnostics in a get_buffer_info lambda (csrc/elastic/buffer.hpp:1045) and passes it to the throw. The intranode path passes rdma_snap=nullptr since it has no RDMA counter. - Both throws now use the repo's EPExceptionWithLineInfo, so __FILE__/__LINE__ are captured on the throw line itself. Previously __LINE__ expanded two lines below the actual throw (611 vs 609 intranode, 1142 vs 1140 internode). The exception type changes from std::runtime_error to EPException; both derive from std::exception and the elastic path already throws EPException through the same binding layer. The original prefixes are preserved verbatim as the exception name, so the message now reads e.g. "DeepEP error: CPU recv timeout exception (csrc/legacy/buffer.hpp:NNN): [intranode dispatch] rank=..." and scanners matching the old prefixes keep matching. - The all-counters-ready branch no longer contradicts itself. The trailing attribution is conditional: when the snapshot shows every counter ready the message says the timeout raced with a completion that landed just after the check, and the "GPU never published" claim is emitted only when something actually reads negative. Format gate (ColumnLimit thread): every added line is stable under the repo's clang-format 15.0.7 + .clang-format (running the format.sh clang-format step changes none of the added lines; the longest added line is 138 columns). Note the file as a whole does not round-trip clang-format cleanly even on upstream main (130+ reformat lines pre-existing), so this commit deliberately avoids introducing that whole-file churn. Verification: - g++ -std=c++17 -fsyntax-only over the full header with torch 2.10, CUDA, and NCCL-device include paths: clean. - clang-format 15.0.7 round-trip: zero changes within the added regions. - Behaviour unchanged: printf lines, timeout predicate, and snapshot semantics are exactly as in the previous commit; only the formatting of the exception text and its construction site moved. Signed-off-by: Anton Alexander <dmvevents@gmail.com>
2 participants
Problem
The two host-side CPU-wait timeouts in
csrc/legacy/buffer.hppreport the symptom but not its origin.buffer.hpp:596(intranode dispatch) throwsDeepEP error: CPU recv timeoutwith no diagnostics at all — no rank, no counters, no elapsed time.buffer.hpp:1105(internode dispatch) prints the total and per-expert counters, but the exception text itself carries nothing. Once theprintfoutput is separated from the exception — multi-rank log interleaving, or only the Python traceback captured — the attribution is gone. The single surviving signal is-1, which says nothing about which counter never arrived, how long the wait actually was, or where the throw came from.Change
Diagnostics only — no behaviour change. Both sites now carry, in the exception text:
__FILE__/__LINE__rankandnum_local_expertsThe existing
printflines at the internode site are preserved verbatim, and both error strings keep their original prefixes (DeepEP error: CPU recv timeout,DeepEP error: timeout (dispatch CPU)) with new detail appended after.Verification
g++ -std=c++17 -Wall -Wextra— clean, no warnings.{-1, 0, -1, 5}); the message names experts 0 and 2 as stalled and correctly omits the two that were ready.Global rank: …line, all per-expert lines, and both error-string prefixes still match their original patterns; pre-patch logs from a real failure also still match the same scanner. A silently blinded scanner would turn a real timeout into a false pass, so this was verified rather than assumed.#include <string>, which was not previously included directly, rather than relying on a transitive include forstd::string/std::to_string.Motivation
On AWS EFA we hit this exact timeout across a batch of 384-expert runs. The cause turned out to be a build-configuration regression in our own image — but the log could not have told us that; recovering it took source archaeology plus a bisect against a known-good image. With this patch the exception alone distinguishes "no counter ever arrived" (dead transport) from "some experts arrived and others did not" (partial routing), which is the first branch point in any such investigation.
Relation to #704
Complementary, non-overlapping. #704 makes the device-side low-latency
trap()self-attributing (the origin of a sticky CUDA 719) incsrc/kernels/legacy/internode_ll.cu. This PR does the host-side twin incsrc/legacy/buffer.hpp, where the CPU busy-wait throws. Different files, different failure paths — in our own logs a word-boundary search for719/LAUNCH_FAILED/cudaErrorLaunchFailurereturns zero, so our failures are purely the host-side path this PR covers. Both are needed for the same reason: today the error signal does not identify where it came from.