Ray在执行训练过程中频繁出现SYSTEM_ERROR_EXIT0

1 问题模板
【Ray使用环境】POC
【Ray版本和类库】1.13.0
【使用现场】
—32台 8卡 NVDIA A100服务器
—基于Ray执行多个torch的ddp训练
【问题复现】
—基于Ray执行多个torch的ddp训练,单个torch ddp训练规模在8GPU到64GPU之间
—出现的问题:在训练过程中,频繁出现worker died的问题 (SYSTEM_ERROR_EXIT错误)导致训练任务异常。具体的log如下:
GCS的log:
[2023-01-07 22:46:34,932 W 3044651 3044651] (gcs_server) gcs_worker_manager.cc:43: Reporting worker exit, worker id = d53f9f3a0ee328581f25f0528850156b577f5388eb8e9f8b0a19d708, node id = 912561135803f170492de14938e6bda6a0109004d512d93084d798d4, address = xxxxxxxxx, exit_type = SYSTEM_ERROR_EXIT0. Unintentional worker failures have been reported. If there are lots of this logs, that might indicate there are unexpected failures in the cluster.

相关的现象为:某一个计算节点上的全部worker会同时因为SYSTEM_ERROR_EXIT0而退出(但是节点上raylet是正常)。例如在32台·A100服务器上,可能在启动5小时后节点A上的全部worker因为SYSTEM_ERROR_EXIT0而退出 (进而导致上面的actor全部crash),但是节点上raylet是正常的。过了几个小时,另外一个节点也会出现同样的问题。

