Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ray OOM causes the process to be killed #429

Closed
PKU-Fgx opened this issue Mar 1, 2025 · 23 comments
Closed

Ray OOM causes the process to be killed #429

PKU-Fgx opened this issue Mar 1, 2025 · 23 comments
Labels

Comments

@PKU-Fgx
Copy link

PKU-Fgx commented Mar 1, 2025

I found that as the training progressed, the System Memory Utilization (%) skyrocketed, and after a fixed point ray would report an out of memory error that would crash the training process.

  • Error

Image

  • System Memory Utilization (%)

Image

  • Script
set -x
MODEL_PATH=<local_path>
export VLLM_ATTENTION_BACKEND=XFORMERS
python3 -m verl.trainer.main_ppo \
    algorithm.adv_estimator=grpo \
    data.train_files=<local_path> \
    data.val_files=<local_path> \
    data.train_batch_size=64 \
    data.val_batch_size=64 \
    data.max_prompt_length=768 \
    data.max_response_length=3328 \
    actor_rollout_ref.model.path=$MODEL_PATH \
    actor_rollout_ref.actor.optim.lr=1e-6 \
    actor_rollout_ref.actor.ppo_mini_batch_size=64 \
    actor_rollout_ref.actor.ppo_max_token_len_per_gpu=12288 \
    actor_rollout_ref.actor.use_kl_loss=False \
    actor_rollout_ref.actor.kl_loss_coef=0. \
    actor_rollout_ref.actor.kl_loss_type=low_var_kl \
    actor_rollout_ref.actor.use_dynamic_bsz=True \
    actor_rollout_ref.actor.ulysses_sequence_parallel_size=1 \
    actor_rollout_ref.model.use_remove_padding=True \
    actor_rollout_ref.model.enable_gradient_checkpointing=True \
    actor_rollout_ref.actor.fsdp_config.param_offload=False \
    actor_rollout_ref.actor.fsdp_config.optimizer_offload=False \
    actor_rollout_ref.rollout.tensor_model_parallel_size=1 \
    actor_rollout_ref.rollout.name=vllm \
    actor_rollout_ref.rollout.temperature=1.0 \
    actor_rollout_ref.rollout.gpu_memory_utilization=0.72 \
    actor_rollout_ref.rollout.n=32 \
    actor_rollout_ref.rollout.log_prob_max_token_len_per_gpu=12288 \
    actor_rollout_ref.rollout.enforce_eager=False \
    actor_rollout_ref.rollout.free_cache_engine=False \
    actor_rollout_ref.ref.log_prob_max_token_len_per_gpu=12288 \
    actor_rollout_ref.ref.fsdp_config.param_offload=True \
    algorithm.kl_ctrl.kl_coef=0. \
    trainer.critic_warmup=0 \
    trainer.logger=['wandb'] \
    trainer.project_name=<wandb> \
    trainer.experiment_name=<wandb> \
    trainer.n_gpus_per_node=8 \
    trainer.nnodes=1 \
    trainer.default_local_dir=<local_path> \
    trainer.default_hdfs_dir=null \
    +trainer.val_before_train=False \
    trainer.save_freq=200 \
    trainer.test_freq=200 \
    trainer.total_epochs=3

Or is there some parameter I haven't configured correctly that is causing the memory usage to keep increasing?

@LinyeLi60
Copy link

same issue

@vermouth1992
Copy link
Collaborator

I suspect that this is memory leak when saving checkpoint.

@PKU-Fgx
Copy link
Author

PKU-Fgx commented Mar 3, 2025

I suspect that this is memory leak when saving checkpoint.

But I only saved the checkpoint once or twice during the training process, so if it's a checkpoint saving memory leak, then there shouldn't be a linear increase in memory usage before saving.

@vermouth1992
Copy link
Collaborator

Then, I highly doubt the reward function that you use have memory leak... Try to switch to dummy reward function to see if there is memory leak

@yushuiwx
Copy link

yushuiwx commented Mar 3, 2025

same issue,

Image

@kevin85421
Copy link
Collaborator

@PeterSH6 would you mind adding the label ray to the issue? Thanks!

@kevin85421
Copy link
Collaborator

