Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[Bug]: Qwen1.5-72B L20x8 latest vLLM TPOT slower than v0.4.0.post, 48ms vs 39ms, why? #4852

Closed
DefTruth opened this issue May 16, 2024 · 10 comments
Closed

[Bug]: Qwen1.5-72B L20x8 latest vLLM TPOT slower than v0.4.0.post, 48ms vs 39ms, why? #4852

DefTruth opened this issue May 16, 2024 · 10 comments
Labels
bug Something isn't working

Comments

@DefTruth
Copy link
Contributor

DefTruth commented May 16, 2024 •
edited
Loading

Your current environment

The output of `python collect_env.py`
Collecting environment information...
PyTorch version: 2.3.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.2
Libc version: glibc-2.35

Python version: 3.10.14 (main, Mar 21 2024, 16:24:04) [GCC 11.2.0] (64-bit runtime)
Python platform: Linux-4.18.0-240.el8.x86_64-x86_64-with-glibc2.35
Is CUDA available: True
CUDA runtime version: 12.3.107
CUDA_MODULE_LOADING set to: LAZY
GPU models and configuration: 
GPU 0: NVIDIA L20
GPU 1: NVIDIA L20
GPU 2: NVIDIA L20
GPU 3: NVIDIA L20
GPU 4: NVIDIA L20
GPU 5: NVIDIA L20
GPU 6: NVIDIA L20
GPU 7: NVIDIA L20

Nvidia driver version: 550.54.15
cuDNN version: Probably one of the following:
/usr/lib/x86_64-linux-gnu/libcudnn.so.8.9.7
/usr/lib/x86_64-linux-gnu/libcudnn.so.9.0.0
/usr/lib/x86_64-linux-gnu/libcudnn_adv.so.9.0.0
/usr/lib/x86_64-linux-gnu/libcudnn_adv_infer.so.8.9.7
/usr/lib/x86_64-linux-gnu/libcudnn_adv_train.so.8.9.7
/usr/lib/x86_64-linux-gnu/libcudnn_cnn.so.9.0.0
/usr/lib/x86_64-linux-gnu/libcudnn_cnn_infer.so.8.9.7
/usr/lib/x86_64-linux-gnu/libcudnn_cnn_train.so.8.9.7
/usr/lib/x86_64-linux-gnu/libcudnn_engines_precompiled.so.9.0.0
/usr/lib/x86_64-linux-gnu/libcudnn_engines_runtime_compiled.so.9.0.0
/usr/lib/x86_64-linux-gnu/libcudnn_graph.so.9.0.0
/usr/lib/x86_64-linux-gnu/libcudnn_heuristic.so.9.0.0
/usr/lib/x86_64-linux-gnu/libcudnn_ops.so.9.0.0
/usr/lib/x86_64-linux-gnu/libcudnn_ops_infer.so.8.9.7
/usr/lib/x86_64-linux-gnu/libcudnn_ops_train.so.8.9.7
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:                   52 bits physical, 57 bits virtual
Byte Order:                      Little Endian
CPU(s):                          128
On-line CPU(s) list:             0-127
Vendor ID:                       GenuineIntel
BIOS Vendor ID:                  Intel(R) Corporation
Model name:                      Intel(R) Xeon(R) Gold 6430
BIOS Model name:                 Intel(R) Xeon(R) Gold 6430
CPU family:                      6
Model:                           143
Thread(s) per core:              2
Core(s) per socket:              32
Socket(s):                       2
Stepping:                        8
Frequency boost:                 enabled
CPU max MHz:                     2101.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 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 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 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:                       3 MiB (64 instances)
L1i cache:                       2 MiB (64 instances)
L2 cache:                        128 MiB (64 instances)
L3 cache:                        120 MiB (2 instances)
NUMA node(s):                    2
NUMA node0 CPU(s):               0-31,64-95
NUMA node1 CPU(s):               32-63,96-127
Vulnerability Itlb multihit:     Not affected
Vulnerability L1tf:              Not affected
Vulnerability Mds:               Not affected
Vulnerability Meltdown:          Not affected
Vulnerability Spec store bypass: Vulnerable
Vulnerability Spectre v1:        Vulnerable: __user pointer sanitization and usercopy barriers only; no swapgs barriers
Vulnerability Spectre v2:        Vulnerable, IBPB: disabled, STIBP: disabled
Vulnerability Srbds:             Not affected
Vulnerability Tsx async abort:   Not affected

