[GH-ISSUE #277] Run vLLM + DeepSeekR1 + Mooncakestore failed in single node 8 gpu, show local access violation work queue error for context mlx5_0 #109

Closed
opened 2026-10-29 21:09:26 +00:00 by bsakaguchi · 27 comments
Owner

Originally created by @maobaolong on GitHub (Apr 19, 2025).
Original GitHub issue: https://github.com/kvcache-ai/Mooncake/issues/277

Following is my config and log。 there are 2TB memory in my node, I specific 100G memory for each vllmWorker , and there are 8 in all, it can be verified by top command.

Image
  • mooncake.json
{
    "local_hostname": "localhost",
    "metadata_server": "etcd://192.168.100.219:2379",
    "protocol": "rdma",
    "device_name": "mlx5_0",
    "global_segment_size": 100545855488,
    "master_server_address": "192.168.100.219:50051"
}
  • vllm.log
I0419 19:17:25.257993 98020 common.h:153] writeString: type 0, str(123): {"local_nic_path":"localhost:12570@mlx5_0","peer_nic_path":"localhost:14121@mlx5_0","qp_num":[11250,11256],"reply_msg":""}
I0419 19:17:25.259255 98307 common.h:153] writeString: type 0, str(123): {"local_nic_path":"localhost:12340@mlx5_0","peer_nic_path":"localhost:13882@mlx5_0","qp_num":[11233,11239],"reply_msg":""}
I0419 19:17:25.260203 97975 common.h:153] writeString: type 0, str(123): {"local_nic_path":"localhost:13882@mlx5_0","peer_nic_path":"localhost:12340@mlx5_0","qp_num":[11259,11261],"reply_msg":""}
W0419 19:17:25.260430 97620 worker_pool.cpp:368] Worker: Received context async event local access violation work queue error for context mlx5_0
I0419 19:17:25.260478 98301 common.h:153] writeString: type 0, str(123): {"local_nic_path":"localhost:14121@mlx5_0","peer_nic_path":"localhost:12343@mlx5_0","qp_num":[11260,11263],"reply_msg":""}
W0419 19:17:25.261195 98302 worker_pool.cpp:368] Worker: Received context async event local access violation work queue error for context mlx5_0
W0419 19:17:25.261330 98302 worker_pool.cpp:368] Worker: Received context async event local access violation work queue error for context mlx5_0
E0419 19:17:25.261432 97613 worker_pool.cpp:260] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff581300000, length: 65536, dest_addr: 140591865266176, local_nic: mlx5_0, peer_nic: localhost:13556@mlx5_0, dest_rkey: 121583, retry_cnt: 0): Work Request Flushed Error
E0419 19:17:25.262290 98296 worker_pool.cpp:260] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff586000000, length: 65536, dest_addr: 140588892553216, local_nic: mlx5_0, peer_nic: localhost:14121@mlx5_0, dest_rkey: 101357, retry_cnt: 0): remote invalid request error

This is the log of mooncake master, there are still put get related logs,but allocate failed log appeared eventually.

Image
Originally created by @maobaolong on GitHub (Apr 19, 2025). Original GitHub issue: https://github.com/kvcache-ai/Mooncake/issues/277 Following is my config and log。 there are 2TB memory in my node, I specific 100G memory for each vllmWorker , and there are 8 in all, it can be verified by top command. <img width="1431" alt="Image" src="https://github.com/user-attachments/assets/a870b62d-9c99-4d0a-922d-fb3271d86412" /> - mooncake.json ```json { "local_hostname": "localhost", "metadata_server": "etcd://192.168.100.219:2379", "protocol": "rdma", "device_name": "mlx5_0", "global_segment_size": 100545855488, "master_server_address": "192.168.100.219:50051" } ``` - vllm.log ``` I0419 19:17:25.257993 98020 common.h:153] writeString: type 0, str(123): {"local_nic_path":"localhost:12570@mlx5_0","peer_nic_path":"localhost:14121@mlx5_0","qp_num":[11250,11256],"reply_msg":""} I0419 19:17:25.259255 98307 common.h:153] writeString: type 0, str(123): {"local_nic_path":"localhost:12340@mlx5_0","peer_nic_path":"localhost:13882@mlx5_0","qp_num":[11233,11239],"reply_msg":""} I0419 19:17:25.260203 97975 common.h:153] writeString: type 0, str(123): {"local_nic_path":"localhost:13882@mlx5_0","peer_nic_path":"localhost:12340@mlx5_0","qp_num":[11259,11261],"reply_msg":""} W0419 19:17:25.260430 97620 worker_pool.cpp:368] Worker: Received context async event local access violation work queue error for context mlx5_0 I0419 19:17:25.260478 98301 common.h:153] writeString: type 0, str(123): {"local_nic_path":"localhost:14121@mlx5_0","peer_nic_path":"localhost:12343@mlx5_0","qp_num":[11260,11263],"reply_msg":""} W0419 19:17:25.261195 98302 worker_pool.cpp:368] Worker: Received context async event local access violation work queue error for context mlx5_0 W0419 19:17:25.261330 98302 worker_pool.cpp:368] Worker: Received context async event local access violation work queue error for context mlx5_0 E0419 19:17:25.261432 97613 worker_pool.cpp:260] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff581300000, length: 65536, dest_addr: 140591865266176, local_nic: mlx5_0, peer_nic: localhost:13556@mlx5_0, dest_rkey: 121583, retry_cnt: 0): Work Request Flushed Error E0419 19:17:25.262290 98296 worker_pool.cpp:260] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff586000000, length: 65536, dest_addr: 140588892553216, local_nic: mlx5_0, peer_nic: localhost:14121@mlx5_0, dest_rkey: 101357, retry_cnt: 0): remote invalid request error ``` This is the log of mooncake master, there are still put get related logs,but allocate failed log appeared eventually. <img width="808" alt="Image" src="https://github.com/user-attachments/assets/5abaa9bf-f61e-4c1c-abc7-8a591dd97ea8" />
Author
Owner

