Always crashed when running rlvr_grpo_original_no_kl_batched_fsdp.py

[xyang2013]

System: 2 x 3090
Command line:
python rlvr_grpo_original_no_kl_batched_fsdp.py --num_gpus 2 --steps 500 --batch_size 1 --show_eta
Crashed at step 37:
[Step 37/500] loss=-0.0000 reward_avg=0.000 tokens_per_sec=76.3 avg_response_len=6.0

[rasbt]

Hm do you have an error message for this one or does it just hang?

[xyang2013]

It just hanged. I used both the previous and current versions. Both have the same issue. I also already set the batch size to 1. I think it is to do with memory based on nvtop plots. The 3090s are linked with NVLINK.

[rasbt]

I'll have to try it on other GPUs to see if that is hardware specific.

I wonder if you set the max length super high so that it would/could exceed the available memory, would it crash with a CUDA error or also hang?

[xyang2013]

The max_new_tokens is at default value - 512. Let me run it again to see if there is any error. In the log, there is no recorded exceptions.

[xyang2013]

Full log:

nohup: ignoring input
[rank1]:[E328 10:20:37.586787466 ProcessGroupNCCL.cpp:688] [Rank 1] Watchdog caught collective operation timeout: WorkNCCL(SeqNum=76, OpType=_REDUCE_SCATTER_BASE, NumelIn=751632384, NumelOut=375816192, Timeout(ms)=600000) ran for 600082 milliseconds before timing out.
[rank1]:[E328 10:20:37.586871104 ProcessGroupNCCL.cpp:2277] [PG ID 0 PG GUID 0(default_pg) Rank 1]  failure detected by watchdog at work sequence id: 76 PG status: last enqueued work: 76, last completed work: 75
[rank1]:[E328 10:20:37.586875785 ProcessGroupNCCL.cpp:735] Stack trace of the failed collective not found, potentially because FlightRecorder is disabled. You can enable it by setting TORCH_NCCL_TRACE_BUFFER_SIZE to a non-zero value.
[rank1]:[E328 10:20:37.586898208 ProcessGroupNCCL.cpp:2610] [PG ID 0 PG GUID 0(default_pg) Rank 1] First PG on this rank to signal dumping.
[rank1]:[E328 10:20:38.103319115 ProcessGroupNCCL.cpp:1890] [PG ID 0 PG GUID 0(default_pg) Rank 1] Received a dump signal due to a collective timeout from this local rank and we will try our best to dump the debug info. Last enqueued NCCL work: 76, last completed NCCL work: 75.This is most likely caused by incorrect usages of collectives, e.g., wrong sizes used across ranks, the order of collectives is not same for all ranks or the scheduled collective, for some reason, didn't run. Additionally, this can be caused by GIL deadlock or other reasons such as network errors or bugs in the communications library (e.g. NCCL), etc.
[rank1]:[E328 10:20:38.103480968 ProcessGroupNCCL.cpp:1606] [PG ID 0 PG GUID 0(default_pg) Rank 1] ProcessGroupNCCL preparing to dump debug info. Include stack trace: 1, only active collectives: 0
[rank1]:[E328 10:21:37.587011938 ProcessGroupNCCL.cpp:749] [Rank 1] Some NCCL operations have failed or timed out. Due to the asynchronous nature of CUDA kernels, subsequent GPU operations might run on corrupted/incomplete data.
[rank1]:[E328 10:21:37.587030810 ProcessGroupNCCL.cpp:763] [Rank 1] To avoid data inconsistency, we are taking the entire process down.
[rank1]:[E328 10:21:37.587604352 ProcessGroupNCCL.cpp:2093] [PG ID 0 PG GUID 0(default_pg) Rank 1] Process group watchdog thread terminated with exception: [Rank 1] Watchdog caught collective operation timeout: WorkNCCL(SeqNum=76, OpType=_REDUCE_SCATTER_BASE, NumelIn=751632384, NumelOut=375816192, Timeout(ms)=600000) ran for 600082 milliseconds before timing out.
Exception raised from checkTimeout at /pytorch/torch/csrc/distributed/c10d/ProcessGroupNCCL.cpp:691 (most recent call first):
frame #0: c10::Error::Error(c10::SourceLocation, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >) + 0x9d (0x74c4e6b72fdd in /home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/lib/libc10.so)
frame #1: c10d::ProcessGroupNCCL::WorkNCCL::checkTimeout(std::optional<std::chrono::duration<long, std::ratio<1l, 1000l> > >) + 0x26a (0x74c40174fd7a in /home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/lib/libtorch_cuda.so)
frame #2: c10d::ProcessGroupNCCL::Watchdog::runLoop() + 0x16a1 (0x74c401754261 in /home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/lib/libtorch_cuda.so)
frame #3: c10d::ProcessGroupNCCL::Watchdog::run() + 0x105 (0x74c4017555a5 in /home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/lib/libtorch_cuda.so)
frame #4: <unknown function> + 0xecdb4 (0x74c4e04ecdb4 in /lib/x86_64-linux-gnu/libstdc++.so.6)
frame #5: <unknown function> + 0x9caa4 (0x74c52209caa4 in /lib/x86_64-linux-gnu/libc.so.6)
frame #6: <unknown function> + 0x129c6c (0x74c522129c6c in /lib/x86_64-linux-gnu/libc.so.6)

