mirror of
https://github.com/deepseek-ai/DeepEP.git
synced 2026-11-05 00:47:32 +00:00
[GH-ISSUE #138] The first call to dispatch after a short period has high latency. #121
Labels
No labels
pull-request
No milestone
No project
No assignees
1 participant
Notifications
Due date
No due date set.
Dependencies
No dependencies set.
Reference
deepseek-ai/DeepEP#121
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 @TheRainstorm on GitHub (Apr 27, 2025).
Original GitHub issue: https://github.com/deepseek-ai/DeepEP/issues/138
Dear developers, thank you for your open-source project. Our project uses DeepEP to implement dispatch and combine in FFN. Currently, there is no overlap between computation and communication latency, so dispatch latency is quite important. However, I encountered an issue with high dispatch latency when using DeepEP.
Test environment
The result of
tests/test_intranode.pyThe result of
tests/test_internode.pyproblem
We have slightly modified the code in tests/test_intranode.py to test the latency of consecutive dispatch calls. The code is as follows:
dispatch_timesrecords the latency of ten consecutive dispatch calls.loop_outsideis in the outermost loop and controls whether to insert a 100ms sleep between each dispatch call. Through experiments, we found that if we sleep for 100ms between each dispatch call, the dispatch latency becomes very high. The results are as follows:It can be seen that except for the very first dispatch in the entire program which has a latency of 1-2ms, subsequent dispatch calls made every 100ms have a latency of approximately 400us, while completely consecutive dispatch calls have a latency of 70us. The maximum sleep interval that keeps the latency at 70us is 49ms (at 50ms it becomes 400us).
Similar phenomena are observed on test_internode. The latency of the first dispatch call is 2-3 times higher than that of consecutive calls. In our application scenario, there are other operations between two dispatches, so we are experiencing the higher latency result each time.
We would appreciate your guidance on the possible reasons for this phenomenon, such as whether network card configuration is involved, and any recommendations for debugging.
@LyricZhao commented on GitHub (Apr 27, 2025):
A tip for debugging such things would be aligning the timeline (wall time) of profiling results.
The kernel only spends more time on unbalanced GPU launch time, so you better check whether, e.g.
time.sleep(0.1)is accurate for all ranks, or something else making the start time of kernels unaligned.Or maybe add a
dist.all_reducebefore the first launch.@TheRainstorm commented on GitHub (Apr 27, 2025):
Thank you for your quick reply. I tried synchronizing using all_reduce before each dispatch measurement, but the phenomenon described above still exists. My main code is as below (modified in
tests/test_intranode.py):@LyricZhao commented on GitHub (Apr 28, 2025):
After
dist.all_reduce(tensor, op=dist.ReduceOp.SUM), you should call CUDA synchronize, as you are couting the CPU time.@LyricZhao commented on GitHub (Apr 28, 2025):
I highly recommend you to count the GPU time using CUDA event or CUPTI (PyTorch profiler), but not
time.perf_counter. The current code snippet is only counting the dispatch barrier (notify_dispatch) time (including a CPU sync) + dispatch kernel launch time.@TheRainstorm commented on GitHub (Apr 28, 2025):
Thank you for pointing out my mistake. I went back to review the relevant knowledge and found a very good article introducing how to precisely time CUDA kernels.
This is my modified code:
This is the result after my modification. Surprisingly, there is almost no difference compared to before. Is it possible that dispatch already implements synchronization between the CPU and GPU? The new results still have the issues mentioned above.
@LyricZhao commented on GitHub (Apr 28, 2025):
Dispatch has two stages:
notify_dispatchanddispatchitself, the first one have synchronization.How about:
After all, my debugging experience is: the kernel only spends more time on unbalanced GPU launch time. If the problem still exists, I guess you should dump the profiling timeline.
@TheRainstorm commented on GitHub (Apr 28, 2025):
The problem still exists, I will profling with Nsight. Thank you for your help.
@cataluna84 commented on GitHub (Apr 28, 2025):
@TheRainstorm Maybe, the first loop's latency is because of the warmup steps, which are kinda required for these distributed systems. You could do a trial run with a simple warmup step in a dummy tensor loop and see the results.
For the consecutive steps, maybe the gradient accumulation is kinda paused as the electricity consumption fluctuates when not under load, as it happens with a single GPU. I am just speculating, we need to look at the profiler, but does the 100ms delay achieves higher accuracy?
@TheRainstorm commented on GitHub (Apr 29, 2025):
I profiled the program using nsys and found that the issue is in
notify_dispatch. When run pythondispatchwith an interval of 50 ms between calls,notify_dispatchtakes approximately 200us. However, when run python dispatch function continuously, the time fornotify_dispatchis very small, less than 20us.Therefore, When the number of tokens is small, such as only 8 tokens per rank, the dispatch time is only 90us(I test in intranode), which makes
notify_dispatcha bottleneck. When the number of tokens is 4096 per rank, thedispatchtime is 470us, and the 200us fornotify_dispatchstill leads to significantly worse results.Do you know why the
notify_dispatchtime changes even though the input hasn't changed?@terminator123 commented on GitHub (Oct 16, 2025):
have you resolved the problem ?
@TheRainstorm commented on GitHub (Nov 6, 2025):
This might not be an actual issue, as my previous testing methodology was flawed.
As LyricZhao pointed out, the dispatch interface internally consists of two phases: notify_dispatch and dispatch. The former phase acts as a synchronization point for all GPUs. Consequently, with a mix of faster and slower GPUs, the notify_dispatch duration can become significantly long, as it must wait for the slowest GPU to reach this synchronization point.
The "dispatch time" I was measuring was actually the combined duration of notify_dispatch + dispatch on a single GPU. By introducing a sleep call, I caused the GPUs to arrive at the sync point at different times, which in turn inflated the notify_dispatch time.
In summary, the root of the problem was my misunderstanding of what the dispatch time from the Python interface truly represents.