[Bug]: infinite empty scheduling on large mm input

[MacroBull]

Your current environment

The output of python collect_env.py

Collecting environment information...
==============================
        System Info
==============================
OS                           : Ubuntu 22.04.5 LTS (x86_64)
GCC version                  : (Ubuntu 11.4.0-1ubuntu1~22.04) 11.4.0
Clang version                : Could not collect
CMake version                : Could not collect
Libc version                 : glibc-2.35

==============================
       PyTorch Info
==============================
PyTorch version              : 2.7.1+cu126
Is debug build               : False
CUDA used to build PyTorch   : 12.6
ROCM used to build PyTorch   : N/A

==============================
      Python Environment
==============================
Python version               : 3.12.9 | packaged by conda-forge | (main, Feb 14 2025, 08:00:06) [GCC 13.3.0] (64-bit runtime)
Python platform              : Linux-4.18.0-193.6.3.el8_2.v1.6.x86_64-x86_64-with-glibc2.35

==============================
       CUDA / GPU Info
==============================
Is CUDA available            : True
CUDA runtime version         : 12.6.77
CUDA_MODULE_LOADING set to   : LAZY
GPU models and configuration : 
GPU 0: NVIDIA H20
GPU 1: NVIDIA H20

Nvidia driver version        : 535.216.01
cuDNN version                : Probably one of the following:
/usr/lib/x86_64-linux-gnu/libcudnn.so.9.5.0
/usr/lib/x86_64-linux-gnu/libcudnn_adv.so.9.5.0
/usr/lib/x86_64-linux-gnu/libcudnn_cnn.so.9.5.0
/usr/lib/x86_64-linux-gnu/libcudnn_engines_precompiled.so.9.5.0
/usr/lib/x86_64-linux-gnu/libcudnn_engines_runtime_compiled.so.9.5.0
/usr/lib/x86_64-linux-gnu/libcudnn_graph.so.9.5.0
/usr/lib/x86_64-linux-gnu/libcudnn_heuristic.so.9.5.0
/usr/lib/x86_64-linux-gnu/libcudnn_ops.so.9.5.0
HIP runtime version          : N/A
MIOpen runtime version       : N/A
Is XNNPACK available         : True

==============================
          CPU Info
==============================
Architecture:                    x86_64
CPU op-mode(s):                  32-bit, 64-bit
Address sizes:                   52 bits physical, 57 bits virtual
Byte Order:                      Little Endian
CPU(s):                          192
On-line CPU(s) list:             0-191
Vendor ID:                       GenuineIntel
Model name:                      Intel(R) Xeon(R) Platinum 8468V
CPU family:                      6
Model:                           143
Thread(s) per core:              2
Core(s) per socket:              48
Socket(s):                       2
Stepping:                        8
CPU max MHz:                     3800.0000
CPU min MHz:                     800.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 tsc_known_freq 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 cat_l2 cdp_l3 invpcid_single cdp_l2 ssbd mba ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid fsgsbase tsc_adjust bmi1 hle avx2 smep bmi2 erms invpcid rtm 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 avx512_bf16 wbnoinvd dtherm ida arat pln pts hwp hwp_act_window hwp_epp hwp_pkg_req avx512vbmi umip pku ospke waitpkg avx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg tme avx512_vpopcntdq la57 rdpid cldemote movdiri movdir64b md_clear pconfig flush_l1d arch_capabilities
Virtualization:                  VT-x
L1d cache:                       4.5 MiB (96 instances)
L1i cache:                       3 MiB (96 instances)
L2 cache:                        192 MiB (96 instances)
L3 cache:                        195 MiB (2 instances)
NUMA node(s):                    2
NUMA node0 CPU(s):               0-47,96-143
NUMA node1 CPU(s):               48-95,144-191
Vulnerability Itlb multihit:     Not affected
Vulnerability L1tf:              Not affected
Vulnerability Mds:               Not affected
Vulnerability Meltdown:          Not affected
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
Vulnerability Srbds:             Not affected
Vulnerability Tsx async abort:   Not affected