@maobaolong commented on GitHub (Apr 19, 2025):

@ShangmingCai 感谢之前的帮助,我们现在 tcp 模式可以运行了,接下来在使用 rdma 模式时,遇到了这个错误,请帮忙看看是什么原因,多谢

<!-- gh-comment-id:2816667880 --> @maobaolong commented on GitHub (Apr 19, 2025): @ShangmingCai 感谢之前的帮助,我们现在 tcp 模式可以运行了,接下来在使用 rdma 模式时,遇到了这个错误,请帮忙看看是什么原因,多谢
Author
Owner

@ShangmingCai commented on GitHub (Apr 19, 2025):

@xiaguan Can you help with this?

<!-- gh-comment-id:2816687645 --> @ShangmingCai commented on GitHub (Apr 19, 2025): @xiaguan Can you help with this?
Author
Owner

@ShangmingCai commented on GitHub (Apr 19, 2025):

BTW, which whl version are you using? We have released the 0.3.0b5 today, can you try it to see if this problem persist?

<!-- gh-comment-id:2816688457 --> @ShangmingCai commented on GitHub (Apr 19, 2025): BTW, which whl version are you using? We have released the 0.3.0b5 today, can you try it to see if this problem persist?
Author
Owner

@xiaguan commented on GitHub (Apr 19, 2025):

Do you enable master's gc?
Error occurs in get or put? Thx

<!-- gh-comment-id:2816697621 --> @xiaguan commented on GitHub (Apr 19, 2025): Do you enable master's gc? Error occurs in get or put? Thx
Author
Owner

@maobaolong commented on GitHub (Apr 19, 2025):

@ShangmingCai Will try it soon, thanks for your help.

<!-- gh-comment-id:2816703796 --> @maobaolong commented on GitHub (Apr 19, 2025): @ShangmingCai Will try it soon, thanks for your help.
Author
Owner

@maobaolong commented on GitHub (Apr 19, 2025):

@xiaguan I run mooncake master by /usr/local/lib/python3.12/dist-packages/mooncake/mooncake_master -max_threads 64 -v=1

And it displayed like following, so i guess it means gc disabled by default?

WARNING: Logging before InitGoogleLogging() is written to STDERR
I0419 20:10:13.173349  3416 master.cpp:27] Master service started on port 50051, enable_gc=0, max_threads=64
I0419 20:10:13.174883  3416 master_service.cpp:77] action=gc_disabled

Error occurs in get or put?
I guess it caused by put, since it displayed allocation failed.

<!-- gh-comment-id:2816706334 --> @maobaolong commented on GitHub (Apr 19, 2025): @xiaguan I run mooncake master by `/usr/local/lib/python3.12/dist-packages/mooncake/mooncake_master -max_threads 64 -v=1` And it displayed like following, so i guess it means gc disabled by default? ``` WARNING: Logging before InitGoogleLogging() is written to STDERR I0419 20:10:13.173349 3416 master.cpp:27] Master service started on port 50051, enable_gc=0, max_threads=64 I0419 20:10:13.174883 3416 master_service.cpp:77] action=gc_disabled ``` > Error occurs in get or put? I guess it caused by `put`, since it displayed `allocation failed`.
Author
Owner

@xiaguan commented on GitHub (Apr 19, 2025):

You could try to turn it on

<!-- gh-comment-id:2816707386 --> @xiaguan commented on GitHub (Apr 19, 2025): You could try to turn it on
Author
Owner

@maobaolong commented on GitHub (Apr 19, 2025):

@xiaguan Oh, thanks, I'm trying the newest mooncake pip package and re-run my test by enable the gc of master. Thanks for your tips.

But is the worker_pool.cpp:368] Worker: Received context async event local access violation work queue error for context mlx5_0 caused by disabled gc ?

<!-- gh-comment-id:2816708804 --> @maobaolong commented on GitHub (Apr 19, 2025): @xiaguan Oh, thanks, I'm trying the newest mooncake pip package and re-run my test by enable the gc of master. Thanks for your tips. But is the ` worker_pool.cpp:368] Worker: Received context async event local access violation work queue error for context mlx5_0` caused by disabled gc ?
Author
Owner

@xiaguan commented on GitHub (Apr 19, 2025):

no it solves the allocation error

The work queue error seems strange, will figure it out later

<!-- gh-comment-id:2816714677 --> @xiaguan commented on GitHub (Apr 19, 2025): no it solves the allocation error The work queue error seems strange, will figure it out later
Author
Owner

@maobaolong commented on GitHub (Apr 19, 2025):

This is a new try. I use the newest version of mooncake 0.3.0b5 for mooncake-master and vllm. and enabled the gc.

Image
INFO 04-19 23:51:44 [engine.py:310] Added request chatcmpl-77010a03977c41c484c87c88abd9569f.
I0419 23:51:51.054445 114308 rdma_endpoint.cpp:108] Connection has been established
I0419 23:51:51.060045 114298 rdma_endpoint.cpp:108] Connection has been established
I0419 23:51:51.066856 114156 rdma_endpoint.cpp:108] Connection has been established
I0419 23:51:51.067245 114311 rdma_endpoint.cpp:108] Connection has been established
I0419 23:51:51.067374 114299 rdma_endpoint.cpp:108] Connection has been established
W0419 23:51:51.067479 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
I0419 23:51:51.068233 114312 endpoint_store.cpp:135] Endpoint localhost:13347@mlx5_0 already exists in SIEVEEndpointStore
I0419 23:51:51.069422 114312 rdma_endpoint.cpp:108] Connection has been established
W0419 23:51:51.070123 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
W0419 23:51:51.070240 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
E0419 23:51:51.071314 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cc000000, length: 65536, dest_addr: 140611776675840, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error
W0419 23:51:51.072116 113629 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
W0419 23:51:51.073052 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
W0419 23:51:51.073107 114305 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
E0419 23:51:51.073233 114156 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff59e000000, length: 65536, dest_addr: 140611877339136, local_nic: mlx5_0, peer_nic: localhost:13048@mlx5_0, dest_rkey: 148283, retry_cnt: 0): remote invalid request error
E0419 23:51:51.073930 114307 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57c000000, length: 65536, dest_addr: 140611910893568, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 0): remote invalid request error
W0419 23:51:51.074009 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
E0419 23:51:51.074743 114311 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57e000000, length: 65536, dest_addr: 140611541794816, local_nic: mlx5_0, peer_nic: localhost:13018@mlx5_0, dest_rkey: 137784, retry_cnt: 0): remote invalid request error
E0419 23:51:51.076172 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cb000000, length: 65536, dest_addr: 140611759898624, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error
E0419 23:51:51.077553 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cf000000, length: 65536, dest_addr: 140611877339136, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 0): remote invalid request error
E0419 23:51:51.079274 114311 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff584000000, length: 65536, dest_addr: 140611927670784, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error
I0419 23:51:51.098073 114295 rdma_endpoint.cpp:108] Connection has been established
W0419 23:51:51.111217 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
E0419 23:51:51.139672 114307 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57c150000, length: 65536, dest_addr: 140611912269824, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 1): remote invalid request error

