[Bug]: async llm engine failed unexpectedly (using mixtral-8x7b with tp=4)

[PeterWang1986]

Your current environment

Collecting environment information...
PyTorch version: 2.1.2+cu121
Is debug build: False
CUDA used to build PyTorch: 12.1
ROCM used to build PyTorch: N/A

OS: Ubuntu 22.04.3 LTS (x86_64)
GCC version: (Ubuntu 11.4.0-1ubuntu1~22.04) 11.4.0
Clang version: Could not collect
CMake version: version 3.29.0
Libc version: glibc-2.35

Python version: 3.10.12 (main, Nov 20 2023, 15:14:05) [GCC 11.4.0] (64-bit runtime)
Python platform: Linux-4.18.0-425.3.1.el8.x86_64-x86_64-with-glibc2.35
Is CUDA available: True
CUDA runtime version: Could not collect
CUDA_MODULE_LOADING set to: LAZY
GPU models and configuration: 
GPU 0: NVIDIA A100-SXM4-80GB
GPU 1: NVIDIA A100-SXM4-80GB
GPU 2: NVIDIA A100-SXM4-80GB
GPU 3: NVIDIA A100-SXM4-80GB

Nvidia driver version: 535.86.10
cuDNN version: Could not collect
HIP runtime version: N/A
MIOpen runtime version: N/A
Is XNNPACK available: True

CPU:
Architecture:                    x86_64
CPU op-mode(s):                  32-bit, 64-bit
Address sizes:                   46 bits physical, 57 bits virtual
Byte Order:                      Little Endian
CPU(s):                          112
On-line CPU(s) list:             0-111
Vendor ID:                       GenuineIntel
Model name:                      Intel(R) Xeon(R) Gold 6348 CPU @ 2.60GHz
CPU family:                      6
Model:                           106
Thread(s) per core:              2
Core(s) per socket:              28
Socket(s):                       2
Stepping:                        6
CPU max MHz:                     3500.0000
CPU min MHz:                     800.0000
BogoMIPS:                        5200.00
Flags:                           fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc cpuid aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault epb cat_l3 invpcid_single intel_ppin ssbd mba ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2 erms invpcid cqm rdt_a avx512f avx512dq rdseed adx smap avx512ifma clflushopt clwb intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves cqm_llc cqm_occup_llc cqm_mbm_total cqm_mbm_local split_lock_detect wbnoinvd dtherm ida arat pln pts hwp hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg tme avx512_vpopcntdq la57 rdpid fsrm md_clear pconfig flush_l1d arch_capabilities
Virtualization:                  VT-x
L1d cache:                       2.6 MiB (56 instances)
L1i cache:                       1.8 MiB (56 instances)
L2 cache:                        70 MiB (56 instances)
L3 cache:                        84 MiB (2 instances)
NUMA node(s):                    2
NUMA node0 CPU(s):               0-27,56-83
NUMA node1 CPU(s):               28-55,84-111
Vulnerability Itlb multihit:     Not affected
Vulnerability L1tf:              Not affected
Vulnerability Mds:               Not affected
Vulnerability Meltdown:          Not affected
Vulnerability Mmio stale data:   Mitigation; Clear CPU buffers; SMT vulnerable
Vulnerability Retbleed:          Not affected
Vulnerability Spec store bypass: Mitigation; Speculative Store Bypass disabled via prctl
Vulnerability Spectre v1:        Mitigation; usercopy/swapgs barriers and __user pointer sanitization
Vulnerability Spectre v2:        Mitigation; Enhanced IBRS, IBPB conditional, RSB filling, PBRSB-eIBRS SW sequence
Vulnerability Srbds:             Not affected
Vulnerability Tsx async abort:   Not affected

Versions of relevant libraries:
[pip3] numpy==1.26.4
[pip3] torch==2.1.2
[pip3] triton==2.1.0
[conda] Could not collectROCM Version: Could not collect
Neuron SDK Version: N/A
vLLM Version: N/A
vLLM Build Flags:
CUDA Archs: Not Set; ROCm: Disabled; Neuron: Disabled
GPU Topology:
GPU0    GPU1    GPU2    GPU3    NIC0    NIC1    NIC2    CPU Affinity    NUMA Affinity   GPU NUMA ID
GPU0     X      NV12    NV12    NV12    SYS     PXB     SYS     28-55,84-111    1               N/A
GPU1    NV12     X      NV12    NV12    SYS     PXB     SYS     28-55,84-111    1               N/A
GPU2    NV12    NV12     X      NV12    SYS     NODE    SYS     28-55,84-111    1               N/A
GPU3    NV12    NV12    NV12     X      SYS     NODE    SYS     28-55,84-111    1               N/A
NIC0    SYS     SYS     SYS     SYS      X      SYS     NODE
NIC1    PXB     PXB     NODE    NODE    SYS      X      SYS
NIC2    SYS     SYS     SYS     SYS     NODE    SYS      X 

