[Performance]: Why does VLLM perform worse than TGI in Speculative decoding?

[skylee-01]

Proposal to improve performance

Hello Teacher, it is a great honor to witness your magnificent work. The team I am part of is currently trying to migrate the inference service from TGI to vLLM. However, we have encountered some issues in the effectiveness evaluation and hope that the teachers can provide guidance.

question：
1、Could you please explain why the GPU utilization of vLLM is lower than that of TGI? Is it possible to increase the GPU utilization by adjusting parameters?
2、Why is the QPS of vLLM lower than that of TGI? How should this be considered and optimized?

Report of performance regression

Experimental DataScenario: In the agent scenario, the number of prompt tokens is between 30-40, and the number of output tokens is between 10-20. We have trained a small n-gram model as a draft model (with an accuracy rate of 70% when predicting num_speculative_tokens=4). We used 2,000 different data entries for stress testing.

🚀vLLM
Startup Parameters:
python3 vllm/entrypoints/openai/api_server.py
--served-model-name base_model
--port XXX
--model XX
--max_model_len 1000
--speculative_model="[ngram_pool]"
--num_speculative_tokens 4
--use_v2_block_manager \

QPS: 16 (availability at 500ms is 100%)

GPU Utilization: 70%

🚗TGI
Startup Parameters:
docker run -it --gpus=device=2 --network host
--model-id model_path
--num-shard 1 --port xxx --router-name=xx --max-top-n-tokens=1 --max-input-length=640 --max-total-tokens=960
--waiting-served-ratio=0.5 --max-batch-prefill-tokens=5120 --max-batch-total-tokens=16000 --max-waiting-tokens=16000
--cloudml-opt 1 --cloudml-opt-verbose 1 --trust-remote-code --speculate=4

QPS: 35 (availability at 500ms is 100%)

GPU Utilization:80%

Misc discussion on performance

No response

Your current environment (if you think it is necessary)

The output of `python collect_env.py`

Collecting environment information...
WARNING 08-15 03:20:34 _custom_ops.py:14] Failed to import from vllm._C with ImportError('/home/work/lisiqi23_work/vllm/_C.abi3.so: undefined symbol: _ZN5torch3jit11parseSchemaERKSs')
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: 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.5
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-5.4.54-1.0.0.std7c.el7.2.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 GeForce RTX 3090
GPU 1: NVIDIA GeForce RTX 3090
GPU 2: NVIDIA GeForce RTX 3090
GPU 3: NVIDIA GeForce RTX 3090
GPU 4: NVIDIA GeForce RTX 3090
GPU 5: NVIDIA GeForce RTX 3090
GPU 6: NVIDIA GeForce RTX 3090
GPU 7: NVIDIA GeForce RTX 3090

Nvidia driver version: 535.104.05
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): 72
On-line CPU(s) list: 0-71
Vendor ID: GenuineIntel
Model name: Intel(R) Xeon(R) Gold 6240 CPU @ 2.60GHz
CPU family: 6
Model: 85
Thread(s) per core: 2
Core(s) per socket: 18
Socket(s): 2
Stepping: 7
Frequency boost: enabled
CPU max MHz: 2601.0000
CPU min MHz: 1000.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 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 pku ospke avx512_vnni md_clear flush_l1d arch_capabilities
Virtualization: VT-x
L1d cache: 1.1 MiB (36 instances)
L1i cache: 1.1 MiB (36 instances)
L2 cache: 36 MiB (36 instances)
L3 cache: 49.5 MiB (2 instances)
NUMA node(s): 2
NUMA node0 CPU(s): 0-17,36-53
NUMA node1 CPU(s): 18-35,54-71
Vulnerability Itlb multihit: KVM: Mitigation: Split huge pages
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: Mitigation; TSX disabled

