[Bug]: the ttft and latency for each request calculated by benchmark_serving.py seems abnormal

[wanzhenchn]

Your current environment

The output of `python collect_env.py`

Collecting environment information... PyTorch version: 2.2.1+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.27.6 Libc version: glibc-2.35

Python version: 3.10.12 (main, Jun 11 2023, 05:26:28) [GCC 11.4.0] (64-bit runtime) Python platform: Linux-5.15.0-52-shopee-generic-x86_64-with-glibc2.35 Is CUDA available: True CUDA runtime version: 12.2.140 CUDA_MODULE_LOADING set to: LAZY GPU models and configuration: GPU 0: NVIDIA A30 GPU 1: NVIDIA A30

Nvidia driver version: 535.104.12 cuDNN version: Probably one of the following: /usr/lib/x86_64-linux-gnu/libcudnn.so.8.9.5 /usr/lib/x86_64-linux-gnu/libcudnn_adv_infer.so.8.9.5 /usr/lib/x86_64-linux-gnu/libcudnn_adv_train.so.8.9.5 /usr/lib/x86_64-linux-gnu/libcudnn_cnn_infer.so.8.9.5 /usr/lib/x86_64-linux-gnu/libcudnn_cnn_train.so.8.9.5 /usr/lib/x86_64-linux-gnu/libcudnn_ops_infer.so.8.9.5 /usr/lib/x86_64-linux-gnu/libcudnn_ops_train.so.8.9.5 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): 144 On-line CPU(s) list: 0-143 Vendor ID: GenuineIntel Model name: Intel(R) Xeon(R) Platinum 8352V CPU @ 2.10GHz CPU family: 6 Model: 106 Thread(s) per core: 2 Core(s) per socket: 36 Socket(s): 2 Stepping: 6 CPU max MHz: 3500.0000 CPU min MHz: 800.0000 BogoMIPS: 4200.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: 3.4 MiB (72 instances) L1i cache: 2.3 MiB (72 instances) L2 cache: 90 MiB (72 instances) L3 cache: 108 MiB (2 instances) NUMA node(s): 2 NUMA node0 CPU(s): 0,2,4,6,8,10,12,14,16,18,20,22,24,26,28,30,32,34,36,38,40,42,44,46,48,50,52,54,56,58,60,62,64,66,68,70,72,74,76,78,80,82,84,86,88,90,92,94,96,98,100,102,104,106,108,110,112,114,116,118,120,122,124,126,128,130,132,134,136,138,140,142 NUMA node1 CPU(s): 1,3,5,7,9,11,13,15,17,19,21,23,25,27,29,31,33,35,37,39,41,43,45,47,49,51,53,55,57,59,61,63,65,67,69,71,73,75,77,79,81,83,85,87,89,91,93,95,97,99,101,103,105,107,109,111,113,115,117,119,121,123,125,127,129,131,133,135,137,139,141,143 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 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: Not affected

Versions of relevant libraries: [pip3] numpy==1.22.2 [pip3] onnx==1.14.0 [pip3] pytorch-quantization==2.1.2 [pip3] torch==2.2.1 [pip3] torch-tensorrt==0.0.0 [pip3] torchdata==0.7.0a0 [pip3] torchtext==0.16.0a0 [pip3] torchvision==0.16.0a0 [pip3] triton==2.2.0 [conda] Could not collectROCM Version: Could not collect Neuron SDK Version: N/A vLLM Version: 0.4.0.post1 vLLM Build Flags: CUDA Archs: 8.0; ROCm: Disabled; Neuron: Disabled GPU Topology: �[4mGPU0 GPU1 CPU Affinity NUMA Affinity GPU NUMA ID�[0m GPU0 X SYS 0,2,4,6,8,10 0 N/A GPU1 SYS X 1,3,5,7,9,11 1 N/A

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

🐛 Describe the bug

I have set breakpoint in the offical benchmark_serving.py and ran following command:

python benchmark_serving.py \ 
--model /data/models/vicuna-13b-v1.5 \
--dataset-name sharegpt \
--dataset-path ShareGPT_V3_unfiltered_cleaned_split.json \
--port 8014 \
--num-prompts 5

The server is launched with --max-num-seqs 1 to test the performance for bach_szie = 1:

python3 -m vllm.entrypoints.openai.api_server \
--host 0.0.0.0 --port 8014 \
--model /data/models/vicuna-13b-v1.5 \
--dtype auto -tp 2 --max-model-len 4096 \
--max-num-seqs 1 \
--gpu-memory-utilization 0.85 \
--enable-prefix-caching \
--swap-space 16

The ttft seems incorrect for prompt_len=30, which elapsed 3.9547242913395166s. The other cases also show the same phenomenon.

[ywang96]

@wanzhenchn I'm trying to understand your goal here

The server is launched with --max-num-seqs 1 to test the performance for bach_szie = 1:

If you set --max-num-seqs 1, doesn't this mean every sequence will have to wait for the previous one to finish? The metric TTFT for each request includes the queue time as well, so I'm trying to see why you think it's abnormal. Please feel free to take a look at benchmark_serving.py and backend_request_func.py if you find anything not right too!

BTW - if you really want to test out the performance of the engine for batch_size = 1, then I would suggest taking a look at benchmark_latency.py.

[wanzhenchn]

@ywang96 Many thanks for your explanations again.

If you set --max-num-seqs 1, doesn't this mean every sequence will have to wait for the previous one to finish? The metric TTFT for each request includes the queue time as well.

Yeah, the problem is that the ALL requests are sent to the server at once. When --max-num-seqs 1, all other requests have to wait in a queue except for the first request. As a result, both TTFT (Time To First Token) and latency will gradually increase.

https://github.com/vllm-project/vllm/blob/c1b4e4157c0b4154f950adaea85a259fc629c758/benchmarks/benchmark_serving.py#L175-L189

So, if one wants to test the performance under different batch sizes(1,2,4,...), the maximum concurrency of coroutine should be set. It's also mentioned in https://github.com/vllm-project/vllm/issues/3127.

https://github.com/vllm-project/vllm/blob/c1b4e4157c0b4154f950adaea85a259fc629c758/benchmarks/benchmark_serving.py#L257-L271

[ywang96]

So, if one wants to test the performance under different batch sizes(1,2,4,...), the maximum concurrency of coroutine should be set. It's also mentioned in #3127.

Yea, though I don't think testing the performance under different batch sizes makes sense since LLMEngine already does continuous batching. Feel free to modify the benchmark script and make a PR - I'm happy to take a look and review it.

I'm closing this issue now since this is not a bug per our discussion.