Legend:

  X    = Self
  SYS  = Connection traversing PCIe as well as the SMP interconnect between NUMA nodes (e.g., QPI/UPI)
  NODE = Connection traversing PCIe as well as the interconnect between PCIe Host Bridges within a NUMA node
  PHB  = Connection traversing PCIe as well as a PCIe Host Bridge (typically the CPU)
  PXB  = Connection traversing multiple PCIe bridges (without traversing the PCIe Host Bridge)
  PIX  = Connection traversing at most a single PCIe bridge
  NV#  = Connection traversing a bonded set of # NVLinks

NIC Legend:

  NIC0: mlx5_0
  NIC1: mlx5_3
  NIC2: mlx5_bond_0

🐛 Describe the bug

we used vllm:v0.4.0.post1 for online inference, here is server start cmd:
python3 -u -m vllm.entrypoints.openai.api_server --port 8091 --model /model_path --served-model-name model_name --max-model-len 8192 --tensor-parallel-size 4 --disable-log-requests --enable-prefix-caching

but sometimes we got bellow error (not everytime):
vllm.engine.async_llm_engine.AsyncEngineDeadError: Task finished unexpectedly. This should never happen! Please open an issue on Github. See stack trace above for the actual cause.

and here are some stacktrace I can find:
raise AsyncEngineDeadError(
File "/workspace/vllm/engine/async_llm_engine.py", line 45, in _raise_exception_on_finish
File "uvloop/cbhandles.pyx", line 63, in uvloop.loop.Handle._run
Traceback (most recent call last):
The above exception was the direct cause of the following exception:
asyncio.exceptions.TimeoutError
raise exceptions.TimeoutError() from exc
File "/usr/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
has_requests_in_progress = await asyncio.wait_for(
File "/workspace/vllm/engine/async_llm_engine.py", line 479, in run_engine_loop
task.result()
File "/workspace/vllm/engine/async_llm_engine.py", line 38, in _raise_exception_on_finish
Traceback (most recent call last):
The above exception was the direct cause of the following exception:
asyncio.exceptions.CancelledError
return fut.result()
File "/usr/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
Traceback (most recent call last):
During handling of the above exception, another exception occurred:
asyncio.exceptions.CancelledError
all_outputs = await asyncio.gather(*coros)
File "/workspace/vllm/executor/ray_gpu_executor.py", line 412, in _run_workers_async
all_outputs = await self._run_workers_async(
File "/workspace/vllm/executor/ray_gpu_executor.py", line 422, in execute_model_async
output = await self.model_executor.execute_model_async(
File "/workspace/vllm/engine/async_llm_engine.py", line 213, in step_async
request_outputs = await self.engine.step_async()
File "/workspace/vllm/engine/async_llm_engine.py", line 453, in engine_step
Traceback (most recent call last):
handle: <Handle functools.partial(<function _raise_exception_on_finish at 0x7f16653081f0>, error_callback=<bound method AsyncLLMEngine._error_callback of <vllm.engine.async_llm_eng
Exception in callback functools.partial(<function _raise_exception_on_finish at 0x7f16653081f0>, error_callback=<bound method AsyncLLMEngine._error_callback of <vllm.engine.async_l
ERROR 04-17 02:57:36 async_llm_engine.py:43] asyncio.exceptions.TimeoutError
ERROR 04-17 02:57:36 async_llm_engine.py:43] raise exceptions.TimeoutError() from exc
ERROR 04-17 02:57:36 async_llm_engine.py:43] File "/usr/lib/python3.10/asyncio/tasks.py", line 458, in wait_for
ERROR 04-17 02:57:36 async_llm_engine.py:43] has_requests_in_progress = await asyncio.wait_for(
ERROR 04-17 02:57:36 async_llm_engine.py:43] File "/workspace/vllm/engine/async_llm_engine.py", line 479, in run_engine_loop	
ERROR 04-17 02:57:36 async_llm_engine.py:43] task.result()
ERROR 04-17 02:57:36 async_llm_engine.py:43] File "/workspace/vllm/engine/async_llm_engine.py", line 38, in _raise_exception_on_finish
ERROR 04-17 02:57:36 async_llm_engine.py:43] Traceback (most recent call last):
ERROR 04-17 02:57:36 async_llm_engine.py:43]
ERROR 04-17 02:57:36 async_llm_engine.py:43] The above exception was the direct cause of the following exception:
ERROR 04-17 02:57:36 async_llm_engine.py:43]
ERROR 04-17 02:57:36 async_llm_engine.py:43] asyncio.exceptions.CancelledError
ERROR 04-17 02:57:36 async_llm_engine.py:43] return fut.result()
ERROR 04-17 02:57:36 async_llm_engine.py:43] File "/usr/lib/python3.10/asyncio/tasks.py", line 456, in wait_for
ERROR 04-17 02:57:36 async_llm_engine.py:43] Traceback (most recent call last):
ERROR 04-17 02:57:36 async_llm_engine.py:43]
ERROR 04-17 02:57:36 async_llm_engine.py:43] During handling of the above exception, another exception occurred:
ERROR 04-17 02:57:36 async_llm_engine.py:43]
ERROR 04-17 02:57:36 async_llm_engine.py:43] asyncio.exceptions.CancelledError
ERROR 04-17 02:57:36 async_llm_engine.py:43] all_outputs = await asyncio.gather(*coros)
ERROR 04-17 02:57:36 async_llm_engine.py:43] File "/workspace/vllm/executor/ray_gpu_executor.py", line 412, in _run_workers_async
ERROR 04-17 02:57:36 async_llm_engine.py:43] all_outputs = await self._run_workers_async(
ERROR 04-17 02:57:36 async_llm_engine.py:43] File "/workspace/vllm/executor/ray_gpu_executor.py", line 422, in execute_model_async
ERROR 04-17 02:57:36 async_llm_engine.py:43] output = await self.model_executor.execute_model_async(
ERROR 04-17 02:57:36 async_llm_engine.py:43] File "/workspace/vllm/engine/async_llm_engine.py", line 213, in step_async
ERROR 04-17 02:57:36 async_llm_engine.py:43] request_outputs = await self.engine.step_async()
ERROR 04-17 02:57:36 async_llm_engine.py:43] File "/workspace/vllm/engine/async_llm_engine.py", line 453, in engine_step
ERROR 04-17 02:57:36 async_llm_engine.py:43] Traceback (most recent call last):
ERROR 04-17 02:57:36 async_llm_engine.py:43] Engine background task failed
ERROR 04-17 02:57:36 async_llm_engine.py:482] Engine iteration timed out. This should never happen!