There are no allocation failed in the master.log, but the above error still in vllm.log. And the test result shown that the performance is poorer than tcp mode, it is strange, maybe related to the above error.

And is there any fallback logic in mooncake? I guess maybe the communicate mode have fallbacked to tcp ?

Checked by

I0419 21:36:24.247948  3554 master.cpp:27] Master service started on port 50051, enable_gc=1, max_threads=64
I0419 21:36:24.249773  3554 master_service.cpp:75] action=start_gc_thread
I0419 21:36:24.249786  3562 master_service.cpp:332] action=gc_thread_started

and

# pip show mooncake-transfer-engineName: mooncake-transfer-engine
Version: 0.3.0b5
<!-- gh-comment-id:2816717526 --> @maobaolong commented on GitHub (Apr 19, 2025): This is a new try. I use the newest version of mooncake `0.3.0b5` for mooncake-master and vllm. and enabled the gc. <img width="1378" alt="Image" src="https://github.com/user-attachments/assets/b359cb72-bd53-46f1-876c-d0af9802f76d" /> ``` INFO 04-19 23:51:44 [engine.py:310] Added request chatcmpl-77010a03977c41c484c87c88abd9569f. I0419 23:51:51.054445 114308 rdma_endpoint.cpp:108] Connection has been established I0419 23:51:51.060045 114298 rdma_endpoint.cpp:108] Connection has been established I0419 23:51:51.066856 114156 rdma_endpoint.cpp:108] Connection has been established I0419 23:51:51.067245 114311 rdma_endpoint.cpp:108] Connection has been established I0419 23:51:51.067374 114299 rdma_endpoint.cpp:108] Connection has been established W0419 23:51:51.067479 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 I0419 23:51:51.068233 114312 endpoint_store.cpp:135] Endpoint localhost:13347@mlx5_0 already exists in SIEVEEndpointStore I0419 23:51:51.069422 114312 rdma_endpoint.cpp:108] Connection has been established W0419 23:51:51.070123 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 W0419 23:51:51.070240 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 E0419 23:51:51.071314 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cc000000, length: 65536, dest_addr: 140611776675840, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error W0419 23:51:51.072116 113629 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 W0419 23:51:51.073052 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 W0419 23:51:51.073107 114305 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 E0419 23:51:51.073233 114156 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff59e000000, length: 65536, dest_addr: 140611877339136, local_nic: mlx5_0, peer_nic: localhost:13048@mlx5_0, dest_rkey: 148283, retry_cnt: 0): remote invalid request error E0419 23:51:51.073930 114307 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57c000000, length: 65536, dest_addr: 140611910893568, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 0): remote invalid request error W0419 23:51:51.074009 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 E0419 23:51:51.074743 114311 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57e000000, length: 65536, dest_addr: 140611541794816, local_nic: mlx5_0, peer_nic: localhost:13018@mlx5_0, dest_rkey: 137784, retry_cnt: 0): remote invalid request error E0419 23:51:51.076172 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cb000000, length: 65536, dest_addr: 140611759898624, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error E0419 23:51:51.077553 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cf000000, length: 65536, dest_addr: 140611877339136, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 0): remote invalid request error E0419 23:51:51.079274 114311 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff584000000, length: 65536, dest_addr: 140611927670784, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error I0419 23:51:51.098073 114295 rdma_endpoint.cpp:108] Connection has been established W0419 23:51:51.111217 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 E0419 23:51:51.139672 114307 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57c150000, length: 65536, dest_addr: 140611912269824, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 1): remote invalid request error ``` There are no `allocation failed` in the master.log, but the above error still in `vllm.log`. And the test result shown that the performance is poorer than `tcp` mode, it is strange, maybe related to the above error. And is there any fallback logic in mooncake? I guess maybe the communicate mode have fallbacked to tcp ? Checked by ``` I0419 21:36:24.247948 3554 master.cpp:27] Master service started on port 50051, enable_gc=1, max_threads=64 I0419 21:36:24.249773 3554 master_service.cpp:75] action=start_gc_thread I0419 21:36:24.249786 3562 master_service.cpp:332] action=gc_thread_started ``` and ```Console # pip show mooncake-transfer-engineName: mooncake-transfer-engine Version: 0.3.0b5 ```
Author
Owner

@maobaolong commented on GitHub (Apr 19, 2025):

@deepindeed2022 is It looks similar with your issue?

https://github.com/kvcache-ai/Mooncake/issues/166#issuecomment-2753150553

<!-- gh-comment-id:2816762758 --> @maobaolong commented on GitHub (Apr 19, 2025): @deepindeed2022 is It looks similar with your issue? https://github.com/kvcache-ai/Mooncake/issues/166#issuecomment-2753150553
Author
Owner

@maobaolong commented on GitHub (Apr 19, 2025):

You could try to turn it on

@xiaguan I found lots of allocator.cpp:89] deallocation_succeeded in my master.log, it seems a gc threads works eagerly rather than on demand? This is not suitable for my workload, I want to do a full cache hit test, the first time cold run, second time, run on full hit mode.