==============================
Versions of relevant libraries
==============================
[pip3] flashinfer-python==0.2.14.post1
[pip3] numpy==2.2.6
[pip3] nvidia-cublas-cu12==12.6.4.1
[pip3] nvidia-cuda-cupti-cu12==12.6.80
[pip3] nvidia-cuda-nvrtc-cu12==12.6.77
[pip3] nvidia-cuda-runtime-cu12==12.6.77
[pip3] nvidia-cudnn-cu12==9.5.1.17
[pip3] nvidia-cudnn-frontend==1.14.0
[pip3] nvidia-cufft-cu12==11.3.0.4
[pip3] nvidia-cufile-cu12==1.11.1.6
[pip3] nvidia-curand-cu12==10.3.7.77
[pip3] nvidia-cusolver-cu12==11.7.1.2
[pip3] nvidia-cusparse-cu12==12.5.4.2
[pip3] nvidia-cusparselt-cu12==0.6.3
[pip3] nvidia-ml-py==12.575.51
[pip3] nvidia-nccl-cu12==2.26.2
[pip3] nvidia-nvjitlink-cu12==12.6.85
[pip3] nvidia-nvtx-cu12==12.6.77
[pip3] pynvml==12.0.0
[pip3] pyzmq==27.0.2
[pip3] torch==2.7.1
[pip3] torchaudio==2.7.1
[pip3] torchvision==0.22.1
[pip3] transformers==4.55.3
[pip3] triton==3.3.1
[conda] Could not collect

==============================
         vLLM Info
==============================
ROCM Version                 : Could not collect
vLLM Version                 : 0.10.1.1
vLLM Build Flags:
  CUDA Archs: Not Set; ROCm: Disabled
GPU Topology:
        GPU0    GPU1    NIC0    NIC1    NIC2    NIC3    NIC4    NIC5    NIC6    NIC7    NIC8    NIC9    CPU Affinity    NUMA Affinity   GPU NUMA ID
GPU0     X      NV18    SYS     SYS     SYS     SYS     SYS     SYS     PIX     NODE    NODE    NODE    48-95,144-191   1               N/A
GPU1    NV18     X      SYS     SYS     SYS     SYS     SYS     SYS     NODE    PIX     NODE    NODE    48-95,144-191   1               N/A
NIC0    SYS     SYS      X      NODE    NODE    NODE    NODE    NODE    SYS     SYS     SYS     SYS
NIC1    SYS     SYS     NODE     X      PIX     NODE    NODE    NODE    SYS     SYS     SYS     SYS
NIC2    SYS     SYS     NODE    PIX      X      NODE    NODE    NODE    SYS     SYS     SYS     SYS
NIC3    SYS     SYS     NODE    NODE    NODE     X      NODE    NODE    SYS     SYS     SYS     SYS
NIC4    SYS     SYS     NODE    NODE    NODE    NODE     X      NODE    SYS     SYS     SYS     SYS
NIC5    SYS     SYS     NODE    NODE    NODE    NODE    NODE     X      SYS     SYS     SYS     SYS
NIC6    PIX     NODE    SYS     SYS     SYS     SYS     SYS     SYS      X      NODE    NODE    NODE
NIC7    NODE    PIX     SYS     SYS     SYS     SYS     SYS     SYS     NODE     X      NODE    NODE
NIC8    NODE    NODE    SYS     SYS     SYS     SYS     SYS     SYS     NODE    NODE     X      NODE
NIC9    NODE    NODE    SYS     SYS     SYS     SYS     SYS     SYS     NODE    NODE    NODE     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
  NIC2: mlx5_2
  NIC3: mlx5_3
  NIC4: mlx5_4
  NIC5: mlx5_5
  NIC6: mlx5_6
  NIC7: mlx5_7
  NIC8: mlx5_8
  NIC9: mlx5_9

==============================
     Environment Variables
==============================
VLLM_USE_MODELSCOPE=1
TORCHINDUCTOR_MAX_COMPILE_WORKERS=16
CUDA_PATH=/usr/local/cuda
MAX_JOBS=4
LD_LIBRARY_PATH=/usr/local/nvidia/lib:/usr/local/nvidia/lib64:/usr/local/cuda/compat/lib:/usr/local/cuda/lib64
OMP_NUM_THREADS=16
CUDA_HOME=/usr/local/cuda
CUDA_HOME=/usr/local/cuda
NCCL_CUMEM_ENABLE=0
PYTORCH_NVML_BASED_CUDA_CHECK=1
TORCHINDUCTOR_COMPILE_THREADS=1
CUDA_MODULE_LOADING=LAZY

🐛 Describe the bug

Serve

vllm serve Qwen/Qwen2.5-VL-72B-Instruct-AWQ --port 8011 --host 0.0.0.0 --uvicorn-log-level info --cpu-offload-gb 0 --max-model-len 32768 --limit-mm-per-prompt {"image":5,"video":2} --allowed-local-media-path /home --skip-mm-profiling --gpu-memory-utilization 0.9