terminate called after throwing an instance of 'c10::DistBackendError'
  what():  [PG ID 0 PG GUID 0(default_pg) Rank 1] Process group watchdog thread terminated with exception: [Rank 1] Watchdog caught collective operation timeout: WorkNCCL(SeqNum=76, OpType=_REDUCE_SCATTER_BASE, NumelIn=751632384, NumelOut=375816192, Timeout(ms)=600000) ran for 600082 milliseconds before timing out.
Exception raised from checkTimeout at /pytorch/torch/csrc/distributed/c10d/ProcessGroupNCCL.cpp:691 (most recent call first):
frame #0: c10::Error::Error(c10::SourceLocation, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >) + 0x9d (0x74c4e6b72fdd in /home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/lib/libc10.so)
frame #1: c10d::ProcessGroupNCCL::WorkNCCL::checkTimeout(std::optional<std::chrono::duration<long, std::ratio<1l, 1000l> > >) + 0x26a (0x74c40174fd7a in /home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/lib/libtorch_cuda.so)
frame #2: c10d::ProcessGroupNCCL::Watchdog::runLoop() + 0x16a1 (0x74c401754261 in /home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/lib/libtorch_cuda.so)
frame #3: c10d::ProcessGroupNCCL::Watchdog::run() + 0x105 (0x74c4017555a5 in /home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/lib/libtorch_cuda.so)
frame #4: <unknown function> + 0xecdb4 (0x74c4e04ecdb4 in /lib/x86_64-linux-gnu/libstdc++.so.6)
frame #5: <unknown function> + 0x9caa4 (0x74c52209caa4 in /lib/x86_64-linux-gnu/libc.so.6)
frame #6: <unknown function> + 0x129c6c (0x74c522129c6c in /lib/x86_64-linux-gnu/libc.so.6)

Exception raised from run at /pytorch/torch/csrc/distributed/c10d/ProcessGroupNCCL.cpp:2099 (most recent call first):
frame #0: c10::Error::Error(c10::SourceLocation, std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> >) + 0x9d (0x74c4e6b72fdd in /home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/lib/libc10.so)
frame #1: <unknown function> + 0x9bbbc8 (0x74c400fbbbc8 in /home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/lib/libtorch_cuda.so)
frame #2: <unknown function> + 0xecdb4 (0x74c4e04ecdb4 in /lib/x86_64-linux-gnu/libstdc++.so.6)
frame #3: <unknown function> + 0x9caa4 (0x74c52209caa4 in /lib/x86_64-linux-gnu/libc.so.6)
frame #4: <unknown function> + 0x129c6c (0x74c522129c6c in /lib/x86_64-linux-gnu/libc.so.6)