<!-- gh-comment-id:2816776680 --> @maobaolong commented on GitHub (Apr 19, 2025): > You could try to turn it on @xiaguan I found lots of `allocator.cpp:89] deallocation_succeeded` in my master.log, it seems a gc threads works eagerly rather than on demand? This is not suitable for my workload, I want to do a full cache hit test, the first time cold run, second time, run on full hit mode.
Author
Owner

@xiaguan commented on GitHub (Apr 19, 2025):

Yes, if garbage collection is enabled, the object will be deleted after get1s. The previous allocation failure may have been caused by insufficient available space in the cluster, along with a high fragmentation rate of Facebook's allocator. We will work on improving this issue in the future.

<!-- gh-comment-id:2816779491 --> @xiaguan commented on GitHub (Apr 19, 2025): Yes, if garbage collection is enabled, the object will be deleted after get1s. The previous allocation failure may have been caused by insufficient available space in the cluster, along with a high fragmentation rate of Facebook's allocator. We will work on improving this issue in the future.
Author
Owner

@maobaolong commented on GitHub (Apr 19, 2025):

Image

@xiaguan Yeah, I just find the source relevant to.

But why I run tcp mode can pass all the tests and didn't encountered this allocation failed issue? It disable gc too.

<!-- gh-comment-id:2816780722 --> @maobaolong commented on GitHub (Apr 19, 2025): <img width="685" alt="Image" src="https://github.com/user-attachments/assets/234f20d2-6397-45e9-9f6a-8cfadb23f35d" /> @xiaguan Yeah, I just find the source relevant to. But why I run tcp mode can pass all the tests and didn't encountered this allocation failed issue? It disable gc too.
Author
Owner

@xiaguan commented on GitHub (Apr 19, 2025):

The current default allocation strategy is random.

<!-- gh-comment-id:2816781505 --> @xiaguan commented on GitHub (Apr 19, 2025): The current default allocation strategy is random.
Author
Owner

@xiaguan commented on GitHub (Apr 19, 2025):

The bug appears to be related to the recently updated TransferEngine, and we will investigate and resolve it as soon as possible.

<!-- gh-comment-id:2816782185 --> @xiaguan commented on GitHub (Apr 19, 2025): The bug appears to be related to the recently updated TransferEngine, and we will investigate and resolve it as soon as possible.
Author
Owner

@maobaolong commented on GitHub (Apr 19, 2025):

Yes, if garbage collection is enabled, the object will be deleted after get1s. The previous allocation failure may have been caused by insufficient available space in the cluster, along with a high fragmentation rate of Facebook's allocator. We will work on improving this issue in the future.

This is wired for the rdma case, after all my 10 requests test finished, there are 63264 tokens in all, and I specific 100GiB for each vllmWorker, and for DeepSeekR1, there are 8 tp in all, it seems there might be something wrong for it, if not, the kvcache of 63264 tokens cannot waste 100GiB memory.

If you want something more context, I'd like to help to reproduce this issue.

And I would be help me a lot, if there are some PR submit, and I'd like to take a trial. Thanks for the help on this issue.

For the gc, it would be nice to removed key by evictor or a high water mark, there might be some better idea than gc after 1s.
@xiaguan

<!-- gh-comment-id:2816783261 --> @maobaolong commented on GitHub (Apr 19, 2025): > Yes, if garbage collection is enabled, the object will be deleted after get1s. The previous allocation failure may have been caused by insufficient available space in the cluster, along with a high fragmentation rate of Facebook's allocator. We will work on improving this issue in the future. This is wired for the rdma case, after all my `10` requests test finished, there are `63264` tokens in all, and I specific 100GiB for each vllmWorker, and for DeepSeekR1, there are 8 tp in all, it seems there might be something wrong for it, if not, the kvcache of `63264` tokens cannot waste `100GiB` memory. If you want something more context, I'd like to help to reproduce this issue. And I would be help me a lot, if there are some PR submit, and I'd like to take a trial. Thanks for the help on this issue. For the gc, it would be nice to removed key by evictor or a high water mark, there might be some better idea than gc after 1s. @xiaguan
Author
Owner

@xiaguan commented on GitHub (Apr 19, 2025):

Could you please provide me with the complete master log?

<!-- gh-comment-id:2816795175 --> @xiaguan commented on GitHub (Apr 19, 2025): Could you please provide me with the complete master log?
Author
Owner

@ShangmingCai commented on GitHub (Apr 19, 2025):

INFO 04-19 23:51:44 [engine.py:310] Added request chatcmpl-77010a03977c41c484c87c88abd9569f.
I0419 23:51:51.054445 114308 rdma_endpoint.cpp:108] Connection has been established
I0419 23:51:51.060045 114298 rdma_endpoint.cpp:108] Connection has been established
I0419 23:51:51.066856 114156 rdma_endpoint.cpp:108] Connection has been established
I0419 23:51:51.067245 114311 rdma_endpoint.cpp:108] Connection has been established
I0419 23:51:51.067374 114299 rdma_endpoint.cpp:108] Connection has been established
W0419 23:51:51.067479 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
I0419 23:51:51.068233 114312 endpoint_store.cpp:135] Endpoint localhost:13347@mlx5_0 already exists in SIEVEEndpointStore
I0419 23:51:51.069422 114312 rdma_endpoint.cpp:108] Connection has been established
W0419 23:51:51.070123 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
W0419 23:51:51.070240 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
E0419 23:51:51.071314 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cc000000, length: 65536, dest_addr: 140611776675840, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error
W0419 23:51:51.072116 113629 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
W0419 23:51:51.073052 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
W0419 23:51:51.073107 114305 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
E0419 23:51:51.073233 114156 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff59e000000, length: 65536, dest_addr: 140611877339136, local_nic: mlx5_0, peer_nic: localhost:13048@mlx5_0, dest_rkey: 148283, retry_cnt: 0): remote invalid request error
E0419 23:51:51.073930 114307 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57c000000, length: 65536, dest_addr: 140611910893568, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 0): remote invalid request error
W0419 23:51:51.074009 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
E0419 23:51:51.074743 114311 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57e000000, length: 65536, dest_addr: 140611541794816, local_nic: mlx5_0, peer_nic: localhost:13018@mlx5_0, dest_rkey: 137784, retry_cnt: 0): remote invalid request error
E0419 23:51:51.076172 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cb000000, length: 65536, dest_addr: 140611759898624, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error
E0419 23:51:51.077553 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cf000000, length: 65536, dest_addr: 140611877339136, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 0): remote invalid request error
E0419 23:51:51.079274 114311 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff584000000, length: 65536, dest_addr: 140611927670784, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error
I0419 23:51:51.098073 114295 rdma_endpoint.cpp:108] Connection has been established
W0419 23:51:51.111217 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0
E0419 23:51:51.139672 114307 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57c150000, length: 65536, dest_addr: 140611912269824, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 1): remote invalid request error