Generate

{
    "messages": [
        {
            "role": "system",
            "content": [
                {"type": "text", "text": "describe the video"},
                {
                    "type": "video_url",
                    "video_url": {
                        "url": "file:///home/cache/ec8fdb302486a171fe3e41a90bd0176bc05e99b2.mp4"
                    },
                },
            ],
        }
    ],
    "model": "Qwen/Qwen2.5-VL-72B-Instruct-AWQ",
    "seed": 42,
    "temperature": 0.2,
    "top_p": 0.1,
}  

Bug

The sever gives no response when the video is large (~22272 tokens) but ok when it is small(~6093 tokens).

When stuck, the worker process takes 100% cpu and 0% gpu, the stack dump from py-spy looks like:

Process 1829647: VLLM::EngineCore
Python v3.12.9 (envs/vllm/bin/python3.12)

Thread 1829647 (active+gil): "MainThread"
get_num_common_prefix_blocks (vllm/v1/core/single_type_kv_cache_manager.py:288)
get_num_common_prefix_blocks (vllm/v1/core/kv_cache_coordinator.py:138)
get_num_common_prefix_blocks (vllm/v1/core/kv_cache_manager.py:340)
schedule (vllm/v1/core/sched/scheduler.py:540)
step (vllm/v1/engine/core.py:287)
_process_engine_step (vllm/v1/engine/core.py:745)
run_busy_loop (vllm/v1/engine/core.py:720)
run_engine_core (vllm/v1/engine/core.py:693)
run (multiprocessing/process.py:108)
_bootstrap (multiprocessing/process.py:314)
_main (multiprocessing/spawn.py:135)
spawn_main (multiprocessing/spawn.py:122)
<module> (<string>:1)

After adding some log to scheduler and re-run, I found vllm keeps yielding empty CachedRequestData after the initial NewRequestData:

(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:364] Peek: Request(request_id='chatcmpl-6a6c3339308745f187d685a4aad4d320', client_index=0, priority=0, status=WAITING, num_prompt_tokens=22320, num_output_tokens=0, num_encoder_inputs=1, has_encoder_inputs=True, max_tokens=32719, eos_token_id=151645, lora_request=None, structured_output_request=set, cache_salt=None, block_hashes_dim=1395, output_token_ids_dim=0, all_token_ids_dim=22320, mm_positions_dim=1, mm_kwargs_dim=1, mm_hashes_dim=1)
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:440] num_new_tokens=22320 num_tokens=22320 num_computed_tokens=0
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:463] num_new_tokens=8192 token_budget=8192
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:530] Added running_req: Request(request_id='chatcmpl-6a6c3339308745f187d685a4aad4d320', client_index=0, priority=0, status=WAITING, num_prompt_tokens=22320, num_output_tokens=0, num_encoder_inputs=1, has_encoder_inputs=True, max_tokens=32719, eos_token_id=151645, lora_request=None, structured_output_request=set, cache_salt=None, block_hashes_dim=1395, output_token_ids_dim=0, all_token_ids_dim=22320, mm_positions_dim=1, mm_kwargs_dim=1, mm_hashes_dim=1)
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:548] num_new_tokens=42 token_budget=8150
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:641] output: SchedulerOutput(scheduled_new_reqs=[NewRequestData(req_id=chatcmpl-6a6c3339308745f187d685a4aad4d320,...,block_ids=([1, 2, 3],),num_computed_tokens=0,lora_request=None)], scheduled_cached_reqs=CachedRequestData(req_ids=[], resumed_from_preemption=[], new_token_ids=[], new_block_ids=[], num_computed_tokens=[]), num_scheduled_tokens={'chatcmpl-6a6c3339308745f187d685a4aad4d320': 42}, total_num_scheduled_tokens=42, scheduled_spec_decode_tokens={}, scheduled_encoder_inputs={}, num_common_prefix_blocks=[3], finished_req_ids=set(), free_encoder_input_ids=[], structured_output_request_ids={}, grammar_bitmask=None, kv_connector_metadata=None)
(EngineCore_0 pid=2029978) WARNING 09-29 20:09:30 [topk_topp_sampler.py:102] FlashInfer 0.2.3+ does not support per-request generators. Falling back to PyTorch-native implementation.
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:209] num_new_tokens=22278 num_tokens_with_spec=22320 num_output_placeholders=0 num_computed_tokens=42
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:219] num_new_tokens=22278 long_prefill_token_threshold=0
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:224] num_new_tokens=8192 token_budget=8192
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:234] num_new_tokens=8192 max_model_len=32768
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:641] output: SchedulerOutput(scheduled_new_reqs=[], scheduled_cached_reqs=CachedRequestData(req_ids=[], resumed_from_preemption=[], new_token_ids=[], new_block_ids=[], num_computed_tokens=[]), num_scheduled_tokens={}, total_num_scheduled_tokens=0, scheduled_spec_decode_tokens={}, scheduled_encoder_inputs={}, num_common_prefix_blocks=[3], finished_req_ids=set(), free_encoder_input_ids=[], structured_output_request_ids={}, grammar_bitmask=None, kv_connector_metadata=None)
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:209] num_new_tokens=22278 num_tokens_with_spec=22320 num_output_placeholders=0 num_computed_tokens=42
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:219] num_new_tokens=22278 long_prefill_token_threshold=0
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:224] num_new_tokens=8192 token_budget=8192
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:234] num_new_tokens=8192 max_model_len=32768
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:641] output: SchedulerOutput(scheduled_new_reqs=[], scheduled_cached_reqs=CachedRequestData(req_ids=[], resumed_from_preemption=[], new_token_ids=[], new_block_ids=[], num_computed_tokens=[]), num_scheduled_tokens={}, total_num_scheduled_tokens=0, scheduled_spec_decode_tokens={}, scheduled_encoder_inputs={}, num_common_prefix_blocks=[3], finished_req_ids=set(), free_encoder_input_ids=[], structured_output_request_ids={}, grammar_bitmask=None, kv_connector_metadata=None)
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:209] num_new_tokens=22278 num_tokens_with_spec=22320 num_output_placeholders=0 num_computed_tokens=42
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:219] num_new_tokens=22278 long_prefill_token_threshold=0
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:224] num_new_tokens=8192 token_budget=8192
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:234] num_new_tokens=8192 max_model_len=32768
(EngineCore_0 pid=2029978) INFO 09-29 20:09:30 [scheduler.py:641] output: SchedulerOutput(scheduled_new_reqs=[], scheduled_cached_reqs=CachedRequestData(req_ids=[], resumed_from_preemption=[], new_token_ids=[], new_block_ids=[], num_computed_tokens=[]), num_scheduled_tokens={}, total_num_scheduled_tokens=0, scheduled_spec_decode_tokens={}, scheduled_encoder_inputs={}, num_common_prefix_blocks=[3], finished_req_ids=set(), free_encoder_input_ids=[], structured_output_request_ids={}, grammar_bitmask=None, kv_connector_metadata=None)
...