@PKU-Fgx, this could be either a veRL issue, a Ray issue, or both. You can use jemalloc to profile it (see ray-project/ray#51031). If it turns out to be a Ray issue after you profile it, I'll take a look.

@PKU-Fgx
Copy link
Author

PKU-Fgx commented Mar 4, 2025

@PeterSH6 would you mind adding the label ray to the issue? Thanks!

Okay, I'll look into that in the next few days.

@hiyouga
Copy link
Collaborator

hiyouga commented Mar 4, 2025

Did you use vLLM 0.7+? It seems that the recent versions of vLLM are the cause of memory leak. You can try vllm 0.6.3

@NIL-zhuang
Copy link

NIL-zhuang commented Mar 4, 2025

same issue for vllm 0.7.3, i didn't save any checkpoint.

@LUMO666
Copy link

LUMO666 commented Mar 4, 2025

Did you use vLLM 0.7+? It seems that the recent versions of vLLM are the cause of memory leak. You can try vllm 0.6.3

same issue on 32B with 16 nodes. use vllm 0.6.3

@Skywuuuu
Copy link

Skywuuuu commented Mar 4, 2025

In my case, I set actor_rollout_ref.rollout.free_cache_engine=False to solve this problem. My vllm version is 0.6.3.

@PKU-Fgx
Copy link
Author

PKU-Fgx commented Mar 4, 2025

In my case, I set actor_rollout_ref.rollout.free_cache_engine=False to solve this problem. My vllm version is 0.6.3.

it does not work well for me, my version is 0.7.2

@PeterSH6 PeterSH6 added the ray label Mar 4, 2025
@yxliu0903
Copy link

In my case, I set actor_rollout_ref.rollout.free_cache_engine=False to solve this problem. My vllm version is 0.6.3.

it does not work well for me, my version is 0.6.3

@PKU-Fgx
Copy link
Author

PKU-Fgx commented Mar 5, 2025

@kevin85421 Hi!I‘ve generated some .heap memory snapshot file by using jemalloc, I'm wondering how I can characterize memory leaks from these heap files (sorry I know very little about this).

I apologize if these questions seem basic, and any insights you could offer would be incredibly helpful. Thank you so much for your time and expertise!

@wzq016
Copy link

wzq016 commented Mar 5, 2025

I encountered the same problem, which I feel is a vllm issue. Leakage at least happens in 0.7+ and 0.6.6.

In my case, the memory jump occurs at two places: generate_sequences and compute log_prob.

Image

I printed the cpu_memory, and I found that the vllm memory usage increases when _add_to_request is called, and llm_engine.step() does not cause memory gain. But after llm_engine.step(), the increased memory is not released.

I suspect the seq_group in vLLM is not corrected released.

Another finding is that a larger dataset causes more leakage (all other hyperparams are the same).

Image

Will keep updated when I have more progress.

@wzq016
Copy link

wzq016 commented Mar 5, 2025

@PKU-Fgx, this could be either a veRL issue, a Ray issue, or both. You can use jemalloc to profile it (see ray-project/ray#51031). If it turns out to be a Ray issue after you profile it, I'll take a look.

Hi, I follow the PR and here is what I get in the middle of training where leakage happens:

Argument "MSWin32" isn't numeric in numeric eq (==) at /usr/local/bin/jeprof line 5124.
Argument "linux" isn't numeric in numeric eq (==) at /usr/local/bin/jeprof line 5124.
Using local file jeprof.2790080.0.f.heap.
Total: 7.9 MB
     2.8  35.1%  35.1%      2.8  35.1% je_prof_backtrace
     1.3  16.6%  51.7%      1.3  16.6% grpc_core::Server::ChannelData::InitTransport
     1.0  12.8%  64.5%      1.0  12.8% ray::rpc::ServerCallFactoryImpl::CreateCall
     0.5   6.6%  71.0%      0.5   6.6% gpr_zalloc
     0.5   6.4%  77.5%      0.8   9.6% grpc_create_chttp2_transport
     0.5   6.3%  83.8%      0.5   6.3% std::string::_Rep::_S_create@@GLIBCXX_3.4
     0.3   3.2%  87.0%      0.4   4.8% grpc_tcp_create
     0.3   3.2%  90.1%      0.3   3.2% absl::lts_20230802::Cord::InlineRep::AppendArray
     0.1   1.9%  92.0%      0.1   1.9% grpc_core::Construct
     0.1   1.6%  93.7%      0.1   1.6% std::vector::reserve
     0.1   1.6%  95.2%      0.4   4.8% grpc_core::Channel::CreateWithBuilder
     0.1   1.6%  96.8%      0.3   3.2% grpc_core::MemoryQuota::CreateMemoryOwner
     0.1   1.6%  98.4%      0.1   1.6% std::__detail::_Map_base::operator[]
     0.1   1.6% 100.0%      0.1   1.6% opencensus::stats::ViewDescriptor::ViewDescriptor
     0.0   0.0% 100.0%      1.1  14.4% EventTracker::RecordExecution
     0.0   0.0% 100.0%      0.1   1.9% __libc_csu_init
     0.0   0.0% 100.0%      0.6   8.2% __libc_init_first@@GLIBC_2.2.5
     0.0   0.0% 100.0%      0.8  10.1% __libc_start_main@GLIBC_2.2.5
     0.0   0.0% 100.0%      0.8  10.1% _start
     0.0   0.0% 100.0%      0.1   1.6% absl::lts_20230802::Status::SetPayload
     0.0   0.0% 100.0%      0.1   1.6% absl::lts_20230802::Status::Status
     0.0   0.0% 100.0%      0.3   3.2% absl::lts_20230802::StrCat
     0.0   0.0% 100.0%      0.1   1.6% absl::lts_20230802::base_internal::CallOnceImpl
     0.0   0.0% 100.0%      0.1   1.6% absl::lts_20230802::base_internal::CallOnceImpl [clone .constprop.0]
     0.0   0.0% 100.0%      1.1  14.4% boost::asio::detail::completion_handler::do_complete
     0.0   0.0% 100.0%      1.3  16.0% boost::asio::detail::scheduler::do_run_one
     0.0   0.0% 100.0%      1.3  16.0% boost::asio::detail::scheduler::run
     0.0   0.0% 100.0%      0.1   1.6% boost::asio::detail::wait_handler::do_complete
     0.0   0.0% 100.0%      1.3  16.0% boost::asio::io_context::run
     0.0   0.0% 100.0%      6.0  75.6% cq_next
     0.0   0.0% 100.0%      6.0  75.6% end_worker
     0.0   0.0% 100.0%      1.3  16.0% execute_native_thread_routine
     0.0   0.0% 100.0%      0.1   1.6% fd_create
     0.0   0.0% 100.0%      0.1   1.6% google::protobuf::::AssignDescriptorsImpl
     0.0   0.0% 100.0%      0.1   1.6% google::protobuf::DescriptorBuilder::BuildFieldOrExtension
     0.0   0.0% 100.0%      0.1   1.6% google::protobuf::DescriptorBuilder::BuildFile
     0.0   0.0% 100.0%      0.1   1.6% google::protobuf::DescriptorBuilder::BuildFileImpl
     0.0   0.0% 100.0%      0.1   1.6% google::protobuf::DescriptorBuilder::BuildMessage [clone .localalias]
     0.0   0.0% 100.0%      0.1   1.6% google::protobuf::DescriptorPool::BuildFileFromDatabase
     0.0   0.0% 100.0%      0.1   1.6% google::protobuf::DescriptorPool::FindFileByName [clone .localalias]
     0.0   0.0% 100.0%      0.1   1.6% google::protobuf::DescriptorPool::TryFindFileInFallbackDatabase
     0.0   0.0% 100.0%      0.1   1.6% google::protobuf::DescriptorPool::generated_pool
     0.0   0.0% 100.0%      0.1   1.6% google::protobuf::internal::AssignDescriptors
     0.0   0.0% 100.0%      2.6  33.4% gpr_malloc
     0.0   0.0% 100.0%      2.3  28.7% gpr_malloc_aligned
     0.0   0.0% 100.0%      0.1   1.6% gpr_once_init
     0.0   0.0% 100.0%      0.1   1.6% gpr_strdup
     0.0   0.0% 100.0%      5.8  74.0% grpc::::CallbackAlternativeCQ::Ref::{lambda#1}::_FUN
     0.0   0.0% 100.0%      0.1   1.6% grpc::CompletionQueue::AsyncNextInternal
     0.0   0.0% 100.0%      0.1   1.6% grpc::ProtoServerReflection::ProtoServerReflection
     0.0   0.0% 100.0%      0.1   1.6% grpc::ServerBuilder::ServerBuilder
     0.0   0.0% 100.0%      0.1   1.6% grpc::reflection::CreateProtoReflection
     0.0   0.0% 100.0%      0.1   1.6% grpc::reflection::ProtoServerReflectionPlugin::ProtoServerReflectionPlugin
     0.0   0.0% 100.0%      0.1   1.6% grpc_auth_context::add_cstring_property
     0.0   0.0% 100.0%      2.3  28.7% grpc_call_create
     0.0   0.0% 100.0%      2.3  28.7% grpc_chttp2_parsing_accept_stream
     0.0   0.0% 100.0%      2.3  28.7% grpc_chttp2_perform_read
     0.0   0.0% 100.0%      0.3   3.2% grpc_chttp2_transport::grpc_chttp2_transport
     0.0   0.0% 100.0%      2.9  36.6% grpc_combiner_continue_exec_ctx
     0.0   0.0% 100.0%      2.4  31.0% grpc_core::::Chttp2ServerListener::ActiveConnection::HandshakingState::OnHandshakeDone
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::::Chttp2ServerListener::OnAccept
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::::MakeAuthContext
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::::SecurityHandshaker::CheckPeerLocked
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::::SecurityHandshaker::DoHandshake
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::::SecurityHandshaker::DoHandshakerNextLocked
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::::SecurityHandshaker::OnHandshakeNextDoneLocked
     0.0   0.0% 100.0%      5.8  74.0% grpc_core::::ThreadInternalsPosix::ThreadInternalsPosix::{lambda#1}::_FUN
     0.0   0.0% 100.0%      2.3  28.7% grpc_core::Arena::CreateWithAlloc
     0.0   0.0% 100.0%      0.4   4.8% grpc_core::Channel::Create
     0.0   0.0% 100.0%      0.3   3.2% grpc_core::ChannelStackBuilderImpl::Build
     0.0   0.0% 100.0%      6.0  75.6% grpc_core::ExecCtx::Flush
     0.0   0.0% 100.0%      0.1   1.7% grpc_core::Executor::InitAll
     0.0   0.0% 100.0%      0.1   1.7% grpc_core::Executor::SetThreading
     0.0   0.0% 100.0%      2.3  28.7% grpc_core::FilterStackCall::Create
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::HandshakeManager::CallNextHandshakerLocked
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::HandshakeManager::DoHandshake
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::InsecureChannelSecurityConnector::check_peer
     0.0   0.0% 100.0%      2.3  28.7% grpc_core::Server::ChannelData::AcceptStream
     0.0   0.0% 100.0%      1.7  21.4% grpc_core::Server::SetupTransport
     0.0   0.0% 100.0%      0.3   3.2% grpc_core::StatusAddChild
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::StatusCreate
     0.0   0.0% 100.0%      0.1   1.6% grpc_core::StatusSetInt
     0.0   0.0% 100.0%      0.1   1.6% grpc_error_set_int
     0.0   0.0% 100.0%      0.1   1.6% grpc_event_engine::experimental::MemoryAllocator::MakeSlice
     0.0   0.0% 100.0%      0.1   1.6% grpc_event_engine_init
     0.0   0.0% 100.0%      0.1   1.6% grpc_event_engine_init::{lambda#1}::_FUN
     0.0   0.0% 100.0%      0.3   3.4% grpc_init
     0.0   0.0% 100.0%      0.3   3.4% grpc_iomgr_init
     0.0   0.0% 100.0%      6.0  75.6% grpc_pollset_work
     0.0   0.0% 100.0%      0.4   4.8% grpc_status_create
     0.0   0.0% 100.0%      0.1   1.6% init_epoll1_linux
     0.0   0.0% 100.0%      2.3  28.7% init_header_frame_parser
     0.0   0.0% 100.0%      0.1   1.6% iomgr_platform_init
     0.0   0.0% 100.0%      2.8  35.1% je_malloc_default
     0.0   0.0% 100.0%      0.6   8.2% main
     0.0   0.0% 100.0%      7.1  89.9% modify_ldt@@GLIBC_2.2.5
     0.0   0.0% 100.0%      0.6   7.9% on_read
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::Delta::Record
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::DeltaProducer::ConsumeLastDelta
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::DeltaProducer::Flush
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::DeltaProducer::Record
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::DeltaProducer::RunHarvesterLoop
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::Record
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::StatsManager::AddConsumer
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::StatsManager::MeasureInformation::AddConsumer
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::StatsManager::MeasureInformation::MergeMeasureData
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::StatsManager::MergeDelta
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::StatsManager::ViewInformation::MergeMeasureData
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::StatsManager::ViewInformation::ViewInformation
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::View::View
     0.0   0.0% 100.0%      0.1   1.6% opencensus::stats::ViewDataImpl::Merge
     0.0   0.0% 100.0%      6.0  75.6% pollset_work@bdcaf0
     0.0   0.0% 100.0%      6.0  75.6% pollset_work@be2110
     0.0   0.0% 100.0%      7.1  89.9% pthread_condattr_setpshared@GLIBC_2.2.5
     0.0   0.0% 100.0%      0.1   1.6% ray::gcs::GcsServer::DoStart
     0.0   0.0% 100.0%      0.1   1.6% ray::gcs::GcsServer::GetOrGenerateClusterId::{lambda#1}::operator::{lambda#1}::operator
     0.0   0.0% 100.0%      0.1   1.6% ray::gcs::GcsServer::RecordMetrics
     0.0   0.0% 100.0%      0.1   1.6% ray::gcs::GcsTaskManager::RecordMetrics
     0.0   0.0% 100.0%      0.3   3.4% ray::rpc::ClientCallManager::ClientCallManager
     0.0   0.0% 100.0%      0.1   1.6% ray::rpc::ClientCallManager::PollEventsFromCompletionQueue
     0.0   0.0% 100.0%      0.1   1.6% ray::rpc::GrpcServer::Run
     0.0   0.0% 100.0%      0.3   3.4% ray::rpc::MetricsAgentClientImpl::MetricsAgentClientImpl
     0.0   0.0% 100.0%      1.0  12.8% ray::rpc::ServerCallImpl::HandleRequestImpl
     0.0   0.0% 100.0%      0.3   3.4% ray::stats::OpenCensusProtoExporter::OpenCensusProtoExporter
     0.0   0.0% 100.0%      0.3   3.4% ray::stats::OpenCensusProtoExporter::Register
     0.0   0.0% 100.0%      0.1   1.6% ray::stats::internal::RegisterAsView
     0.0   0.0% 100.0%      0.1   1.6% ray::stats::internal::RegisterView
     0.0   0.0% 100.0%      0.1   1.6% ray::stats::internal::Stats::Record
     0.0   0.0% 100.0%      0.1   1.6% ray::stats::internal::Stats::Stats::{lambda#1}::operator
     0.0   0.0% 100.0%      2.9  36.6% read_action_locked
     0.0   0.0% 100.0%      0.1   1.6% std::_Function_handler::_M_invoke@344e70
     0.0   0.0% 100.0%      0.1   1.6% std::_Function_handler::_M_invoke@41f5f0
     0.0   0.0% 100.0%      0.1   1.6% std::_Function_handler::_M_invoke@4258b0
     0.0   0.0% 100.0%      1.1  14.4% std::_Function_handler::_M_invoke@59d580
     0.0   0.0% 100.0%      0.3   3.2% std::basic_string::basic_string@@GLIBCXX_3.4
     0.0   0.0% 100.0%      0.3   3.2% std::string::_Rep::_M_clone@@GLIBCXX_3.4
     0.0   0.0% 100.0%      0.3   3.2% std::string::_S_construct@@GLIBCXX_3.4.14
     0.0   0.0% 100.0%      0.3   3.2% std::string::append@@GLIBCXX_3.4
     0.0   0.0% 100.0%      0.3   3.2% std::string::reserve@@GLIBCXX_3.4
     0.0   0.0% 100.0%      0.1   1.6% tcp_handle_read
     0.0   0.0% 100.0%      0.1   1.6% tcp_read

Is the file I get correct? All the memory usage is relatively small.

@kevin85421
Copy link
Collaborator

@PKU-Fgx, maybe you can profile Ray core worker processes and compare different memory dumps to see how much memory they contribute.

@kevin85421
Copy link
Collaborator

@wzq016 you profiles the GCS process. You can profile core worker processes.

@PKU-Fgx
Copy link
Author

PKU-Fgx commented Mar 6, 2025

@kevin85421 I think I have discovered a clue indicating a continuously increasing memory usage. I used jeprof to print memory snapshots of a specific Ray worker process at intervals i500, i1000, and i1900. I noticed that the memory usage of the function at address 0000000000506437 keeps increasing without being released. However, I am unsure how to trace back this hexadecimal address to identify the specific source of the memory leak. Could you share your thoughts or suggestions on this matter?

Image
Ray Work i500

Image
Ray Work i1000

Image
Ray Work i1900 (latest)

@hiyouga
Copy link
Collaborator

hiyouga commented Mar 6, 2025

@PKU-Fgx We have found this issue is caused by vllm-project/vllm#14326 and this PR could solve the memory leak problem

@PKU-Fgx
Copy link
Author

PKU-Fgx commented Mar 6, 2025

@hiyouga It works! So it's a vLLM problem, thanks a lot!

Image

@hiyouga
Copy link
Collaborator

hiyouga commented Mar 6, 2025

An example script to fix this problem:

export VLLM_COMMIT=227578480d71fc94ef46ca77fb69496412158d68
sudo pip install vllm --pre --extra-index-url https://wheels.vllm.ai/${VLLM_COMMIT}
git clone -b verl_v1 https://github.com/hiyouga/vllm.git
sudo cp -r vllm/vllm/ /usr/local/lib/python3.10/dist-packages/

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests