search

vllm-project / vllm

A high-throughput and memory-efficient inference and serving engine for LLMs
https://docs.vllm.ai
Apache License 2.0
30.7k stars 4.66k forks source link

[Bug]: AsyncLLMEngine hangs when using `asyncio.gather` with vllm version 0.5.5 #8393

Open pengye91 opened 2 months ago

pengye91 commented 2 months ago

Your current environment

The output of `python collect_env.py` ```text Collecting environment information... PyTorch version: 2.4.0+cu121 Is debug build: False CUDA used to build PyTorch: 12.1 ROCM used to build PyTorch: N/A OS: Debian GNU/Linux 12 (bookworm) (x86_64) GCC version: (Debian 12.2.0-14) 12.2.0 Clang version: Could not collect CMake version: version 3.30.2 Libc version: glibc-2.36 Python version: 3.12.4 | packaged by Anaconda, Inc. | (main, Jun 18 2024, 15:12:24) [GCC 11.2.0] (64-bit runtime) Python platform: Linux-5.4.0-164-generic-x86_64-with-glibc2.36 Is CUDA available: True CUDA runtime version: Could not collect CUDA_MODULE_LOADING set to: LAZY GPU models and configuration: GPU 0: Tesla V100-SXM2-32GB GPU 1: Tesla V100-SXM2-32GB GPU 2: Tesla V100-SXM2-32GB GPU 3: Tesla V100-SXM2-32GB GPU 4: Tesla V100-SXM2-32GB GPU 5: Tesla V100-SXM2-32GB GPU 6: Tesla V100-SXM2-32GB GPU 7: Tesla V100-SXM2-32GB Nvidia driver version: 535.104.12 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, 48 bits virtual Byte Order: Little Endian CPU(s): 96 On-line CPU(s) list: 0-95 Vendor ID: GenuineIntel Model name: Intel(R) Xeon(R) Platinum 8260 CPU @ 2.40GHz CPU family: 6 Model: 85 Thread(s) per core: 2 Core(s) per socket: 24 Socket(s): 2 Stepping: 7 CPU(s) scaling MHz: 79% CPU max MHz: 3900.0000 CPU min MHz: 1000.0000 BogoMIPS: 4800.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 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 cdp_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 mpx rdt_a avx512f avx512dq rdseed adx smap clflushopt clwb intel_pt avx512cd avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves cqm_llc cqm_occup_llc cqm_mbm_total cqm_mbm_local dtherm ida arat pln pts hwp hwp_act_window hwp_epp hwp_pkg_req pku ospke avx512_vnni md_clear flush_l1d arch_capabilities Virtualization: VT-x L1d cache: 1.5 MiB (48 instances) L1i cache: 1.5 MiB (48 instances) L2 cache: 48 MiB (48 instances) L3 cache: 71.5 MiB (2 instances) NUMA node(s): 2 NUMA node0 CPU(s): 0-23,48-71 NUMA node1 CPU(s): 24-47,72-95 Vulnerability Gather data sampling: Mitigation; Microcode Vulnerability Itlb multihit: KVM: Mitigation: Split huge pages Vulnerability L1tf: Not affected Vulnerability Mds: Not affected Vulnerability Meltdown: Not affected Vulnerability Mmio stale data: Mitigation; Clear CPU buffers; SMT vulnerable Vulnerability Retbleed: Mitigation; Enhanced IBRS Vulnerability Spec store bypass: Mitigation; Speculative Store Bypass disabled via prctl and seccomp 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: Mitigation; TSX disabled Versions of relevant libraries: [pip3] numpy==1.26.4 [pip3] nvidia-cublas-cu12==12.1.3.1 [pip3] nvidia-cuda-cupti-cu12==12.1.105 [pip3] nvidia-cuda-nvrtc-cu12==12.1.105 [pip3] nvidia-cuda-runtime-cu12==12.1.105 [pip3] nvidia-cudnn-cu12==9.1.0.70 [pip3] nvidia-cufft-cu12==11.0.2.54 [pip3] nvidia-curand-cu12==10.3.2.106 [pip3] nvidia-cusolver-cu12==11.4.5.107 [pip3] nvidia-cusparse-cu12==12.1.0.106 [pip3] nvidia-ml-py==12.560.30 [pip3] nvidia-nccl-cu12==2.20.5 [pip3] nvidia-nvjitlink-cu12==12.6.20 [pip3] nvidia-nvtx-cu12==12.1.105 [pip3] pyzmq==26.1.1 [pip3] sentence-transformers==3.0.1 [pip3] torch==2.4.0 [pip3] torchvision==0.19.0 [pip3] transformers==4.44.0 [pip3] triton==3.0.0 [conda] numpy 1.26.4 pypi_0 pypi [conda] nvidia-cublas-cu12 12.1.3.1 pypi_0 pypi [conda] nvidia-cuda-cupti-cu12 12.1.105 pypi_0 pypi [conda] nvidia-cuda-nvrtc-cu12 12.1.105 pypi_0 pypi [conda] nvidia-cuda-runtime-cu12 12.1.105 pypi_0 pypi [conda] nvidia-cudnn-cu12 9.1.0.70 pypi_0 pypi [conda] nvidia-cufft-cu12 11.0.2.54 pypi_0 pypi [conda] nvidia-curand-cu12 10.3.2.106 pypi_0 pypi [conda] nvidia-cusolver-cu12 11.4.5.107 pypi_0 pypi [conda] nvidia-cusparse-cu12 12.1.0.106 pypi_0 pypi [conda] nvidia-ml-py 12.560.30 pypi_0 pypi [conda] nvidia-nccl-cu12 2.20.5 pypi_0 pypi [conda] nvidia-nvjitlink-cu12 12.6.20 pypi_0 pypi [conda] nvidia-nvtx-cu12 12.1.105 pypi_0 pypi [conda] pyzmq 26.1.1 pypi_0 pypi [conda] sentence-transformers 3.0.1 pypi_0 pypi [conda] torch 2.4.0 pypi_0 pypi [conda] torchvision 0.19.0 pypi_0 pypi [conda] transformers 4.44.0 pypi_0 pypi [conda] triton 3.0.0 pypi_0 pypi ROCM Version: Could not collect Neuron SDK Version: N/A vLLM Version: 0.5.5@09c7792610ada9f88bbf87d32b472dd44bf23cc2 vLLM Build Flags: CUDA Archs: Not Set; ROCm: Disabled; Neuron: Disabled GPU Topology: GPU0 GPU1 GPU2 GPU3 GPU4 GPU5 GPU6 GPU7 NIC0 NIC1 CPU Affinity NUMA Affinity GPU NUMA ID GPU0 X NV1 NV2 NV1 SYS SYS SYS NV2 SYS SYS 0-23,48-71 0 N/A GPU1 NV1 X NV1 NV2 SYS SYS NV2 SYS SYS SYS 0-23,48-71 0 N/A GPU2 NV2 NV1 X NV2 SYS NV1 SYS SYS SYS SYS 0-23,48-71 0 N/A GPU3 NV1 NV2 NV2 X NV1 SYS SYS SYS SYS SYS 0-23,48-71 0 N/A GPU4 SYS SYS SYS NV1 X NV2 NV2 NV1 NODE NODE 24-47,72-95 1 N/A GPU5 SYS SYS NV1 SYS NV2 X NV1 NV2 NODE NODE 24-47,72-95 1 N/A GPU6 SYS NV2 SYS SYS NV2 NV1 X NV1 PIX PIX 24-47,72-95 1 N/A GPU7 NV2 SYS SYS SYS NV1 NV2 NV1 X PIX PIX 24-47,72-95 1 N/A NIC0 SYS SYS SYS SYS NODE NODE PIX PIX X PIX NIC1 SYS SYS SYS SYS NODE NODE PIX PIX PIX 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_1 ```

Model Input Dumps

No response

🐛 Describe the bug

I'm simply change a little bit of the api_server.py to serve with multiple prompts and using asyncio.gather to wait all responses to be ready.

the log shows that all requests can successfully finishes, but the response can't be returned from the asyncio.gather, it just hangs forever until timeout.

"""
NOTE: This API server is used only for demonstrating usage of AsyncEngine
and simple performance benchmarks. It is not intended for production use.
For production use, we recommend using our OpenAI compatible server.
We are also not going to accept PRs modifying this file, please
change `vllm/entrypoints/openai/api_server.py` instead.
"""
import asyncio
import json
import ssl
from argparse import Namespace
from typing import Any, AsyncGenerator, Optional

from fastapi import FastAPI, Request
from fastapi.responses import JSONResponse, Response, StreamingResponse

from vllm.engine.arg_utils import AsyncEngineArgs
from vllm.engine.async_llm_engine import AsyncLLMEngine
from vllm.entrypoints.launcher import serve_http
from vllm.logger import init_logger
from vllm.sampling_params import SamplingParams
from vllm.usage.usage_lib import UsageContext
from vllm.utils import (FlexibleArgumentParser, iterate_with_cancellation,
                        random_uuid)
from vllm.version import __version__ as VLLM_VERSION
from transformers import AutoTokenizer

logger = init_logger("vllm.entrypoints.api_server")

TIMEOUT_KEEP_ALIVE = 5  # seconds.
app = FastAPI()
engine = None
tokenizer = None

@app.get("/health")
async def health() -> Response:
    """Health check."""
    return Response(status_code=200)

@app.post("/batch_chat")
async def generate(request: Request) -> Response:
    """Generate completion for the request.

    The request should be a JSON object with the following fields:
    - prompt: the prompt to use for the generation.
    - stream: whether to stream the results or not.
    - other fields: the sampling parameters (See `SamplingParams` for details).
    """
    request_dict = await request.json()
    prompts = request_dict.pop("texts")
    stream = request_dict.pop("stream", False)
    sampling_params = SamplingParams(**request_dict)
    request_id = random_uuid()
    messages = [[
        {"role": "system", "content": "You are a helpful assistant."},
        {"role": "user", "content": prompt}
    ] for prompt in prompts]
    texts = [tokenizer.apply_chat_template(message, tokenize=False, add_generation_prompt=True) for message in messages]

    assert engine is not None
    results_generators = [iterate_with_cancellation(engine.generate(text, sampling_params, request_id) , is_cancelled=request.is_disconnected) for text in texts]

    async def process_generator(results_generator) -> str:
        final_output = None
        async for request_output in results_generator:
            final_output = request_output

        text_outputs = final_output.outputs[0].text
        return text_outputs

    tasks = [process_generator(results_generator) for results_generator in results_generators]
    outputs = await asyncio.gather(*tasks)
    return JSONResponse(content={"response": outputs})

def build_app(args: Namespace) -> FastAPI:
    global app

    app.root_path = args.root_path
    return app

async def init_app(
    args: Namespace,
    llm_engine: Optional[AsyncLLMEngine] = None,
) -> FastAPI:
    app = build_app(args)

    global engine
    global tokenizer

    engine_args = AsyncEngineArgs.from_cli_args(args)
    engine = (llm_engine
              if llm_engine is not None else AsyncLLMEngine.from_engine_args(
                  engine_args, usage_context=UsageContext.API_SERVER))

    tokenizer = AutoTokenizer.from_pretrained(engine_args.model, padding_side="left")
    return app

async def run_server(args: Namespace,
                     llm_engine: Optional[AsyncLLMEngine] = None,
                     **uvicorn_kwargs: Any) -> None:
    logger.info("vLLM API server version %s", VLLM_VERSION)
    logger.info("args: %s", args)

    app = await init_app(args, llm_engine)
    assert engine is not None

    shutdown_task = await serve_http(
        app,
        engine=engine,
        host=args.host,
        port=args.port,
        log_level=args.log_level,
        timeout_keep_alive=TIMEOUT_KEEP_ALIVE,
        ssl_keyfile=args.ssl_keyfile,
        ssl_certfile=args.ssl_certfile,
        ssl_ca_certs=args.ssl_ca_certs,
        ssl_cert_reqs=args.ssl_cert_reqs,
        **uvicorn_kwargs,
    )

    await shutdown_task

if __name__ == "__main__":
    parser = FlexibleArgumentParser()
    parser.add_argument("--host", type=str, default=None)
    parser.add_argument("--port", type=int, default=8000)
    parser.add_argument("--ssl-keyfile", type=str, default=None)
    parser.add_argument("--ssl-certfile", type=str, default=None)
    parser.add_argument("--ssl-ca-certs",
                        type=str,
                        default=None,
                        help="The CA certificates file")
    parser.add_argument(
        "--ssl-cert-reqs",
        type=int,
        default=int(ssl.CERT_NONE),
        help="Whether client certificate is required (see stdlib ssl module's)"
    )
    parser.add_argument(
        "--root-path",
        type=str,
        default=None,
        help="FastAPI root_path when app is behind a path based routing proxy")
    parser.add_argument("--log-level", type=str, default="debug")
    parser = AsyncEngineArgs.add_cli_args(parser)
    args = parser.parse_args()

    asyncio.run(run_server(args))

the server launch command:

python api_server.py --model=/root/.cache/huggingface/hub/models--Qwen--Qwen2-72B-Instruct/snapshots/1af63c698f59c4235668ec9c1395468cb7cd7e79/ --disable-log-stats --enforce-eager --tensor-parallel-size=8 --dtype=float16

the trace log file is too large, I picked the repeated part when the server hangs here:

vllm_trace.log

the prompts are simply a list of two strings: ['who are you', 'who are you'].

the logs of the server:

INFO:     Started server process [708619]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:     Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
INFO 09-12 10:33:05 async_llm_engine.py:208] Added request 1052656a5d7f4a9785b84d122dfc7200.
INFO 09-12 10:33:05 async_llm_engine.py:208] Added request 1052656a5d7f4a9785b84d122dfc7200.
DEBUG 09-12 10:33:05 async_llm_engine.py:899] Waiting for new requests...
DEBUG 09-12 10:33:05 async_llm_engine.py:913] Got new requests!
INFO 09-12 10:33:44 async_llm_engine.py:176] Finished request 1052656a5d7f4a9785b84d122dfc7200.
INFO 09-12 10:33:49 async_llm_engine.py:176] Finished request 1052656a5d7f4a9785b84d122dfc7200.
DEBUG 09-12 10:33:49 async_llm_engine.py:899] Waiting for new requests...

I know there are some related issues, but it seems the problem still exists after the fix.

Before submitting a new issue...

pengye91 commented 2 months ago

checked with a smaller model Qwen/Qwen2-0.5B-Instruct, the issue remains.

DarkLight1337 commented 2 months ago

Can you check whether this issue still persists in the current version (0.6.1)?

pengye91 commented 2 months ago

Can you check whether this issue still persists in the current version (0.6.1)?

@DarkLight1337 still persists.

INFO 09-12 15:31:12 llm_engine.py:232] Initializing an LLM engine (v0.6.1) with config: model='/root/.cache/huggingface/hub/models--Qwen--Qwen2-0.5B-Instruct/snapshots/c540970f9e29518b1d8f06ab8b24cba66ad77b6d/', speculative_config=None, tokenizer='/root/.cache/huggingface/hub/models--Qwen--Qwen2-0.5B-Instruct/snapshots/c540970f9e29518b1d8f06ab8b24cba66ad77b6d/', skip_tokenizer_init=False, tokenizer_mode=auto, revision=None, override_neuron_config=None, rope_scaling=None, rope_theta=None, tokenizer_revision=None, trust_remote_code=False, dtype=torch.float16, max_seq_len=32768, download_dir=None, load_format=LoadFormat.AUTO, tensor_parallel_size=1, pipeline_parallel_size=1, disable_custom_all_reduce=False, quantization=None, enforce_eager=True, kv_cache_dtype=auto, quantization_param_path=None, device_config=cuda, decoding_config=DecodingConfig(guided_decoding_backend='outlines'), observability_config=ObservabilityConfig(otlp_traces_endpoint=None, collect_model_forward_time=False, collect_model_execute_time=False), seed=0, served_model_name=/root/.cache/huggingface/hub/models--Qwen--Qwen2-0.5B-Instruct/snapshots/c540970f9e29518b1d8f06ab8b24cba66ad77b6d/, use_v2_block_manager=False, num_scheduler_steps=1, enable_prefix_caching=False, use_async_output_proc=False)
INFO 09-12 15:31:13 selector.py:217] Cannot use FlashAttention-2 backend for Volta and Turing GPUs.
INFO 09-12 15:31:13 selector.py:116] Using XFormers backend.
/root/miniconda3/lib/python3.12/site-packages/xformers/ops/fmha/flash.py:211: FutureWarning: `torch.library.impl_abstract` was renamed to `torch.library.register_fake`. Please use that instead; we will remove `torch.library.impl_abstract` in a future version of PyTorch.
  @torch.library.impl_abstract("xformers_flash::flash_fwd")
/root/miniconda3/lib/python3.12/site-packages/xformers/ops/fmha/flash.py:344: FutureWarning: `torch.library.impl_abstract` was renamed to `torch.library.register_fake`. Please use that instead; we will remove `torch.library.impl_abstract` in a future version of PyTorch.
  @torch.library.impl_abstract("xformers_flash::flash_bwd")
DEBUG 09-12 15:31:13 parallel_state.py:845] world_size=1 rank=0 local_rank=0 distributed_init_method=tcp://172.16.184.78:52183 backend=nccl
INFO 09-12 15:31:13 model_runner.py:997] Starting to load model /root/.cache/huggingface/hub/models--Qwen--Qwen2-0.5B-Instruct/snapshots/c540970f9e29518b1d8f06ab8b24cba66ad77b6d/...
INFO 09-12 15:31:14 selector.py:217] Cannot use FlashAttention-2 backend for Volta and Turing GPUs.
INFO 09-12 15:31:14 selector.py:116] Using XFormers backend.
Loading safetensors checkpoint shards:   0% Completed | 0/1 [00:00<?, ?it/s]
Loading safetensors checkpoint shards: 100% Completed | 1/1 [00:00<00:00,  1.78it/s]
Loading safetensors checkpoint shards: 100% Completed | 1/1 [00:00<00:00,  1.78it/s]

INFO 09-12 15:31:14 model_runner.py:1008] Loading model weights took 0.9276 GB
INFO 09-12 15:31:15 gpu_executor.py:122] # GPU blocks: 135941, # CPU blocks: 21845
INFO 09-12 15:31:19 launcher.py:20] Available routes are:
INFO 09-12 15:31:19 launcher.py:28] Route: /openapi.json, Methods: HEAD, GET
INFO 09-12 15:31:19 launcher.py:28] Route: /docs, Methods: HEAD, GET
INFO 09-12 15:31:19 launcher.py:28] Route: /docs/oauth2-redirect, Methods: HEAD, GET
INFO 09-12 15:31:19 launcher.py:28] Route: /redoc, Methods: HEAD, GET
INFO 09-12 15:31:19 launcher.py:28] Route: /health, Methods: GET
INFO 09-12 15:31:19 launcher.py:28] Route: /chat, Methods: POST
INFO 09-12 15:31:19 launcher.py:28] Route: /batch_chat, Methods: POST
INFO:     Started server process [713749]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:     Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
INFO 09-12 15:31:44 async_llm_engine.py:206] Added request 2e70ae2bab0b44638ad1b02aa1ab3902.
INFO 09-12 15:31:44 async_llm_engine.py:206] Added request 2e70ae2bab0b44638ad1b02aa1ab3902.
DEBUG 09-12 15:31:44 async_llm_engine.py:908] Waiting for new requests...
DEBUG 09-12 15:31:44 async_llm_engine.py:922] Got new requests!
INFO 09-12 15:31:44 async_llm_engine.py:174] Finished request 2e70ae2bab0b44638ad1b02aa1ab3902.
INFO 09-12 15:31:45 async_llm_engine.py:174] Finished request 2e70ae2bab0b44638ad1b02aa1ab3902.
DEBUG 09-12 15:31:45 async_llm_engine.py:908] Waiting for new requests...
TOPAPEC commented 1 day ago

Same issue here. Tqdm shows that the last request remains from 60 total, but hangs forever. vllm 0.6.4