Versions of relevant libraries:
[pip3] numpy==1.26.0
[pip3] nvidia-nccl-cu12==2.20.5
[pip3] pyzmq==26.0.3
[pip3] torch==2.4.0
[pip3] torchvision==0.19.0
[pip3] transformers==4.44.0
[pip3] triton==3.0.0
[conda] Could not collect
ROCM Version: Could not collect
Neuron SDK Version: N/A
vLLM Version: 0.5.2@
vLLM Build Flags:
CUDA Archs: Not Set; ROCm: Disabled; Neuron: Disabled
GPU Topology:
GPU0 GPU1 GPU2 GPU3 GPU4 GPU5 GPU6 GPU7 NIC0 NIC1 CPU AffinityNUMA Affinity GPU NUMA ID
GPU0 X PIX PIX PIX NODE NODE NODE NODE SYS SYS 0-17,36-53 0 N/A
GPU1 PIX X PIX PIX NODE NODE NODE NODE SYS SYS 0-17,36-53 0 N/A
GPU2 PIX PIX X PIX NODE NODE NODE NODE SYS SYS 0-17,36-53 0 N/A
GPU3 PIX PIX PIX X NODE NODE NODE NODE SYS SYS 0-17,36-53 0 N/A
GPU4 NODE NODE NODE NODE X PIX PIX PIX SYS SYS 0-17,36-53 0 N/A
GPU5 NODE NODE NODE NODE PIX X PIX PIX SYS SYS 0-17,36-53 0 N/A
GPU6 NODE NODE NODE NODE PIX PIX X PIX SYS SYS 0-17,36-53 0 N/A
GPU7 NODE NODE NODE NODE PIX PIX PIX X SYS SYS 0-17,36-53 0 N/A
NIC0 SYS SYS SYS SYS SYS SYS SYS SYS X PIX
NIC1 SYS SYS SYS SYS SYS SYS SYS SYS 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

[skylee-01]

Please, teachers, provide some help。 @cadedaniel , @youkaichao

[ShangmingCai]

Maybe you should consider the parameter --speculative-disable-by-batch-size.

Speculative decoding does not always improve token goodput under high workloads. If your SLO availability is abnormal, it is probably because some incoming requests are arranged in the pending queue.

In addition, the definition of the indicators in the benchmark results you provided is vague. Hence, the data in the current table is a bit difficult to understand.

[cadedaniel]

Can you share metrics from the log, including System efficiency and step time of each stage in speculative decoding? These can be used to determine if the issue is in the API server layer or in speculative decoding layer.

[skylee-01]

Thank you very much for your help, below are some metrics data. @cadedaniel

metrics log
INFO 08-20 02:39:37 metrics.py:411] Avg prompt throughput: 871.4 tokens/s, Avg generation throughput: 88.1 tokens/s, Running: 1 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.2%, CPU KV cache usage: 0.0%.
INFO 08-20 02:39:42 metrics.py:411] Avg prompt throughput: 883.5 tokens/s, Avg generation throughput: 85.3 tokens/s, Running: 2 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.4%, CPU KV cache usage: 0.0%.
INFO 08-20 02:40:09 metrics.py:411] Avg prompt throughput: 1134.2 tokens/s, Avg generation throughput: 117.6 tokens/s, Running: 2 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.5%, CPU KV cache usage: 0.0%.
INFO 08-20 02:40:29 metrics.py:411] Avg prompt throughput: 1181.6 tokens/s, Avg generation throughput: 114.5 tokens/s, Running: 2 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.4%, CPU KV cache usage: 0.0%.
INFO 08-20 02:40:34 metrics.py:411] Avg prompt throughput: 1175.3 tokens/s, Avg generation throughput: 116.4 tokens/s, Running: 2 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.4%, CPU KV cache usage: 0.0%.
INFO 08-20 02:40:49 metrics.py:411] Avg prompt throughput: 1454.0 tokens/s, Avg generation throughput: 143.4 tokens/s, Running: 3 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.6%, CPU KV cache usage: 0.0%.
INFO 08-20 02:40:54 metrics.py:411] Avg prompt throughput: 1474.5 tokens/s, Avg generation throughput: 138.6 tokens/s, Running: 4 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.9%, CPU KV cache usage: 0.0%.
INFO 08-20 02:40:59 metrics.py:411] Avg prompt throughput: 1443.6 tokens/s, Avg generation throughput: 143.5 tokens/s, Running: 4 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.9%, CPU KV cache usage: 0.0%.
INFO 08-20 02:41:09 metrics.py:411] Avg prompt throughput: 1473.6 tokens/s, Avg generation throughput: 143.2 tokens/s, Running: 4 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.9%, CPU KV cache usage: 0.0%.
INFO 08-20 02:41:14 metrics.py:411] Avg prompt throughput: 1476.3 tokens/s, Avg generation throughput: 144.9 tokens/s, Running: 6 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 1.4%, CPU KV cache usage: 0.0%.