报错的Worker的日志如下:
[2023-01-07 22:46:34,756 I 20699 20793] direct_actor_task_submitter.cc:265: Failing pending tasks for actor 65ddfc5908f14c68ac5c9c9602000000 because the actor is already dead.
[2023-01-07 22:46:34,756 I 20699 20793] direct_actor_task_submitter.cc:283: Failing tasks waiting for death info, size=0, actor_id=65ddfc5908f14c68ac5c9c9602000000
[2023-01-07 22:46:34,756 I 20699 20793] task_manager.cc:419: Task failed: IOError: Fail all inflight tasks due to actor state change.: Type=ACTOR_TASK, Language=PYTHON, Resources: {}, function_descriptor={type=PythonFunctionDescriptor, module_name=xxxxx, class_name=_create_executable_class.._WrappedExecutable, function_name=xxxxxxx, function_hash=}, task_id=e178fb377578209565ddfc5908f14c68ac5c9c9602000000, task_name=x, job_id=02000000, num_args=2, num_returns=2, depth=0, xxxxxxxx, actor_task_spec={actor_id=65ddfc5908f14c68ac5c9c9602000000, actor_caller_id=ffffffffffffffff828e94ccc382067b56eb737702000000, actor_counter=0}, serialized_runtime_env={“envVars”: {“DEBUG_STORAGE”: “False”, “PYTHONPATH”: “xxxxxxx”, “STORAGE_CONCURRENCY”: “False”, “TRANSFER_VALUE”: “False”}}, runtime_env_eager_install=0
[2023-01-07 22:46:34,881 C 20699 20699] direct_actor_transport.cc:163: Check failed: objects_valid 0 1
*** StackTrace Information ***
ray::SpdLogMessage::Flush()
ray::RayLog::~RayLog()
ray::core::CoreWorkerDirectTaskReceiver::HandleTask()::{lambda()#1}::operator()()
std::_Function_handler<>::_M_invoke()
ray::core::InboundRequest::Accept()
ray::core::ActorSchedulingQueue::ScheduleRequests()
ray::core::ActorSchedulingQueue::Add()
ray::core::CoreWorkerDirectTaskReceiver::HandleTask()
std::_Function_handler<>::_M_invoke()
EventTracker::RecordExecution()
std::_Function_handler<>::_M_invoke()
boost::asio::detail::completion_handler<>::do_complete()
boost::asio::detail::scheduler::do_run_one()
boost::asio::detail::scheduler::run()
boost::asio::io_context::run()
ray::core::CoreWorker::RunTaskExecutionLoop()
ray::core::CoreWorkerProcessImpl::RunWorkerTaskExecutionLoop()
ray::core::CoreWorkerProcess::RunTaskExecutionLoop()
__pyx_pw_3ray_7_raylet_10CoreWorker_7run_task_loop()
method_vectorcall_NOARGS

比较关键的异常是 Check failed: objects_valid 0 1,在社区看到一个类似的issue,大体上看起来跟fork进程有关系。在ray worker中fork进程其实是非常容易出问题的,因为ray worker底层会有集群的grpc连接和runtime context,fork后的进程很容易把runtime搞乱。
@sunpengsdu 目前想确定一下:1、能否确定下ray worker fork了哪些进程?torch这块儿逻辑是你们自己集成的还是直接用了ray train。2、能否确定下最新版本的ray 2.2.0是否有相同的问题?3、能否提供更详细的节点日志看下?

  1. 你代码里面有用到 ray client 么?
  2. 你能在日志中找到类似 no attritube “core_worker” 这样的 python 层的 exception 么?
  3. 发现 2 所说的日志的那个进程是 ray server 进程么?

如果你这三个问题都是 yes 的话,那我九成确定这个是一个已知问题,在于 ray client/server 的设定:

  1. ray server 进程上会维护一个引用,这个引用的意思是说有多少个 client 链接上来了,不管什么情况 client 断链了,这个引用都会减1
  2. 引用为 0 了,ray server 会直接 shutdown,在 shutdown 之后 task 结束就会吃这个 ray check

我是楼主的同事,给您答复一下。

  1. ray worker是一个自定义的训练过程,使用了一些torch的包,比如dataloader,dataloader会fork子进程,但模型是自己的,具体需要请教模型侧得同时,我不清楚,没有使用ray train。2、ray 2.0+版本在我们的环境频繁出现掉节点的问题,所以我们回退到了ray 1.13.0。3. 测试是开启了ray log level为debug,有点大38G,目前我们分析日志,能看出的特征是,在故障时刻,python层报worker died,但没有明显的worker错误栈,只能看出ray.get的结果是错误的,core-worker报summit task failed due to network error,rpc error: socket colsed,actor state DEAD;另外查询node stat的组件会报查询node节点失败,error updating node stats of xxxx, 错误代码 reply = await stub.GetNodeStats , status = StatusCode.DEADLINE_EXCEEDED,但在故障时刻,raylet.out并没有触发明显的错误,只有关于disconnectClient的报错,我们看了worker manger相关代码,确定不是reylet主动清理的worker,应为worker没有收到SIGTERM(我们在worker注册了相关handler)也worker manager 也没有执行kill_worker(with SIGKILL),因为日志没有KILL的相关日志,所以初步判断disconnectClient的响应性的。目前唯一的特征是所有died的worker都属于一个节点,但没有任务具体的报错栈和明显的ray日志,我们自己的初步研判是check failed: object_vaild 0 1,是次生的报错,由于网络问题,不是原生的报错。

目前我们已经解决的是一个 ray client-server 导致的 check failed: object_vaild 0 1,看起来你们应该不是这种

我觉得你们大概率是 @SongGuyang 所提到的这个 fork 进程导致的,我们的实践中对于 fork 还是比较谨慎的,暂时没有遇到过,貌似社区那个 issue 本地还比较好复现,这几天我有空也跟着研究一下

目前我们看到的actor里出现fork是在dataloader那里,之前我们遇见过torch dataloader因为多层fork导致的一些问题,后面解决了dataloader代码里嵌套fork后,dataloader就没有再出现问题。虽然我们也知道在ray worker中fork进程非常容易出问题,但是torch daraloader本身的工作机制就是靠的多进程,在ray train的example代码里,也是跑原始的torch dataloader

https://github.com/ray-project/ray/blob/b44f5cd8a7d7ffdcac28a29764f866a36f00d52d/python/ray/train/examples/pytorch/torch_fashion_mnist_example.py#L98

也就是说如果这么包装train_func的话,dataloader的fork/spawn是不可避免的。

1 个赞

@sunpengsdu 我们研究了一下,根因是这样的,actor 进程在 fork 的时候,子进程上的 rpc client 和父进程的 rpc client 监听了相同的端口,导致 rpc request 发到哪个进程变得无法控制:

这个应该是一个 ray 的 bug,可能的解决方案是弄个 fork hook,把子进程上继承来的句柄删掉。

1 个赞

我们在社区讨论下解法。

@sunpengsdu @mwiacx 你们目前什么状态?我们最近有些发现,ray处理task异常的时候没有处理BaseException,会导致你们遇到的这个报错。我在社区提了pr [core][bugfix] catch BaseException by SongGuyang · Pull Request #32105 · ray-project/ray · GitHub

我想确认下,你们这个case,会不会是task里抛了BaseException异常(或者什么异常直接继承了BaseException)。如果是这个原因就比较好修复。

我们在尝试ray2.2.0版本是否更加稳定,在单节点上跑简化版vit一周时间,1.13出现了一次掉节点,一次rpc timeout,2.20则可以稳定训练,但是目前在多节点版本也遇见了如下问题Log monitor 报错 FileNotFound