It looks like in
_try_schedule_encoder_inputs, when not disable_chunked_mm_input and num_new_tokens(of mm, not to split) > encoder_compute_budget(no more than max-num-batched-tokens), 0 tokens will be scheduled so the request is never processed.

An obvious solution is to add --max-num-batched-tokens 32768 to serve arguments, but for the issue, this invalid config is validated in V0 & vllm <= 0.8 and aborted with an error.

The bug is why V1 ignores this.

Before submitting a new issue...

• Make sure you already searched for relevant issues, and asked the chatbot living at the bottom right corner of the documentation page, which can answer lots of frequently asked questions.

[DarkLight1337]

Can you try upgrading to v0.10.2? I think this should be fixed by #21798 already?

[DarkLight1337]

cc @ywang96

[DarkLight1337]

Related to #23338

[ywang96]

Can you check which version of vLLM you're on? In particular, in V1 when you start the server it should say something like

(EngineCore_DP0 pid=3657648) INFO 09-29 17:33:27 [gpu_model_runner.py:3261] Encoder cache will be initialized with a budget of 114688 tokens, and profiled with 1 video items of the maximum feature size.

If the number showed in this log is smaller than the length of video tokens in your request then it'll be never scheduled. This was a a bug that we fixed recently, and should be available in 10.2

[MacroBull]

Can you check which version of vLLM you're on? In particular, in V1 when you start the server it should say something like

(EngineCore_DP0 pid=3657648) INFO 09-29 17:33:27 [gpu_model_runner.py:3261] Encoder cache will be initialized with a budget of 114688 tokens, and profiled with 1 video items of the maximum feature size.

If the number showed in this log is smaller than the length of video tokens in your request then it'll be never scheduled. This was a a bug that we fixed recently, and should be available in 10.2

Nice, it works!

I upgraded from v0.10.1 to v0.10.2, the mm_budget log shows, and the large video is processed.

Although I don’t know how it works, it goes even with --skip-mm-profiling. Thanks! I’ll close this issue :)