There are no allocation failed in the master.log, but the above error still in vllm.log. And the test result shown that the performance is poorer than tcp mode, it is strange, maybe related to the above error.

And is there any fallback logic in mooncake? I guess maybe the communicate mode have fallbacked to tcp ?

@alogfans Could this be related to the device fault-tolerant issue? Please check the log when you are available. I find this log suspicious :"remote invalid request error".

<!-- gh-comment-id:2816795468 --> @ShangmingCai commented on GitHub (Apr 19, 2025): > ``` > INFO 04-19 23:51:44 [engine.py:310] Added request chatcmpl-77010a03977c41c484c87c88abd9569f. > I0419 23:51:51.054445 114308 rdma_endpoint.cpp:108] Connection has been established > I0419 23:51:51.060045 114298 rdma_endpoint.cpp:108] Connection has been established > I0419 23:51:51.066856 114156 rdma_endpoint.cpp:108] Connection has been established > I0419 23:51:51.067245 114311 rdma_endpoint.cpp:108] Connection has been established > I0419 23:51:51.067374 114299 rdma_endpoint.cpp:108] Connection has been established > W0419 23:51:51.067479 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 > I0419 23:51:51.068233 114312 endpoint_store.cpp:135] Endpoint localhost:13347@mlx5_0 already exists in SIEVEEndpointStore > I0419 23:51:51.069422 114312 rdma_endpoint.cpp:108] Connection has been established > W0419 23:51:51.070123 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 > W0419 23:51:51.070240 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 > E0419 23:51:51.071314 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cc000000, length: 65536, dest_addr: 140611776675840, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error > W0419 23:51:51.072116 113629 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 > W0419 23:51:51.073052 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 > W0419 23:51:51.073107 114305 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 > E0419 23:51:51.073233 114156 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff59e000000, length: 65536, dest_addr: 140611877339136, local_nic: mlx5_0, peer_nic: localhost:13048@mlx5_0, dest_rkey: 148283, retry_cnt: 0): remote invalid request error > E0419 23:51:51.073930 114307 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57c000000, length: 65536, dest_addr: 140611910893568, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 0): remote invalid request error > W0419 23:51:51.074009 114309 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 > E0419 23:51:51.074743 114311 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57e000000, length: 65536, dest_addr: 140611541794816, local_nic: mlx5_0, peer_nic: localhost:13018@mlx5_0, dest_rkey: 137784, retry_cnt: 0): remote invalid request error > E0419 23:51:51.076172 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cb000000, length: 65536, dest_addr: 140611759898624, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error > E0419 23:51:51.077553 114298 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff4cf000000, length: 65536, dest_addr: 140611877339136, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 0): remote invalid request error > E0419 23:51:51.079274 114311 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff584000000, length: 65536, dest_addr: 140611927670784, local_nic: mlx5_0, peer_nic: localhost:13347@mlx5_0, dest_rkey: 94772, retry_cnt: 0): remote invalid request error > I0419 23:51:51.098073 114295 rdma_endpoint.cpp:108] Connection has been established > W0419 23:51:51.111217 114297 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_0 > E0419 23:51:51.139672 114307 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff57c150000, length: 65536, dest_addr: 140611912269824, local_nic: mlx5_0, peer_nic: localhost:12558@mlx5_0, dest_rkey: 141369, retry_cnt: 1): remote invalid request error > ``` > > There are no `allocation failed` in the master.log, but the above error still in `vllm.log`. And the test result shown that the performance is poorer than `tcp` mode, it is strange, maybe related to the above error. > > And is there any fallback logic in mooncake? I guess maybe the communicate mode have fallbacked to tcp ? @alogfans Could this be related to the device fault-tolerant issue? Please check the log when you are available. I find this log suspicious :"remote invalid request error".
Author
Owner

@maobaolong commented on GitHub (Apr 20, 2025):

Could you please provide me with the complete master log?

@xiaguan Thanks for follow-up this issue. I use Qwen2.5-1.5B-Instruct model with tp=4 and mlx_1 as rdma device to reproduce this issue.

  • Use ib_send_bw tested mlx5_1 can work.
ib_send_bw -d mlx5_1 -x 1 -D 10 -F
ib_send_bw -d mlx5_1 -x 1 -D 10 -F localhost
  • ib device info
# ibv_devices
    device                 node GUID
    ------              ----------------
    mlx5_bond_6         a088c203001123dc
    mlx5_bond_5         a088c203001127bc
    mlx5_bond_7         a088c2030011237c
    mlx5_bond_4         946dae0300b49d7e
    mlx5_bond_8         a088c2030011577c
    mlx5_bond_3         a088c203001142fc
    mlx5_bond_2         a088c2030011535c
    mlx5_bond_1         a088c2030011411c
    mlx5_0              a088c203001bc810
    mlx5_1              a088c203001bc811
    mlx5_2              0000000000000000
    mlx5_3              0000000000000000
    mlx5_4              0000000000000000
    mlx5_5              0000000000000000
  • vllm serve log of cpp part