✓ qwen3/qwen3-0.6B-base.pth already up-to-date
[Step 1/500] loss=-0.0000 reward_avg=0.000 tok/sec=120.7 avg_resp_len=63.9 | ETA: 1h 10m 25s
[Step 2/500] loss=-0.0000 reward_avg=0.000 tok/sec=106.6 avg_resp_len=7.8 | ETA: 39m 58s
[Step 3/500] loss=-3.4438 reward_avg=0.125 tok/sec=150.1 avg_resp_len=69.8 | ETA: 47m 08s
[Step 4/500] loss=-0.0000 reward_avg=0.000 tok/sec=125.3 avg_resp_len=16.4 | ETA: 39m 36s
[Step 5/500] loss=-0.0000 reward_avg=0.000 tok/sec=83.3 avg_resp_len=7.0 | ETA: 33m 50s
[Step 6/500] loss=0.2267 reward_avg=0.125 tok/sec=83.0 avg_resp_len=6.0 | ETA: 29m 43s
[Step 7/500] loss=-0.0000 reward_avg=0.000 tok/sec=92.8 avg_resp_len=8.0 | ETA: 27m 03s
[Step 8/500] loss=-0.0000 reward_avg=0.000 tok/sec=96.8 avg_resp_len=7.0 | ETA: 24m 48s
[Step 9/500] loss=-0.0000 reward_avg=0.000 tok/sec=108.6 avg_resp_len=10.0 | ETA: 23m 20s
[Step 10/500] loss=-0.0000 reward_avg=0.000 tok/sec=101.3 avg_resp_len=8.6 | ETA: 22m 05s
[Step 11/500] loss=-0.0000 reward_avg=0.000 tok/sec=105.6 avg_resp_len=9.0 | ETA: 21m 02s
[Step 12/500] loss=-0.0000 reward_avg=0.000 tok/sec=91.7 avg_resp_len=6.1 | ETA: 19m 58s
[Step 13/500] loss=-0.0000 reward_avg=0.000 tok/sec=97.1 avg_resp_len=10.5 | ETA: 19m 29s
[Step 14/500] loss=-0.0000 reward_avg=0.000 tok/sec=91.2 avg_resp_len=6.0 | ETA: 18m 40s
[Step 15/500] loss=-0.0000 reward_avg=0.000 tok/sec=88.8 avg_resp_len=7.0 | ETA: 18m 03s
[Step 16/500] loss=-0.0000 reward_avg=0.000 tok/sec=117.4 avg_resp_len=15.0 | ETA: 17m 56s
[Step 17/500] loss=-0.0000 reward_avg=0.000 tok/sec=121.4 avg_resp_len=14.8 | ETA: 17m 45s
[Step 18/500] loss=-0.0000 reward_avg=1.000 tok/sec=91.7 avg_resp_len=6.0 | ETA: 17m 12s
[Step 19/500] loss=-0.0000 reward_avg=0.000 tok/sec=85.9 avg_resp_len=8.0 | ETA: 16m 54s
[Step 20/500] loss=-0.0000 reward_avg=0.000 tok/sec=157.7 avg_resp_len=234.5 | ETA: 25m 32s
[Step 21/500] loss=-0.6066 reward_avg=0.500 tok/sec=94.7 avg_resp_len=7.2 | ETA: 24m 44s
[Step 22/500] loss=-0.0000 reward_avg=0.000 tok/sec=93.9 avg_resp_len=6.4 | ETA: 23m 57s
[Step 23/500] loss=-0.7468 reward_avg=0.500 tok/sec=78.7 avg_resp_len=8.0 | ETA: 23m 25s
[Step 24/500] loss=-0.0000 reward_avg=0.000 tok/sec=91.3 avg_resp_len=6.1 | ETA: 22m 45s
[Step 25/500] loss=-0.0000 reward_avg=0.000 tok/sec=88.4 avg_resp_len=7.0 | ETA: 22m 12s
[Step 26/500] loss=-0.0000 reward_avg=0.000 tok/sec=49.1 avg_resp_len=7.2 | ETA: 22m 01s
[Step 27/500] loss=-0.9779 reward_avg=0.500 tok/sec=80.0 avg_resp_len=7.0 | ETA: 21m 34s
[Step 28/500] loss=-0.0178 reward_avg=0.125 tok/sec=93.7 avg_resp_len=7.0 | ETA: 21m 05s
[Step 29/500] loss=-0.0000 reward_avg=0.000 tok/sec=97.5 avg_resp_len=7.0 | ETA: 20m 38s
[Step 30/500] loss=-0.0000 reward_avg=0.000 tok/sec=106.8 avg_resp_len=9.0 | ETA: 20m 15s
[Step 31/500] loss=-0.0000 reward_avg=0.000 tok/sec=125.1 avg_resp_len=16.2 | ETA: 20m 05s
[Step 32/500] loss=-0.0000 reward_avg=0.000 tok/sec=73.1 avg_resp_len=6.1 | ETA: 19m 44s
[Step 33/500] loss=-0.0000 reward_avg=0.000 tok/sec=90.0 avg_resp_len=6.4 | ETA: 19m 22s
[Step 34/500] loss=-0.0000 reward_avg=0.000 tok/sec=88.5 avg_resp_len=8.0 | ETA: 19m 05s
[Step 35/500] loss=-0.0000 reward_avg=0.000 tok/sec=88.8 avg_resp_len=6.2 | ETA: 18m 45s
[Step 36/500] loss=-0.0000 reward_avg=0.000 tok/sec=91.1 avg_resp_len=7.0 | ETA: 18m 27s
[Step 37/500] loss=-0.0000 reward_avg=0.000 tok/sec=74.8 avg_resp_len=6.0 | ETA: 18m 11s
W0328 10:21:39.101000 92422 site-packages/torch/multiprocessing/spawn.py:165] Terminating process 92450 via signal SIGTERM
Traceback (most recent call last):
  File "/home/xiaoy/repos/reasoning-from-scratch/ch06/02_rlvr_grpo_scripts_intro/rlvr_grpo_original_no_kl_batched_fsdp_updated.py", line 571, in <module>
    mp.spawn(main_worker, args=(args.num_gpus, args), nprocs=args.num_gpus)
  File "/home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/multiprocessing/spawn.py", line 340, in spawn
    return start_processes(fn, args, nprocs, join, daemon, start_method="spawn")
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/multiprocessing/spawn.py", line 296, in start_processes
    while not context.join():
              ^^^^^^^^^^^^^^
  File "/home/xiaoy/miniconda3/envs/rfs/lib/python3.12/site-packages/torch/multiprocessing/spawn.py", line 192, in join
    raise ProcessExitedException(
torch.multiprocessing.spawn.ProcessExitedException: process 1 terminated with signal SIGABRT

[shaheennabi]

@xyang2013 Since there are no recorded exceptions before the timeout, I wonder if one rank is hanging during generation or reward computation rather than crashing. Did the rerun reproduce the issue, and if so, around the same step?