The metrics results for each request
INFO 08-20 02:40:50 serving_completion.py:176] RequestOutput[]:RequestOutput(request_id=cmpl-35dd069a12a94e96a0977a4217909533-0, prompt=None, prompt_token_ids=[xxxxxxxx], prompt_logprobs=None, outputs=[CompletionOutput(index=0, text='xxx', token_ids=(xxx), cumulative_logprob=None, logprobs=None, finish_reason=None, stop_reason=None)], finished=False, cumulative_logprob=None, logprobs=None, finish_reason=stop, stop_reason=None)], finished=True, metrics=RequestMetrics(arrival_time=1724121650.2600157, last_token_time=1724121650.516544, first_scheduled_time=1724121650.277678, first_token_time=1724121650.2996101, time_in_queue=0.01766228675842285, finished_time=1724121650.5164864), lora_request=None)
INFO 08-20 02:40:59 serving_completion.py:176] RequestOutput[]:RequestOutput(request_id=cmpl-0c3db968d4434480b449144b7d691264-0, prompt=None, prompt_token_ids=[xxxxxxxx], prompt_logprobs=None, outputs=[CompletionOutput(index=0, text='xxx', token_ids=(xxx), cumulative_logprob=None, logprobs=None, finish_reason=None, stop_reason=None)], finished=False, prompt_logprobs=None, outputs=[CompletionOutput(index=0, text='product', token_ids=(3031,), cumulative_logprob=None, logprobs=None, finish_reason=None, stop_reason=None)], finished=False, metrics=RequestMetrics(arrival_time=1724121659.0208986, last_token_time=1724121659.046004, first_scheduled_time=1724121659.0239568, first_token_time=1724121659.0458817, time_in_queue=0.003058195114135742, finished_time=None), lora_request=None)
INFO 08-20 02:41:14 serving_completion.py:176] RequestOutput[]:RequestOutput(request_id=cmpl-7301243ecfab48619fa93a2002abff7f-0, prompt=None, prompt_token_ids=[xxxxxxxx], prompt_logprobs=None, outputs=[CompletionOutput(index=0, text='xxx', token_ids=(xxx), cumulative_logprob=None, logprobs=None, finish_reason=None, stop_reason=None)], finished=False, cumulative_logprob=None, logprobs=None, finish_reason=None, stop_reason=None)], finished=False, metrics=RequestMetrics(arrival_time=1724121674.4457335, last_token_time=1724121674.519317, first_scheduled_time=1724121674.454099, first_token_time=1724121674.474261, time_in_queue=0.008365392684936523, finished_time=None), lora_request=None)