# grep cpp run-vllm-mbl-qwen.log
I0420 01:05:12.171046 121516 client.cpp:83] Connect to Master success
I0420 01:05:12.174928 121516 transfer_engine.cpp:86] Transfer Engine uses address 192.168.100.162 and port 15873 for serving local TCP service
I0420 01:05:12.181720 121516 client.cpp:45] transport_type=rdma
I0420 01:05:12.186365 121516 rdma_context.cpp:413] Find best gid index: 3 on mlx5_1/
I0420 01:05:12.187484 121516 rdma_context.cpp:125] RDMA device: mlx5_1, LID: 0, GID: (GID_Index 3) 00:00:00:00:00:00:00:00:00:00:ff:ff:1e:dd:a1:a2
I0420 01:05:12.187978 121516 allocator.cpp:99] initializing_simple_allocator size=1073741824
I0420 01:05:12.188017 121516 allocator.cpp:138] simple_allocator_initialized pool_id=0
I0420 01:05:12.188561 121515 client.cpp:83] Connect to Master success
I0420 01:05:12.191768 121515 transfer_engine.cpp:86] Transfer Engine uses address 192.168.100.162 and port 16556 for serving local TCP service
I0420 01:05:12.197477 121515 client.cpp:45] transport_type=rdma
I0420 01:05:12.197662 121517 client.cpp:83] Connect to Master success
I0420 01:05:12.199843 121443 client.cpp:83] Connect to Master success
I0420 01:05:12.201031 121517 transfer_engine.cpp:86] Transfer Engine uses address 192.168.100.162 and port 16652 for serving local TCP service
I0420 01:05:12.202510 121443 transfer_engine.cpp:86] Transfer Engine uses address 192.168.100.162 and port 15969 for serving local TCP service
I0420 01:05:12.203898 121515 rdma_context.cpp:413] Find best gid index: 3 on mlx5_1/
I0420 01:05:12.204650 121515 rdma_context.cpp:125] RDMA device: mlx5_1, LID: 0, GID: (GID_Index 3) 00:00:00:00:00:00:00:00:00:00:ff:ff:1e:dd:a1:a2
I0420 01:05:12.205034 121515 allocator.cpp:99] initializing_simple_allocator size=1073741824
I0420 01:05:12.205065 121515 allocator.cpp:138] simple_allocator_initialized pool_id=0
I0420 01:05:12.208149 121517 client.cpp:45] transport_type=rdma
I0420 01:05:12.210265 121443 client.cpp:45] transport_type=rdma
I0420 01:05:12.212263 121517 rdma_context.cpp:413] Find best gid index: 3 on mlx5_1/
I0420 01:05:12.213027 121517 rdma_context.cpp:125] RDMA device: mlx5_1, LID: 0, GID: (GID_Index 3) 00:00:00:00:00:00:00:00:00:00:ff:ff:1e:dd:a1:a2
I0420 01:05:12.213421 121517 allocator.cpp:99] initializing_simple_allocator size=1073741824
I0420 01:05:12.213461 121517 allocator.cpp:138] simple_allocator_initialized pool_id=0
I0420 01:05:12.215334 121443 rdma_context.cpp:413] Find best gid index: 3 on mlx5_1/
I0420 01:05:12.216061 121443 rdma_context.cpp:125] RDMA device: mlx5_1, LID: 0, GID: (GID_Index 3) 00:00:00:00:00:00:00:00:00:00:ff:ff:1e:dd:a1:a2
I0420 01:05:12.216614 121443 allocator.cpp:99] initializing_simple_allocator size=1073741824
I0420 01:05:12.216653 121443 allocator.cpp:138] simple_allocator_initialized pool_id=0
I0420 01:05:59.618247 122536 rdma_endpoint.cpp:108] Connection has been established
W0420 01:05:59.639585 122537 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_1
E0420 01:05:59.641764 122446 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff587000000, length: 65536, dest_addr: 140612156806624, local_nic: mlx5_1, peer_nic: localhost:12706@mlx5_1, dest_rkey: 307956, retry_cnt: 0): remote invalid request error
I0420 01:06:10.688514 121515 store_py.cpp:65] Received signal 2, cleaning up resources
I0420 01:06:10.688516 121443 store_py.cpp:65] Received signal 2, cleaning up resources
I0420 01:06:10.688513 121517 store_py.cpp:65] Received signal 2, cleaning up resources
I0420 01:06:10.688513 121516 store_py.cpp:65] Received signal 2, cleaning up resources
I0420 01:06:10.688541 121515 store_py.cpp:58] Cleaning up DistributedObjectStore instance
I0420 01:06:10.688549 121443 store_py.cpp:58] Cleaning up DistributedObjectStore instance
I0420 01:06:10.688560 121517 store_py.cpp:58] Cleaning up DistributedObjectStore instance
I0420 01:06:10.688568 121516 store_py.cpp:58] Cleaning up DistributedObjectStore instance
I0420 01:06:13.005766 121515 allocator.cpp:160] simple_allocator_destroyed status=success
I0420 01:06:13.006567 121516 allocator.cpp:160] simple_allocator_destroyed status=success
I0420 01:06:13.008828 121517 allocator.cpp:160] simple_allocator_destroyed status=success
I0420 01:06:14.037289 121443 allocator.cpp:160] simple_allocator_destroyed status=success
  • mooncake master.log
/usr/local/lib/python3.12/dist-packages/mooncake/mooncake_master -v=1 -max_threads 64 -enable_gc  

master.log