Versions of relevant libraries:
[pip3] flashinfer==0.0.4+cu121torch2.3
[pip3] mypy==1.9.0
[pip3] mypy-extensions==1.0.0
[pip3] numpy==1.26.4
[pip3] nvidia-nccl-cu12==2.20.5
[pip3] torch==2.3.0
[pip3] triton==2.3.0
[pip3] tritonclient==2.45.0
[pip3] vllm-nccl-cu12==2.18.1.0.3.0
[conda] flashinfer                0.0.4+cu121torch2.3          pypi_0    pypi
[conda] numpy                     1.26.4                   pypi_0    pypi
[conda] nvidia-nccl-cu12          2.20.5                   pypi_0    pypi
[conda] torch                     2.3.0                    pypi_0    pypi
[conda] triton                    2.3.0                    pypi_0    pypi
[conda] tritonclient              2.45.0                   pypi_0    pypi
[conda] vllm-nccl-cu12            2.18.1.0.3.0             pypi_0    pypiROCM Version: Could not collect
Neuron SDK Version: N/A
vLLM Version: 0.4.2
vLLM Build Flags:
CUDA Archs: 5.2 6.0 6.1 7.0 7.2 7.5 8.0 8.6 8.7 9.0+PTX; ROCm: Disabled; Neuron: Disabled
GPU Topology:
�[4mGPU0	GPU1	GPU2	GPU3	GPU4	GPU5	GPU6	GPU7	CPU Affinity	NUMA Affinity	GPU NUMA ID�[0m
GPU0	 X 	PIX	PIX	PIX	SYS	SYS	SYS	SYS	0-31,64-95	0		N/A
GPU1	PIX	 X 	PIX	PIX	SYS	SYS	SYS	SYS	0-31,64-95	0		N/A
GPU2	PIX	PIX	 X 	PIX	SYS	SYS	SYS	SYS	0-31,64-95	0		N/A
GPU3	PIX	PIX	PIX	 X 	SYS	SYS	SYS	SYS	0-31,64-95	0		N/A
GPU4	SYS	SYS	SYS	SYS	 X 	PIX	PIX	PIX	32-63,96-127	1		N/A
GPU5	SYS	SYS	SYS	SYS	PIX	 X 	PIX	PIX	32-63,96-127	1		N/A
GPU6	SYS	SYS	SYS	SYS	PIX	PIX	 X 	PIX	32-63,96-127	1		N/A
GPU7	SYS	SYS	SYS	SYS	PIX	PIX	PIX	 X 	32-63,96-127	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

vLLM 0.4.0.post1:

[I][2024-05-16 14:54:13][ 1/10][ 1/10  10%] session:0   turn:0  req:0    output: 50   prompt: 1342(+[1342])  first(ms):    94.7(+[   94.7])  other(ms): 40.0    latency(s): 2.06
[I][2024-05-16 14:54:23][ 2/10][ 2/10  20%] session:1   turn:0  req:1    output: 50   prompt: 1299(+[1299])  first(ms):    66.4(+[   66.4])  other(ms): 39.7    latency(s): 2.01
[I][2024-05-16 14:54:33][ 3/10][ 3/10  30%] session:2   turn:0  req:2    output: 50   prompt: 731 (+[ 731])  first(ms):    67.8(+[   67.8])  other(ms): 39.6    latency(s): 2.01
[I][2024-05-16 14:54:43][ 4/10][ 4/10  40%] session:3   turn:0  req:3    output: 50   prompt: 1369(+[1369])  first(ms):    76.7(+[   76.7])  other(ms): 39.4    latency(s): 2.01
[I][2024-05-16 14:54:53][ 5/10][ 5/10  50%] session:4   turn:0  req:4    output: 50   prompt: 1119(+[1119])  first(ms):    75.0(+[   75.0])  other(ms): 40.8    latency(s): 2.07
[I][2024-05-16 14:55:03][ 6/10][ 6/10  60%] session:5   turn:0  req:5    output: 50   prompt: 1068(+[1068])  first(ms):    77.7(+[   77.7])  other(ms): 39.9    latency(s): 2.03

vLLM 0.4.2 latest:

[I][2024-05-16 14:47:04][ 1/10][ 1/10  10%] session:0   turn:0  req:0    output: 50   prompt: 1549(+[1549])  first(ms):   821.6(+[  821.6])  other(ms): 47.2    latency(s): 3.14
[I][2024-05-16 14:47:14][ 3/10][ 2/10  20%] session:2   turn:0  req:2    output: 50   prompt: 1200(+[1200])  first(ms):  1197.6(+[ 1197.6])  other(ms): 104.2   latency(s): 6.30
[I][2024-05-16 14:47:14][ 2/10][ 3/10  30%] session:1   turn:0  req:1    output: 50   prompt: 1727(+[1727])  first(ms):  4013.2(+[ 4013.2])  other(ms): 114.7   latency(s): 9.63
[I][2024-05-16 14:47:17][ 4/10][ 4/10  40%] session:3   turn:0  req:3    output: 50   prompt: 1406(+[1406])  first(ms):  2905.0(+[ 2905.0])  other(ms): 53.5    latency(s): 5.52
[I][2024-05-16 14:47:17][ 5/10][ 5/10  50%] session:4   turn:0  req:4    output: 50   prompt: 980 (+[ 980])  first(ms):   466.0(+[  466.0])  other(ms): 44.4    latency(s): 2.64
[I][2024-05-16 14:47:24][ 6/10][ 6/10  60%] session:5   turn:0  req:5    output: 50   prompt: 1022(+[1022])  first(ms):  2680.2(+[ 2680.2])  other(ms): 63.7    latency(s): 5.80
[I][2024-05-16 14:47:24][ 7/10][ 7/10  70%] session:6   turn:0  req:6    output: 50   prompt: 1772(+[1772])  first(ms):   836.7(+[  836.7])  other(ms): 45.4    latency(s): 3.06
[I][2024-05-16 14:47:28][ 8/10][ 8/10  80%] session:7   turn:0  req:7    output: 50   prompt: 1714(+[1714])  first(ms):   808.7(+[  808.7])  other(ms): 45.0    latency(s): 3.01
[I][2024-05-16 14:47:31][ 9/10][ 9/10  90%] session:8   turn:0  req:8    output: 50   prompt: 1311(+[1311])  first(ms):   602.8(+[  602.8])  other(ms): 44.2    latency(s): 2.77
[I][2024-05-16 14:47:34][10/10][10/10 100%] session:9   turn:0  req:9    output: 50   prompt: 1977(+[1977])  first(ms):   888.7(+[  888.7])  other(ms): 47.2    latency(s): 3.20

commit: #4794
@DefTruth DefTruth added the bug Something isn't working label May 16, 2024
@DefTruth
Copy link
Contributor Author

@youkaichao @rkooo567

@DefTruth
Copy link
Contributor Author

command：

export CUDA_VISIBLE_DEVICES=0,1,2,3,4,5,6,7
python3 -m vllm.entrypoints.openai.api_server \
    --model Qwen1.5-72B-Chat \
    --tensor-parallel-size 8 \
    --max-model-len 8192 \
    --trust-remote-code \
    --disable-custom-all-reduce \
    --enable-prefix-caching \
    --tokenizer-mode slow \
    --enforce-eager \
    --gpu-memory-utilization 0.9 \
    --port 8861

@youkaichao
Copy link
Member

If you can biset to find out the commit that leads to the degradation, that would be helpful. Otherwise, it is very difficult to answer a generic report of a performance regression.

@DefTruth
Copy link
Contributor Author

If you can biset to find out the commit that leads to the degradation, that would be helpful. Otherwise, it is very difficult to answer a generic report of a performance regression.

vLLM seems to have been under reconstruction recently. I'm not quite sure what's causing TPOT to be slow

@youkaichao
Copy link
Member

most commits should be runnable since they pass the ci tests. it's not related with the refactoring. just bisect to find out the potentially commit that leads to this regression.

@DefTruth
Copy link
Contributor Author

I have test on L20, not sure the device is same as in CI.

@DefTruth
Copy link
Contributor Author

with cuda graph: 35.7ms -> 36.7ms, without cuda graph: 39ms -> 45ms

@DefTruth
Copy link
Contributor Author

DefTruth commented Jun 5, 2024

maybe relate to #5207

@youkaichao
Copy link
Member

feel free to test if #5207 solves your problem here.

@DefTruth
Copy link
Contributor Author

@youkaichao close, seems the latest vllm (up to #5410) has fixed this problem. (TP0T 45ms v0.4.2 -> 39ms v0.5, eager mode)

[I][2024-06-11 16:31:36][ 1/20][ 1/20   5%] session:0   turn:0  req:0    output: 50   prompt: 1024(+[1024])  first(ms):   426.7(+[  426.7])  other(ms): 39.3    latency(s): 2.35
[I][2024-06-11 16:31:46][ 2/20][ 2/20  10%] session:1   turn:0  req:1    output: 50   prompt: 1024(+[1024])  first(ms):   427.0(+[  427.0])  other(ms): 40.6    latency(s): 2.42
[I][2024-06-11 16:31:56][ 3/20][ 3/20  15%] session:2   turn:0  req:2    output: 50   prompt: 1024(+[1024])  first(ms):   427.8(+[  427.8])  other(ms): 39.2    latency(s): 2.35
[I][2024-06-11 16:32:06][ 4/20][ 4/20  20%] session:3   turn:0  req:3    output: 50   prompt: 1024(+[1024])  first(ms):   428.5(+[  428.5])  other(ms): 39.2    latency(s): 2.35
[I][2024-06-11 16:32:16][ 5/20][ 5/20  25%] session:4   turn:0  req:4    output: 50   prompt: 1024(+[1024])  first(ms):   427.6(+[  427.6])  other(ms): 39.2    latency(s): 2.35
[I][2024-06-11 16:32:26][ 6/20][ 6/20  30%] session:5   turn:0  req:5    output: 50   prompt: 1024(+[1024])  first(ms):   429.1(+[  429.1])  other(ms): 39.0    latency(s): 2.34
[I][2024-06-11 16:32:36][ 7/20][ 7/20  35%] session:6   turn:0  req:6    output: 50   prompt: 1024(+[1024])  first(ms):   427.0(+[  427.0])  other(ms): 40.5    latency(s): 2.41
[I][2024-06-11 16:32:46][ 8/20][ 8/20  40%] session:7   turn:0  req:7    output: 50   prompt: 1024(+[1024])  first(ms):   427.0(+[  427.0])  other(ms): 39.1    latency(s): 2.34
[I][2024-06-11 16:32:56][ 9/20][ 9/20  45%] session:8   turn:0  req:8    output: 50   prompt: 1024(+[1024])  first(ms):   425.3(+[  425.3])  other(ms): 38.8    latency(s): 2.33
[I][2024-06-11 16:33:06][10/20][10/20  50%] session:9   turn:0  req:9    output: 50   prompt: 1024(+[1024])  first(ms):   426.2(+[  426.2])  other(ms): 39.1    latency(s): 2.34
[I][2024-06-11 16:33:16][11/20][11/20  55%] session:10  turn:0  req:10   output: 50   prompt: 1024(+[1024])  first(ms):   428.2(+[  428.2])  other(ms): 38.9    latency(s): 2.33
[I][2024-06-11 16:33:26][12/20][12/20  60%] session:11  turn:0  req:11   output: 50   prompt: 1024(+[1024])  first(ms):   426.4(+[  426.4])  other(ms): 39.0    latency(s): 2.34
[I][2024-06-11 16:33:36][13/20][13/20  65%] session:12  turn:0  req:12   output: 50   prompt: 1024(+[1024])  first(ms):   425.6(+[  425.6])  other(ms): 39.6    latency(s): 2.37
[I][2024-06-11 16:33:46][14/20][14/20  70%] session:13  turn:0  req:13   output: 50   prompt: 1024(+[1024])  first(ms):   425.5(+[  425.5])  other(ms): 39.2    latency(s): 2.35
[I][2024-06-11 16:33:56][15/20][15/20  75%] session:14  turn:0  req:14   output: 50   prompt: 1024(+[1024])  first(ms):   425.2(+[  425.2])  other(ms): 39.9    latency(s): 2.38

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@youkaichao @DefTruth