The return results of the Metrics API
HELP python_gc_objects_collected_total Objects collected during gc
TYPE python_gc_objects_collected_total counter
python_gc_objects_collected_total{generation="0"} 90800.0
python_gc_objects_collected_total{generation="1"} 33812.0
python_gc_objects_collected_total{generation="2"} 1103.0
HELP python_gc_objects_uncollectable_total Uncollectable objects found during GC
TYPE python_gc_objects_uncollectable_total counter
python_gc_objects_uncollectable_total{generation="0"} 0.0
python_gc_objects_uncollectable_total{generation="1"} 0.0
python_gc_objects_uncollectable_total{generation="2"} 0.0
HELP python_gc_collections_total Number of times this generation was collected
TYPE python_gc_collections_total counter
python_gc_collections_total{generation="0"} 1396.0
python_gc_collections_total{generation="1"} 125.0
python_gc_collections_total{generation="2"} 79.0
HELP python_info Python platform information
TYPE python_info gauge
python_info{implementation="CPython",major="3",minor="10",patchlevel="12",version="3.10.12"} 1.0
HELP process_virtual_memory_bytes Virtual memory size in bytes.
TYPE process_virtual_memory_bytes gauge
process_virtual_memory_bytes 5.3048090624e+010
HELP process_resident_memory_bytes Resident memory size in bytes.
TYPE process_resident_memory_bytes gauge
process_resident_memory_bytes 7.082962944e+09
HELP process_start_time_seconds Start time of the process since unix epoch in seconds.
TYPE process_start_time_seconds gauge
process_start_time_seconds 1.72412149394e+09
HELP process_cpu_seconds_total Total user and system CPU time spent in seconds.
TYPE process_cpu_seconds_total counter
process_cpu_seconds_total 172.89
HELP process_open_fds Number of open file descriptors.
TYPE process_open_fds gauge
process_open_fds 105.0
HELP process_max_fds Maximum number of open file descriptors.
TYPE process_max_fds gauge
process_max_fds 1.048576e+06
HELP vllm:cache_config_info information of cache_config
TYPE vllm:cache_config_info gauge
vllm:cache_config_info{block_size="16",cache_dtype="auto",cpu_offload_gb="0",enable_prefix_caching="False",gpu_memory_utilization="0.9",num_cpu_blocks="655",num_gpu_blocks="2054",num_gpu_blocks_override="None",sliding_window="None",swap_space_bytes="4294967296"} 1.0
HELP python_gc_objects_collected_total Objects collected during gc
TYPE python_gc_objects_collected_total counter
python_gc_objects_collected_total{generation="0"} 98653.0
python_gc_objects_collected_total{generation="1"} 37145.0
python_gc_objects_collected_total{generation="2"} 1103.0
HELP python_gc_objects_uncollectable_total Uncollectable objects found during GC
TYPE python_gc_objects_uncollectable_total counter
python_gc_objects_uncollectable_total{generation="0"} 0.0
python_gc_objects_uncollectable_total{generation="1"} 0.0
python_gc_objects_uncollectable_total{generation="2"} 0.0
HELP python_gc_collections_total Number of times this generation was collected
TYPE python_gc_collections_total counter
python_gc_collections_total{generation="0"} 1412.0
python_gc_collections_total{generation="1"} 127.0
python_gc_collections_total{generation="2"} 79.0
HELP python_info Python platform information
TYPE python_info gauge
python_info{implementation="CPython",major="3",minor="10",patchlevel="12",version="3.10.12"} 1.0
HELP process_virtual_memory_bytes Virtual memory size in bytes.
TYPE process_virtual_memory_bytes gauge
process_virtual_memory_bytes 5.3048090624e+010
HELP process_resident_memory_bytes Resident memory size in bytes.
TYPE process_resident_memory_bytes gauge
process_resident_memory_bytes 7.083024384e+09

Thank you again for your help.

[skylee-01]

Dear Professor @cadedaniel ,

I have further experimented with this issue.
Using the Nsight system, I obtained the GPU usage of vLLM and TGI under the condition of qps=25.
I found that: between two instances of spec_decode_worker._run_speculative_decoding_step, there are always several instances of spec_decode_worker._run_no_spec inserted. However, the GPU utilization of spec_decode_worker._run_no_spec is relatively low. The GPU fluctuation of TGI is basically consistent, and its utilization is higher compared to vLLM.
I speculate: vLLM inserts prefill between two decodings and does so at a higher frequency. TGI combines multiple prefills.

I would like to ask if my speculation is correct, and if so, how should I optimize this scenario.

vllm

tgi

[njhill]

@skylee-01 I wonder if you could try the same test but adding --scheduler-delay-factor=0.5. This should result in more batching of prefills.