<!-- gh-comment-id:2816959119 --> @maobaolong commented on GitHub (Apr 20, 2025): > Could you please provide me with the complete master log? @xiaguan Thanks for follow-up this issue. I use Qwen2.5-1.5B-Instruct model with `tp=4` and mlx_1 as rdma device to reproduce this issue. - Use ib_send_bw tested `mlx5_1` can work. ```Console ib_send_bw -d mlx5_1 -x 1 -D 10 -F ib_send_bw -d mlx5_1 -x 1 -D 10 -F localhost ``` - ib device info ```Console # ibv_devices device node GUID ------ ---------------- mlx5_bond_6 a088c203001123dc mlx5_bond_5 a088c203001127bc mlx5_bond_7 a088c2030011237c mlx5_bond_4 946dae0300b49d7e mlx5_bond_8 a088c2030011577c mlx5_bond_3 a088c203001142fc mlx5_bond_2 a088c2030011535c mlx5_bond_1 a088c2030011411c mlx5_0 a088c203001bc810 mlx5_1 a088c203001bc811 mlx5_2 0000000000000000 mlx5_3 0000000000000000 mlx5_4 0000000000000000 mlx5_5 0000000000000000 ``` - vllm serve log of cpp part ``` # grep cpp run-vllm-mbl-qwen.log I0420 01:05:12.171046 121516 client.cpp:83] Connect to Master success I0420 01:05:12.174928 121516 transfer_engine.cpp:86] Transfer Engine uses address 192.168.100.162 and port 15873 for serving local TCP service I0420 01:05:12.181720 121516 client.cpp:45] transport_type=rdma I0420 01:05:12.186365 121516 rdma_context.cpp:413] Find best gid index: 3 on mlx5_1/ I0420 01:05:12.187484 121516 rdma_context.cpp:125] RDMA device: mlx5_1, LID: 0, GID: (GID_Index 3) 00:00:00:00:00:00:00:00:00:00:ff:ff:1e:dd:a1:a2 I0420 01:05:12.187978 121516 allocator.cpp:99] initializing_simple_allocator size=1073741824 I0420 01:05:12.188017 121516 allocator.cpp:138] simple_allocator_initialized pool_id=0 I0420 01:05:12.188561 121515 client.cpp:83] Connect to Master success I0420 01:05:12.191768 121515 transfer_engine.cpp:86] Transfer Engine uses address 192.168.100.162 and port 16556 for serving local TCP service I0420 01:05:12.197477 121515 client.cpp:45] transport_type=rdma I0420 01:05:12.197662 121517 client.cpp:83] Connect to Master success I0420 01:05:12.199843 121443 client.cpp:83] Connect to Master success I0420 01:05:12.201031 121517 transfer_engine.cpp:86] Transfer Engine uses address 192.168.100.162 and port 16652 for serving local TCP service I0420 01:05:12.202510 121443 transfer_engine.cpp:86] Transfer Engine uses address 192.168.100.162 and port 15969 for serving local TCP service I0420 01:05:12.203898 121515 rdma_context.cpp:413] Find best gid index: 3 on mlx5_1/ I0420 01:05:12.204650 121515 rdma_context.cpp:125] RDMA device: mlx5_1, LID: 0, GID: (GID_Index 3) 00:00:00:00:00:00:00:00:00:00:ff:ff:1e:dd:a1:a2 I0420 01:05:12.205034 121515 allocator.cpp:99] initializing_simple_allocator size=1073741824 I0420 01:05:12.205065 121515 allocator.cpp:138] simple_allocator_initialized pool_id=0 I0420 01:05:12.208149 121517 client.cpp:45] transport_type=rdma I0420 01:05:12.210265 121443 client.cpp:45] transport_type=rdma I0420 01:05:12.212263 121517 rdma_context.cpp:413] Find best gid index: 3 on mlx5_1/ I0420 01:05:12.213027 121517 rdma_context.cpp:125] RDMA device: mlx5_1, LID: 0, GID: (GID_Index 3) 00:00:00:00:00:00:00:00:00:00:ff:ff:1e:dd:a1:a2 I0420 01:05:12.213421 121517 allocator.cpp:99] initializing_simple_allocator size=1073741824 I0420 01:05:12.213461 121517 allocator.cpp:138] simple_allocator_initialized pool_id=0 I0420 01:05:12.215334 121443 rdma_context.cpp:413] Find best gid index: 3 on mlx5_1/ I0420 01:05:12.216061 121443 rdma_context.cpp:125] RDMA device: mlx5_1, LID: 0, GID: (GID_Index 3) 00:00:00:00:00:00:00:00:00:00:ff:ff:1e:dd:a1:a2 I0420 01:05:12.216614 121443 allocator.cpp:99] initializing_simple_allocator size=1073741824 I0420 01:05:12.216653 121443 allocator.cpp:138] simple_allocator_initialized pool_id=0 I0420 01:05:59.618247 122536 rdma_endpoint.cpp:108] Connection has been established W0420 01:05:59.639585 122537 worker_pool.cpp:373] Worker: Received context async event local access violation work queue error for context mlx5_1 E0420 01:05:59.641764 122446 worker_pool.cpp:265] Worker: Process failed for slice (opcode: 1, source_addr: 0x7ff587000000, length: 65536, dest_addr: 140612156806624, local_nic: mlx5_1, peer_nic: localhost:12706@mlx5_1, dest_rkey: 307956, retry_cnt: 0): remote invalid request error I0420 01:06:10.688514 121515 store_py.cpp:65] Received signal 2, cleaning up resources I0420 01:06:10.688516 121443 store_py.cpp:65] Received signal 2, cleaning up resources I0420 01:06:10.688513 121517 store_py.cpp:65] Received signal 2, cleaning up resources I0420 01:06:10.688513 121516 store_py.cpp:65] Received signal 2, cleaning up resources I0420 01:06:10.688541 121515 store_py.cpp:58] Cleaning up DistributedObjectStore instance I0420 01:06:10.688549 121443 store_py.cpp:58] Cleaning up DistributedObjectStore instance I0420 01:06:10.688560 121517 store_py.cpp:58] Cleaning up DistributedObjectStore instance I0420 01:06:10.688568 121516 store_py.cpp:58] Cleaning up DistributedObjectStore instance I0420 01:06:13.005766 121515 allocator.cpp:160] simple_allocator_destroyed status=success I0420 01:06:13.006567 121516 allocator.cpp:160] simple_allocator_destroyed status=success I0420 01:06:13.008828 121517 allocator.cpp:160] simple_allocator_destroyed status=success I0420 01:06:14.037289 121443 allocator.cpp:160] simple_allocator_destroyed status=success ``` - mooncake master.log ```Console /usr/local/lib/python3.12/dist-packages/mooncake/mooncake_master -v=1 -max_threads 64 -enable_gc ``` [master.log](https://github.com/user-attachments/files/19823544/master.log)
Author
Owner

@stmatengss commented on GitHub (Apr 20, 2025):

Yes, if garbage collection is enabled, the object will be deleted after get1s. The previous allocation failure may have been caused by insufficient available space in the cluster, along with a high fragmentation rate of Facebook's allocator. We will work on improving this issue in the future.

This is wired for the rdma case, after all my 10 requests test finished, there are 63264 tokens in all, and I specific 100GiB for each vllmWorker, and for DeepSeekR1, there are 8 tp in all, it seems there might be something wrong for it, if not, the kvcache of 63264 tokens cannot waste 100GiB memory.

If you want something more context, I'd like to help to reproduce this issue.

And I would be help me a lot, if there are some PR submit, and I'd like to take a trial. Thanks for the help on this issue.

For the gc, it would be nice to removed key by evictor or a high water mark, there might be some better idea than gc after 1s. @xiaguan

This might relate to the issue identified by @eryugey, where memory occupation grows significantly during long-time running. We suspect the Slice Cache introduced in the recent TransferEngine update is the primary cause.

<!-- gh-comment-id:2816996188 --> @stmatengss commented on GitHub (Apr 20, 2025): > > Yes, if garbage collection is enabled, the object will be deleted after get1s. The previous allocation failure may have been caused by insufficient available space in the cluster, along with a high fragmentation rate of Facebook's allocator. We will work on improving this issue in the future. > > This is wired for the rdma case, after all my `10` requests test finished, there are `63264` tokens in all, and I specific 100GiB for each vllmWorker, and for DeepSeekR1, there are 8 tp in all, it seems there might be something wrong for it, if not, the kvcache of `63264` tokens cannot waste `100GiB` memory. > > If you want something more context, I'd like to help to reproduce this issue. > > And I would be help me a lot, if there are some PR submit, and I'd like to take a trial. Thanks for the help on this issue. > > For the gc, it would be nice to removed key by evictor or a high water mark, there might be some better idea than gc after 1s. [@xiaguan](https://github.com/xiaguan) This might relate to the issue identified by @eryugey, where memory occupation grows significantly during long-time running. We suspect the Slice Cache introduced in the recent TransferEngine update is the primary cause.
Author
Owner

@maobaolong commented on GitHub (Apr 20, 2025):

@stmatengss Thanks for your information, but i only run vllm + mooncake server for my test purpose only, and I can make sure that it do not live longer than 3 minutes.

And as compare purpose, I ran infinistore as well, it can pass my test for the same model and other vllm variables.

<!-- gh-comment-id:2817028626 --> @maobaolong commented on GitHub (Apr 20, 2025): @stmatengss Thanks for your information, but i only run vllm + mooncake server for my test purpose only, and I can make sure that it do not live longer than 3 minutes. And as compare purpose, I ran `infinistore` as well, it can pass my test for the same model and other vllm variables.
Author
Owner

@alogfans commented on GitHub (Apr 21, 2025):

@stmatengss The "allocation failed" error does not related to the Slice Cache.
@maobaolong Both "Remote Invalid Request Error" and "local access violation work queue error" seems bugs in the user code. Can you provide detailed log by adding MC_LOG_LEVEL environment variable as "TRACE"?

<!-- gh-comment-id:2817491771 --> @alogfans commented on GitHub (Apr 21, 2025): @stmatengss The "allocation failed" error does not related to the Slice Cache. @maobaolong Both "Remote Invalid Request Error" and "local access violation work queue error" seems bugs in the user code. Can you provide detailed log by adding MC_LOG_LEVEL environment variable as "TRACE"?
Author
Owner

@maobaolong commented on GitHub (Apr 21, 2025):

@alogfans I will run again soon.

<!-- gh-comment-id:2817626418 --> @maobaolong commented on GitHub (Apr 21, 2025): @alogfans I will run again soon.
Author
Owner

@xiaguan commented on GitHub (Apr 23, 2025):

@maobaolong This issue has been resolved in our private conversation. May I go ahead and close it?

<!-- gh-comment-id:2823659769 --> @xiaguan commented on GitHub (Apr 23, 2025): @maobaolong This issue has been resolved in our private conversation. May I go ahead and close it?
Author
Owner

@maobaolong commented on GitHub (Apr 23, 2025):

@xiaguan @alogfans @stmatengss @ShangmingCai Thanks for your kindly help on this issue, eventually, we found this is not a urgent issue and can only reproduce on our private version of vLLM and our model, so I'd like to close this issue.

Thank all for your help again!

<!-- gh-comment-id:2824095361 --> @maobaolong commented on GitHub (Apr 23, 2025): @xiaguan @alogfans @stmatengss @ShangmingCai Thanks for your kindly help on this issue, eventually, we found this is not a urgent issue and can only reproduce on our private version of vLLM and our model, so I'd like to close this issue. Thank all for your help again!
Author
Owner

@qyzhaoxun commented on GitHub (May 29, 2025):

@xiaguan @maobaolong 你好,使用vllm+mooncake-transferengine跑 pd 分离也遇到了下面的错误,"Remote Invalid Request Error" and "local access violation work queue error" 。可以问一下这个报错是怎么解决的吗?
使用的vllm版本是vllm/vllm-openai:v0.8.5.post1。input token在2000以下没问题,但是到3000+的时候就复线了

<!-- gh-comment-id:2919270701 --> @qyzhaoxun commented on GitHub (May 29, 2025): @xiaguan @maobaolong 你好,使用vllm+mooncake-transferengine跑 pd 分离也遇到了下面的错误,"Remote Invalid Request Error" and "local access violation work queue error" 。可以问一下这个报错是怎么解决的吗? 使用的vllm版本是vllm/vllm-openai:v0.8.5.post1。input token在2000以下没问题,但是到3000+的时候就复线了
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
kvcache-ai/Mooncake#109
No description provided.