[PeterWang1986]

BTW
we also encounter the same error when disable prefix caching.

[Alienfeel]

looks similar to #3839

works well in vllm-0.3.3

[youkaichao]

Can you try to build from the latest main branch, and run with export VLLM_TRACE_FUNCTION=1 ? This should give you hint on which function crashes or hangs. It is just introduced in #4079 .

[supdizh]

same here, upgrade vllm from 0.33 to 0.4.0 post1
always report "Engine iteration timed out/Engine background task failed" after an hour or two (with qwen1.5 72b tp=4)
interestingly, the GPU-Utils were stuck at 100% but powers were low, and a few request stuck as running:
INFO 04-20 05:44:38 metrics.py:218] Avg prompt throughput: 0.0 tokens/s, Avg generation throughput: 0.0 tokens/s, Running: 10 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 17.1%, CPU KV cache usage: 0.0%

full log:
vllmlog_20240420_eginedead.log

will try export VLLM_TRACE_FUNCTION=1 and smaller size model without TP/ray

[ljqiff]

i have same problem,when i use 8A800 to run Qwen2-72b. But i use 4A800,it can work.

[supdizh]

i have same problem,when i use 8_A800 to run Qwen2-72b. But i use 4_A800,it can work.

you could try using TP with multi-process instead of ray, I'm fine with mp
--distributed-executor-backend mp

[ljqiff]

已收到你的邮件。

[github-actions]

This issue has been automatically marked as stale because it has not had any activity within 90 days. It will be automatically closed if no further activity occurs within 30 days. Leave a comment if you feel this issue should remain open. Thank you!