[cadedaniel]

Some thoughts:

• Can you enable the speculative stats in speculative decoding? We should see logs like this:
  

  vllm/vllm/engine/metrics.py

  Lines 386 to 392 in c6af027

  	return ("Speculative metrics: "
  	f"Draft acceptance rate: {metrics.draft_acceptance_rate:.3f}, "
  	f"System efficiency: {metrics.system_efficiency:.3f}, "
  	f"Number of speculative tokens: {metrics.num_spec_tokens}, "
  	f"Number of accepted tokens: {metrics.accepted_tokens}, "
  	f"Number of draft tokens: {metrics.draft_tokens}, "
  	f"Number of emitted tokens: {metrics.emitted_tokens}.")

• I have not tried vLLM speculative decoding up to QPS=25+. Unfortunately due to some architecture issues where the API server runs in the same process as the worker0, high QPS incurs very low GPU utilization. This is the tracking issue for fixing that: [RFC]: Isolate OpenAI Server Into Separate Process #6797. Can you check that this is being used?

• Another issue you're likely facing is scheduling prefills efficiently. You should follow @njhill's advice with --scheduler-delay-factor=0.5. This is a rough analog for TGI parameters --waiting-served-ratio=0.5 --max-batch-prefill-tokens=5120 --max-waiting-tokens=16000, you may need to do more tuning there. This will reduce the ratio of spec_decode_worker._run_no_spec to speculations.

• I have trouble reading the screenshots you shared; can you share throughput (tokens per second) with both TGI and vLLM at a fixed QPS? it should include with and without speculation as well (without speculation may be faster in both cases).

[LiuXiaoxuanPKU]

I'm confused about the nsys results. It seems there are four prefill phases between two decoding phases, how can that be possible?

[skylee-01]

Dear Professor @cadedaniel :

1、Below are some logs you need:
qps=25 not add the --scheduler-delay-factor
INFO 08-26 12:07:05 metrics.py:411] Avg prompt throughput: 1480.7 tokens/s, Avg generation throughput: 143.6 tokens/s, Running: 7 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 1.6%, CPU KV cache usage: 0.0%.
INFO 08-26 12:07:05 metrics.py:427] Speculative metrics: Draft acceptance rate: 0.655, System efficiency: 0.649, Number of speculative tokens: 4, Number of accepted tokens: 1735, Number of draft tokens: 2648, Number of emitted tokens: 2149.
INFO 08-26 12:07:10 metrics.py:411] Avg prompt throughput: 1446.8 tokens/s, Avg generation throughput: 146.7 tokens/s, Running: 6 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 1.4%, CPU KV cache usage: 0.0%.
INFO 08-26 12:07:10 metrics.py:427] Speculative metrics: Draft acceptance rate: 0.656, System efficiency: 0.654, Number of speculative tokens: 4, Number of accepted tokens: 3268, Number of draft tokens: 4980, Number of emitted tokens: 4074.
INFO 08-26 12:07:15 metrics.py:411] Avg prompt throughput: 1478.1 tokens/s, Avg generation throughput: 150.8 tokens/s, Running: 6 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 1.4%, CPU KV cache usage: 0.0%.
INFO 08-26 12:07:15 metrics.py:427] Speculative metrics: Draft acceptance rate: 0.653, System efficiency: 0.652, Number of speculative tokens: 4, Number of accepted tokens: 4987, Number of draft tokens: 7632, Number of emitted tokens: 6223.
INFO 08-26 12:07:20 metrics.py:411] Avg prompt throughput: 1483.3 tokens/s, Avg generation throughput: 144.8 tokens/s, Running: 10 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 2.2%, CPU KV cache usage: 0.0%.
INFO 08-26 12:07:20 metrics.py:427] Speculative metrics: Draft acceptance rate: 0.654, System efficiency: 0.652, Number of speculative tokens: 4, Number of accepted tokens: 6651, Number of draft tokens: 10168, Number of emitted tokens: 8282.

qps=25 and --scheduler-delay-factor=0.5
INFO 08-26 12:16:55 metrics.py:411] Avg prompt throughput: 1473.2 tokens/s, Avg generation throughput: 149.8 tokens/s, Running: 4 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 0.9%, CPU KV cache usage: 0.0%.
INFO 08-26 12:16:55 metrics.py:427] Speculative metrics: Draft acceptance rate: 0.653, System efficiency: 0.650, Number of speculative tokens: 4, Number of accepted tokens: 3264, Number of draft tokens: 5000, Number of emitted tokens: 4060.
INFO 08-26 12:17:00 metrics.py:411] Avg prompt throughput: 1465.2 tokens/s, Avg generation throughput: 145.3 tokens/s, Running: 6 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 1.3%, CPU KV cache usage: 0.0%.
INFO 08-26 12:17:00 metrics.py:427] Speculative metrics: Draft acceptance rate: 0.652, System efficiency: 0.648, Number of speculative tokens: 4, Number of accepted tokens: 4892, Number of draft tokens: 7500, Number of emitted tokens: 6073.
INFO 08-26 12:17:05 metrics.py:411] Avg prompt throughput: 1457.0 tokens/s, Avg generation throughput: 140.4 tokens/s, Running: 4 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 1.0%, CPU KV cache usage: 0.0%.
INFO 08-26 12:17:05 metrics.py:427] Speculative metrics: Draft acceptance rate: 0.656, System efficiency: 0.654, Number of speculative tokens: 4, Number of accepted tokens: 6517, Number of draft tokens: 9940, Number of emitted tokens: 8125.
INFO 08-26 12:17:10 metrics.py:411] Avg prompt throughput: 1474.9 tokens/s, Avg generation throughput: 153.0 tokens/s, Running: 5 reqs, Swapped: 0 reqs, Pending: 0 reqs, GPU KV cache usage: 1.1%, CPU KV cache usage: 0.0%.
INFO 08-26 12:17:10 metrics.py:427] Speculative metrics: Draft acceptance rate: 0.656, System efficiency: 0.655, Number of speculative tokens: 4, Number of accepted tokens: 8103, Number of draft tokens: 12348, Number of emitted tokens: 10116.

2、We have tested the latest 0.5.5 version of VLLM, and there was no significant change in the results. The latest version should have resolved the architectural issues.

3、We attempted to test with the option --scheduler-delay-factor=0.5. Although the QPS did not increase, the scheduling order of prefill and decode was optimized according to the log analysis。Below is the optimized nsight。

4、 I haven't found out how TGI prints the throughput, but from the stress test logs, it seems that both vllm and TGI have consistent output for each query

Problem Analysis: After the scheduling optimization, the QPS did not increase, which is very strange. So I further investigated the issue. I found that there were intermittent delays of 300ms, which severely affected the QPS increase because our metric is 100% availability within 500ms. An answer's output is within 200ms, and if there is a 300ms delay, it would cause queries near this node to exceed the 500ms limit

Speculative decoding 300ms issue

The issue of a 300ms delay can also occur without using speculative decoding.

Some details about the 300ms issue

Upon further investigation, the cause of the problem could not be identified, and the location of the code and the time of occurrence are both random.
Dear Professor, could you please explain why this issue has occurred and how it can be resolved?

nsys: https://github.com/skylee-01/experimental_data/blob/main/vllm_300ms_delay.zip

[skylee-01]

I'm confused about the nsys results. It seems there are four prefill phases between two decoding phases, how can that be possible?

Thank you for your response. This issue occurs in scenarios with high QPS.

[skylee-01]

@skylee-01 I wonder if you could try the same test but adding --scheduler-delay-factor=0.5. This should result in more batching of prefills.

Thank you very much for your reply. Your suggestions are excellent. We have experimented with this parameter, and although it did not improve QPS, we have mastered the method of optimizing scheduling through learning about this parameter.

[skylee-01]

From the perspective of nsys, the pre-fill and decoding stages are separate. Could you please advise on how to use the continuous batch processing feature? @youkaichao