[Bug]: Strange metrics when running `benchmark_serving` under high concurrency

[AsicDyc]

Your current environment

The output of python collect_env.py

Your output of `python collect_env.py` here
INFO 06-05 16:06:27 [__init__.py:239] Automatically detected platform cuda.
Collecting environment information...
==============================
        System Info
==============================
OS                           : CentOS Linux 7 (Core) (x86_64)
GCC version                  : (GCC) 8.3.1 20190311 (Red Hat 8.3.1-3)
Clang version                : Could not collect
CMake version                : version 3.25.0-rc2
Libc version                 : glibc-2.17

==============================
       PyTorch Info
==============================
PyTorch version              : 2.6.0+cu124
Is debug build               : False
CUDA used to build PyTorch   : 12.4
ROCM used to build PyTorch   : N/A

==============================
      Python Environment
==============================
Python version               : 3.10.12 (main, Oct 10 2024, 21:53:07) [GCC 10.2.1 20210130 (Red Hat 10.2.1-11)] (64-bit runtime)
Python platform              : Linux-4.18.0-147.mt20200626.413.el8_1.x86_64-x86_64-with-glibc2.17

==============================
       CUDA / GPU Info
==============================
Is CUDA available            : True
CUDA runtime version         : 12.4.99
CUDA_MODULE_LOADING set to   : LAZY
GPU models and configuration : 
GPU 0: NVIDIA A100-SXM4-80GB
GPU 1: NVIDIA A100-SXM4-80GB

Nvidia driver version        : 535.129.03
cuDNN version                : Probably one of the following:
/usr/lib64/libcudnn.so.8.9.7
/usr/lib64/libcudnn_adv_infer.so.8.9.7
/usr/lib64/libcudnn_adv_train.so.8.9.7
/usr/lib64/libcudnn_cnn_infer.so.8.9.7
/usr/lib64/libcudnn_cnn_train.so.8.9.7
/usr/lib64/libcudnn_ops_infer.so.8.9.7
/usr/lib64/libcudnn_ops_train.so.8.9.7
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
Byte Order:                      Little Endian
Address sizes:                   43 bits physical, 48 bits virtual
CPU(s):                          256
On-line CPU(s) list:             0-24
Off-line CPU(s) list:            25-255
Thread(s) per core:              0
Core(s) per socket:              64
Socket(s):                       2
NUMA node(s):                    2
Vendor ID:                       AuthenticAMD
CPU family:                      25
Model:                           1
Model name:                      AMD EPYC 7713 64-Core Processor
Stepping:                        1
Frequency boost:                 enabled
CPU MHz:                         3036.840
CPU max MHz:                     2000.0000
CPU min MHz:                     1500.0000
BogoMIPS:                        3981.31
Virtualization:                  AMD-V
L1d cache:                       2 MiB
L1i cache:                       2 MiB
L2 cache:                        32 MiB
L3 cache:                        256 MiB
NUMA node0 CPU(s):               0-63,128-191
NUMA node1 CPU(s):               64-127,192-255
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 Tsx async abort:   Not affected
Flags:                           fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush mmx fxsr sse sse2 ht syscall nx mmxext fxsr_opt pdpe1gb rdtscp lm constant_tsc rep_good nopl xtopology nonstop_tsc cpuid extd_apicid aperfmperf pni pclmulqdq monitor ssse3 fma cx16 pcid sse4_1 sse4_2 x2apic movbe popcnt aes xsave avx f16c rdrand lahf_lm cmp_legacy svm extapic cr8_legacy abm sse4a misalignsse 3dnowprefetch osvw ibs skinit wdt tce topoext perfctr_core perfctr_nb bpext perfctr_llc mwaitx cpb cat_l3 cdp_l3 invpcid_single hw_pstate sme ssbd mba sev ibrs ibpb stibp vmmcall fsgsbase bmi1 avx2 smep bmi2 erms invpcid cqm rdt_a rdseed adx smap clflushopt clwb sha_ni xsaveopt xsavec xgetbv1 xsaves cqm_llc cqm_occup_llc cqm_mbm_total cqm_mbm_local clzero irperf xsaveerptr wbnoinvd arat npt lbrv svm_lock nrip_save tsc_scale vmcb_clean flushbyasid decodeassists pausefilter pfthreshold v_vmsave_vmload vgif umip pku ospke vaes vpclmulqdq rdpid overflow_recov succor smca

==============================
Versions of relevant libraries
==============================
[pip3] mt-tritonclient==1.0.4
[pip3] mypy==1.15.0
[pip3] mypy_extensions==1.1.0
[pip3] numpy==1.26.4
[pip3] nvidia-cublas-cu12==12.4.5.8
[pip3] nvidia-cuda-cupti-cu12==12.4.127
[pip3] nvidia-cuda-nvrtc-cu12==12.4.127
[pip3] nvidia-cuda-runtime-cu12==12.4.127
[pip3] nvidia-cudnn-cu12==9.1.0.70
[pip3] nvidia-cufft-cu12==11.2.1.3
[pip3] nvidia-curand-cu12==10.3.5.147
[pip3] nvidia-cusolver-cu12==11.6.1.9
[pip3] nvidia-cusparse-cu12==12.3.1.170
[pip3] nvidia-cusparselt-cu12==0.6.2
[pip3] nvidia-ml-py==12.570.86
[pip3] nvidia-modelopt==0.21.1
[pip3] nvidia-nccl-cu12==2.21.5
[pip3] nvidia-nvjitlink-cu12==12.4.127
[pip3] nvidia-nvtx-cu12==12.4.127
[pip3] onnx==1.17.0
[pip3] onnx_graphsurgeon==0.5.8
[pip3] pynvml==12.0.0
[pip3] pyzmq==26.4.0
[pip3] torch==2.6.0
[pip3] torchaudio==2.6.0
[pip3] torchprofile==0.0.4
[pip3] torchvision==0.21.0
[pip3] transformers==4.51.3
[pip3] triton==3.2.0
[pip3] tritonclient==2.44.0
[conda] numpy                     1.19.5                   pypi_0    pypi
[conda] pyzmq                     25.1.1                   pypi_0    pypi

==============================
         vLLM Info
==============================
ROCM Version                 : Could not collect
Neuron SDK Version           : N/A
vLLM Version                 : 0.8.5.post1
vLLM Build Flags:
  CUDA Archs: Not Set; ROCm: Disabled; Neuron: Disabled
GPU Topology:
        GPU0    GPU1    NIC0    NIC1    NIC2    NIC3    NIC4    NIC5    NIC6    NIC7    CPU Affinity    NUMA Affinity   GPU NUMA ID
GPU0     X      NV12    SYS     SYS     SYS     SYS     SYS     SYS     PXB     PXB                             N/A
GPU1    NV12     X      SYS     SYS     SYS     SYS     SYS     SYS     PXB     PXB                             N/A
NIC0    SYS     SYS      X      PIX     SYS     SYS     SYS     SYS     SYS     SYS
NIC1    SYS     SYS     PIX      X      SYS     SYS     SYS     SYS     SYS     SYS
NIC2    SYS     SYS     SYS     SYS      X      PIX     SYS     SYS     SYS     SYS
NIC3    SYS     SYS     SYS     SYS     PIX      X      SYS     SYS     SYS     SYS
NIC4    SYS     SYS     SYS     SYS     SYS     SYS      X      PIX     SYS     SYS
NIC5    SYS     SYS     SYS     SYS     SYS     SYS     PIX      X      SYS     SYS
NIC6    PXB     PXB     SYS     SYS     SYS     SYS     SYS     SYS      X      PIX
NIC7    PXB     PXB     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
  NIC2: mlx5_2
  NIC3: mlx5_3
  NIC4: mlx5_4
  NIC5: mlx5_5
  NIC6: mlx5_6
  NIC7: mlx5_7

==============================
     Environment Variables
==============================
LD_LIBRARY_PATH=/lib64:/usr/lib64:/lib64:/usr/lib64:/opt/rh/devtoolset-8/root/usr/lib64:/opt/rh/devtoolset-8/root/usr/lib:/opt/rh/devtoolset-8/root/usr/lib64/dyninst:/opt/rh/devtoolset-8/root/usr/lib/dyninst:/opt/rh/devtoolset-8/root/usr/lib64:/opt/rh/devtoolset-8/root/usr/lib:/opt/triton_model_server/backends/tensorrtllm/libs:/usr/local/cuda/compat/:/opt/triton_model_server/lib:/opt/triton_model_server/lib64:/usr/local/lib/python3.10/site-packages/torch/lib:/usr/local/lib64:/usr/local/lib:/opt/tritonserver/lib:/opt/tritonserver/lib64:/opt/tritonserver/backends/tensorrtllm:/opt/tritonserver/backends/tensorrtllm/libs:/usr/local/openmpi/lib:/usr/local/lib:/usr/local/openssl/lib::/usr/local/TensorRT-10.3.0.26/lib:/usr/local/TensorRT-10.7.0.23/lib:/usr/local/java/bin:/home/sankuai/conda/envs/codelab/bin:/home/sankuai/conda/condabin:/usr/local/jdk1.8.0_45/bin:/opt/meituan/spark-2.2/sbin:/opt/meituan/spark-2.2/bin:/opt/meituan/hadoop/sbin:/opt/rh/devtoolset-8/root/usr/bin:/opt/tritonserver/perf_tools:/opt/triton_model_server/bin:/opt/tritonserver/bin:/usr/local/openmpi/include:/usr/local/openmpi/bin:/usr/local/nvidia/bin:/usr/local/cuda/bin:/usr/local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/local/java/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/opt/tritonserver/perf_tools:/opt/triton_model_server/bin:/opt/tritonserver/bin:/usr/local/openmpi/include:/usr/local/openmpi/bin:/usr/local/nvidia/bin:/usr/local/cuda/bin:/usr/local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/opt/meituan/hadoop/bin:/usr/local/java/bin:/opt/rh/devtoolset-8/root/usr/lib64:/opt/rh/devtoolset-8/root/usr/lib:/opt/rh/devtoolset-8/root/usr/lib64/dyninst:/opt/rh/devtoolset-8/root/usr/lib/dyninst:/opt/rh/devtoolset-8/root/usr/lib64:/opt/rh/devtoolset-8/root/usr/lib:/opt/triton_model_server/backends/tensorrtllm/libs:/usr/local/cuda/compat/:/opt/triton_model_server/lib:/opt/triton_model_server/lib64:/usr/local/lib/python3.10/site-packages/torch/lib:/usr/local/lib64:/usr/local/lib:/opt/tritonserver/lib:/opt/tritonserver/lib64:/opt/tritonserver/backends/tensorrtllm:/opt/tritonserver/backends/tensorrtllm/libs:/usr/local/openmpi/lib:/usr/local/lib:/usr/local/openssl/lib::/usr/local/TensorRT-10.3.0.26/lib:/usr/local/TensorRT-10.7.0.23/lib:/usr/local/java/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/lib64:/usr/lib64:$LD_LIBRARY_PATH:/opt/triton_model_server/backends/tensorrtllm/libs:/usr/local/cuda/compat/:/opt/triton_model_server/lib:/opt/triton_model_server/lib64:/usr/local/lib/python3.10/site-packages/torch/lib:/usr/local/lib64:/usr/local/lib:/opt/tritonserver/lib:/opt/tritonserver/lib64:/opt/tritonserver/backends/tensorrtllm:/opt/tritonserver/backends/tensorrtllm/libs:/usr/local/openmpi/lib:/usr/local/lib:/usr/local/openssl/lib::/usr/local/TensorRT-10.3.0.26/lib:/usr/local/TensorRT-10.7.0.23/lib:/usr/local/cuda/lib64:/usr/local/cuda/extras/CUPTI/lib64:/usr/local/java/jre/lib/amd64/server:/opt/meituan/hadoop/lib/native:/opt/triton_model_server/backends/tensorrtllm/libs:/usr/local/cuda/compat/:/opt/triton_model_server/lib:/opt/triton_model_server/lib64:/usr/local/lib/python3.10/site-packages/torch/lib:/usr/local/lib64:/usr/local/lib:/opt/tritonserver/lib:/opt/tritonserver/lib64:/opt/tritonserver/backends/tensorrtllm:/opt/tritonserver/backends/tensorrtllm/libs:/usr/local/openmpi/lib:/usr/local/lib:/usr/local/openssl/lib::/usr/local/TensorRT-10.3.0.26/lib:/usr/local/TensorRT-10.7.0.23/lib:/usr/local/cuda/lib64:/usr/local/cuda/extras/CUPTI/lib64:/usr/local/java/jre/lib/amd64/server:/opt/meituan/hadoop/lib/native
NVIDIA_VISIBLE_DEVICES=GPU-7a1844eb-8b2b-2d4c-41ba-2e4bd62cb4ba,GPU-9b74314e-cb73-75a4-64b0-659c9b7afa2c
NCCL_IB_GID_INDEX=7
NVIDIA_DRIVER_CAPABILITIES=compute,utility
OMP_NUM_THREADS=25
NCCL_CUMEM_ENABLE=0
PYTORCH_NVML_BASED_CUDA_CHECK=1
TORCHINDUCTOR_COMPILE_THREADS=1
CUDA_MODULE_LOADING=LAZY

🐛 Describe the bug

When running benchmark_serving.py, I got some strange metrics:

• I got an expected ttft and an abnormally large tpot for the first inference after the vllm serve started.
  The script I used for server side is:

  VLLM_TORCH_PROFILER_DIR=./outputs/vllm_profile VLLM_RPC_TIMEOUT=1800000 \
      vllm serve ../../data/huggingface.co/Qwen/Qwen3-32B \
          --max-model-len=16384 \
          --max-num-batch-tokens=2048 \
          --max-num-seqs=128 \
          -tp 2 \
          --disable-log-requests
  

  The script I used for client side is:

  python3 benchmarks/benchmark_serving.py --port 8000 \
          --save-result  --save-detailed \
          --result-dir outputs/benchmark \
          --backend vllm \
          --model ../data/huggingface.co/Qwen/Qwen3-32B \
          --dataset-name custom \
          --dataset-path "dataset/custom_all.jsonl" \
          --custom-output-len 10 \
          --num-prompts 16 \
          --max-concurrency 2 \
          --temperature 0.6 \
          --top-p 0.95 \
          --top-k 1 \
          --profile
  

  And the output I got:

  =========== Serving Benchmark Result ===========
  Successful requests: 16
  Benchmark duration (s): 19.65
  Total input tokens: 109554
  Total generated tokens: 160
  Request throughput (req/s): 0.81
  Output token throughput (tok/s): 8.14
  Total Token throughput (tok/s): 5583.69
  ---------------Time to First Token---------------
  Mean TFTT (ms): 1395.23
  Median TFTT (ms): 1535.06
  P99 TFTT (ms): 2659.78
  -----Time per Output Token (excl. 1st token)-----
  Mean TPOT (ms): 116.35
  Median TPOT (ms): 104.55
  P99 TPOT (ms): 208.98
  ---------------Inter-token Latency---------------
  Mean ITL (ms): 116.35
  Median ITL (ms): 27.72
  P99 ITL (ms): 379.71
  ================================================
  

• I got an abnormally small ttft and an expected tpot for the following inferences, and I noticed the prefix cache hit rate is always bigger than 50%, while in the first inference it's about 10%
  The output I got:

  =========== Serving Benchmark Result ===========
  Successful requests: 16
  Benchmark duration (s): 2.72
  Total input tokens: 109554
  Total generated tokens: 160
  Request throughput (req/s): 5.88
  Output token throughput (tok/s): 58.81
  Total Token throughput (tok/s): 40324.99
  ---------------Time to First Token---------------
  Mean TFTT (ms): 28.29
  Median TFTT (ms): 28.63
  P99 TFTT (ms): 30.06
  -----Time per Output Token (excl. 1st token)-----
  Mean TPOT (ms): 116.35
  Median TPOT (ms): 104.55
  P99 TPOT (ms): 208.98
  ---------------Inter-token Latency---------------
  Mean ITL (ms): 28.49
  Median ITL (ms): 27.48
  P99 ITL (ms): 46.02
  ================================================
  

• When I set --max-concurrency to 4 and higher, I found similar phenomena
  I reviewed the detailed output json file and found that when tpot is abnormally large, most of the tpot are still as large as expected, only very few tpot are as large as ttft.
  Some other issues also mentioned similar phenomenon, like [Bug]: vllm 0.8.3 abnormal TTFT (too long) in the first serving #16858, but they were not resolved well.

Any advice would be helpful! Looking forward for your response!

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.

[cjackal]

This is due to the prefix caching enabled during the benchmark, which is fixed in #18771.

[AsicDyc]

Thanks for your answer! After I turned off the prefix cache by setting --no-enable-prefix-caching, I did find that the subsequent inferences no longer had abnormally low ttft, but the tpot was still abnormally high, which was the same as the first inference phenomenon. Here is the output I got, and the expected value of tpot is around 28ms referring to offline result and genai-perf result:

============ Serving Benchmark Result ============
Successful requests:                     64        
Benchmark duration (s):                  269.39    
Total input tokens:                      431013    
Total generated tokens:                  640       
Request throughput (req/s):              0.24      
Output token throughput (tok/s):         2.38      
Total Token throughput (tok/s):          1602.35   
---------------Time to First Token----------------
Mean TTFT (ms):                          1310.44   
Median TTFT (ms):                        1447.49   
P99 TTFT (ms):                           2831.79   
-----Time per Output Token (excl. 1st token)------
Mean TPOT (ms):                          134.20    
Median TPOT (ms):                        133.13    
P99 TPOT (ms):                           226.51    
---------------Inter-token Latency----------------
Mean ITL (ms):                           134.20    
Median ITL (ms):                         28.99     
P99 ITL (ms):                            1339.97   
==================================================

[AsicDyc]

And here is the output json, posting here in case it can help:

output json file:

``` {"date": "20250606-101753", "backend": "vllm", "model_id": "../../data/huggingface.co/Qwen/Qwen3-32B", "tokenizer_id": "../../data/huggingface.co/Qwen/Qwen3-32B", "num_prompts": 64, "request_rate": "inf", "burstiness": 1.0, "max_concurrency": 2, "duration": 269.3877644762397, "completed": 64, "total_input_tokens": 431013, "total_output_tokens": 640, "request_throughput": 0.23757574930855804, "request_goodput:": null, "output_throughput": 2.3757574930855805, "total_token_throughput": 1602.3482018169846, "input_lens": [3858, 8064, 9, 8939, 7814, 10552, 3274, 9126, 4803, 9250, 8616, 9034, 5949, 6096, 9741, 4429, 8869, 4285, 4914, 9551, 8482, 4131, 8395, 9666, 3875, 5576, 2954, 8655, 4875, 9740, 3076, 9601, 94, 9916, 4843, 6062, 9072, 7824, 4293, 3508, 5149, 10398, 2067, 10821, 3593, 9736, 7959, 9424, 5864, 10360, 7278, 8955, 3028, 3413, 3774, 3812, 9605, 9709, 8407, 8648, 9687, 4110, 8412, 4993], "output_lens": [10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10, 10], "ttfts": [0.6514406315982342, 1.9485444892197847, 0.055491238832473755, 1.521445730701089, 1.3239671681076288, 1.828992635011673, 0.5664689037948847, 1.5729202758520842, 0.8107060920447111, 1.5979563985019922, 1.4801952242851257, 1.5587328560650349, 0.9929223023355007, 0.9992435183376074, 1.7015614416450262, 0.7508104592561722, 1.5362798310816288, 0.7180858962237835, 0.8346813637763262, 1.6734686810523272, 1.449725029990077, 0.7175226490944624, 1.4389808252453804, 1.6883405111730099, 0.6624189503490925, 0.9323098286986351, 0.4993015471845865, 1.4955412484705448, 0.8428404200822115, 1.708222433924675, 0.5441496875137091, 1.6830673478543758, 0.08581190183758736, 1.7464683260768652, 0.8262857645750046, 1.0009825434535742, 1.5781547892838717, 1.317761780694127, 0.7338366527110338, 0.5956862196326256, 0.8682229034602642, 1.8409953508526087, 0.3769788146018982, 1.9039545319974422, 0.6312571689486504, 1.706322217360139, 1.6732699014246464, 2.5488585587590933, 2.5282586868852377, 2.7373740319162607, 2.992548640817404, 1.9944258499890566, 1.9670150186866522, 0.561447337269783, 1.1617623027414083, 0.6368353459984064, 2.2693895660340786, 1.7176433205604553, 1.7467340771108866, 1.498437862843275, 1.806426327675581, 0.7230282071977854, 1.4452636111527681, 0.8603037726134062], "itls": [[1.2977637965232134, 0.028832558542490005, 0.02839740552008152, 0.027967890724539757, 0.027987679466605186, 0.02779410406947136, 0.02776801772415638, 0.028345292434096336, 0.028423722833395004], [0.02881482057273388, 0.028392331674695015, 0.02797338180243969, 0.027983402833342552, 0.02779017575085163, 0.027768148109316826, 0.02833854965865612, 0.028867285698652267, 0.027950160205364227], [1.3215111810714006, 0.1725471019744873, 0.02858825959265232, 0.027318481355905533, 0.027783283963799477, 0.02763640694320202, 0.028290782123804092, 0.026879802346229553, 0.027907300740480423], [0.02860097400844097, 0.02731739915907383, 0.02779301255941391, 0.02763134054839611, 0.028290128335356712, 0.02688024379312992, 0.027847304940223694, 0.028920426964759827, 1.2951757833361626], [0.02953915111720562, 1.3143015317618847, 0.48517672531306744, 0.029043247923254967, 0.029674015939235687, 0.030004186555743217, 0.027506284415721893, 0.028329312801361084, 0.02926088683307171], [0.02903328835964203, 0.029673807322978973, 0.03000405617058277, 0.027508819475769997, 0.028323030099272728, 0.02967873401939869, 0.02788121998310089, 0.538756500929594, 0.029763855040073395], [0.02972310781478882, 0.0284136813133955, 1.3285661414265633, 0.21638856828212738, 0.02891351282596588, 0.02827286720275879, 0.028137683868408203, 0.028116421774029732, 0.028606534004211426], [0.02888830564916134, 0.028279388323426247, 0.028138313442468643, 0.02811426855623722, 0.029007218778133392, 0.02782881073653698, 0.7828988209366798, 0.028970852494239807, 0.029570309445261955], [0.028951246291399002, 0.029929855838418007, 0.028370611369609833, 1.3276693392544985, 0.24207576736807823, 0.028585312888026237, 0.028463969007134438, 0.028277644887566566, 0.029062895104289055], [0.028601927682757378, 0.028453389182686806, 0.02828161232173443, 0.02899816259741783, 0.02901880070567131, 1.3363277688622475, 0.11536332219839096, 0.02893308363854885, 0.030554812401533127], [0.02891533449292183, 0.030930303037166595, 0.028714679181575775, 1.3275084663182497, 0.20255359448492527, 0.028990278020501137, 0.028879370540380478, 0.02891809120774269, 0.02957046963274479], [0.028980247676372528, 0.02887318842113018, 0.028920818120241165, 0.02997908927500248, 0.028261635452508926, 0.9648397248238325, 0.029360083863139153, 0.028788408264517784, 0.02942311391234398], [0.02937426045536995, 0.028794167563319206, 0.029360095039010048, 0.028816591948270798, 0.9709610920399427, 0.029142484068870544, 0.028450973331928253, 0.028286783024668694, 0.02867273986339569], [0.029153116047382355, 0.0284348726272583, 0.028286350890994072, 0.02904597297310829, 0.02895805612206459, 1.3324876558035612, 0.34014290757477283, 0.029089024290442467, 0.02951054833829403], [0.029078423976898193, 0.029839808121323586, 0.02845870517194271, 0.722493490204215, 0.029293689876794815, 0.02855656109750271, 0.029586531221866608, 0.028692908585071564, 0.02928406000137329], [0.0292944498360157, 0.028558745980262756, 0.029587261378765106, 0.02869587391614914, 0.029227636754512787, 0.028528910130262375, 1.3357473835349083, 0.17248307913541794, 0.03167176805436611], [0.032008443027734756, 0.028366152197122574, 0.6897374894469976, 0.02885867841541767, 0.02746574953198433, 0.028224462643265724, 0.028158383443951607, 0.028148863464593887, 0.02899298258125782], [0.028841227293014526, 0.027465596795082092, 0.02822042815387249, 0.028156859800219536, 0.02814672701060772, 0.029380984604358673, 0.027893444523215294, 0.8069402799010277, 0.028085973113775253], [0.028048504143953323, 0.029100265353918076, 1.333924239501357, 0.3109531458467245, 0.02597656287252903, 0.04289212077856064, 0.028894927352666855, 0.013025900349020958, 0.0321587473154068], [0.025985898450016975, 0.04287945665419102, 0.028894728049635887, 0.013026082888245583, 0.03257754258811474, 0.05039904825389385, 1.3119121938943863, 0.0874546654522419, 0.030007624998688698], [0.030380235984921455, 0.028077388182282448, 0.6896035969257355, 0.02851938270032406, 0.027043389156460762, 0.028101595118641853, 0.028219394385814667, 0.027967805042862892, 0.02901591546833515], [0.028537705540657043, 0.02704267017543316, 0.028104189783334732, 0.028219887986779213, 0.027977459132671356, 0.028940144926309586, 0.02873655967414379, 1.340121852234006, 0.07033625617623329], [0.02718357741832733, 1.3392035830765963, 0.3219831958413124, 0.041908660903573036, 0.019038543105125427, 0.02700856700539589, 0.0278534647077322, 0.028189320117235184, 0.030269667506217957], [0.04190879873931408, 0.019049596041440964, 0.026992395520210266, 0.027849910780787468, 0.028186693787574768, 0.030624816194176674, 0.036504339426755905, 0.6260452959686518, 0.03238724544644356], [0.032383810728788376, 0.03008461929857731, 0.9026690255850554, 0.02862064354121685, 0.035918787121772766, 0.022988392040133476, 0.025968968868255615, 0.027047019451856613, 0.031269339844584465], [0.028591888025403023, 0.03590519167482853, 0.022995708510279655, 0.02596048265695572, 0.027044354006648064, 0.03172755055129528, 0.03414140082895756, 0.46519154496490955, 0.02725496143102646], [0.02762053720653057, 0.03503592498600483, 1.331725087016821, 0.128983149304986, 0.017243215814232826, 0.03540552780032158, 0.022184131667017937, 0.035781195387244225, 0.024153990671038628], [0.017301734536886215, 0.03540599159896374, 0.02219001203775406, 0.03577311150729656, 0.024102631956338882, 0.04042627662420273, 0.802945002913475, 0.01863687112927437, 0.03028864413499832], [0.018613504245877266, 0.030721008777618408, 0.056392936035990715, 1.3097844198346138, 0.34210214763879776, 0.02867867238819599, 0.028778107836842537, 0.02819438837468624, 0.029100768268108368], [0.02867085672914982, 0.028776515275239944, 0.02819385752081871, 0.03029622696340084, 0.04200867563486099, 0.5014390032738447, 0.027764638885855675, 0.02767154574394226, 0.02977408468723297], [0.027779215946793556, 0.027680711820721626, 0.02966904453933239, 0.02935122884809971, 1.3361947778612375, 0.31821106374263763, 0.02976553700864315, 0.027639035135507584, 0.029014673084020615], [0.02975420467555523, 0.02763359434902668, 0.029421770945191383, 0.02830490469932556, 0.057584481313824654, 0.02689334936439991, 0.027128731831908226, 0.028018508106470108, 0.030333098024129868], [0.026888839900493622, 0.027126869186758995, 0.028038695454597473, 0.03070952743291855, 0.03024735487997532, 0.04979771561920643, 1.3068065587431192, 0.3598065432161093, 0.02922828681766987], [0.029244305565953255, 0.050523312762379646, 0.7764053717255592, 0.028317730873823166, 0.028537897393107414, 0.028590286150574684, 0.0286256093531847, 0.028435122221708298, 0.02973501943051815], [0.028313271701335907, 0.0285302996635437, 0.02859700843691826, 0.02862495183944702, 0.028435422107577324, 0.029834026470780373, 0.027831345796585083, 0.9734612535685301, 0.025271443650126457], [0.02536255680024624, 0.035231031477451324, 1.3352341763675213, 0.2081925831735134, 0.03667657636106014, 0.03487534075975418, 0.02788781188428402, 0.020049920305609703, 0.03226301074028015], [0.036710385233163834, 0.03488028235733509, 0.027916863560676575, 0.020024573430418968, 0.03217199072241783, 0.044399067759513855, 1.2741141282022, 0.04086945205926895, 0.04157324507832527], [0.0408683679997921, 0.04168093763291836, 0.03698032535612583, 0.6972149237990379, 0.02854352444410324, 0.03397541679441929, 0.02189667895436287, 0.028392121195793152, 0.028494564816355705], [0.02854422852396965, 0.03396260365843773, 0.02187708020210266, 0.028410188853740692, 0.02896714396774769, 0.02784951962530613, 0.5680698584765196, 0.028325878083705902, 0.028570085763931274], [0.028328651562333107, 0.02848122827708721, 0.028977032750844955, 0.839925142005086, 0.028795180842280388, 0.028155546635389328, 0.02798466384410858, 0.02884789928793907, 0.02850627712905407], [0.028797516599297523, 0.028110411018133163, 0.028021864593029022, 0.02884548343718052, 0.028985340148210526, 0.02900969423353672, 1.346432639285922, 0.4656075984239578, 0.03230333887040615], [0.03270191699266434, 0.026268932968378067, 0.35090641118586063, 0.02930316887795925, 0.027385683730244637, 0.028022525832057, 0.028198907151818275, 0.028367474675178528, 0.031474316492676735], [0.029320649802684784, 0.02738730050623417, 0.028013648465275764, 0.02820071205496788, 0.02836834453046322, 0.03138391673564911, 0.026789462193846703, 1.3399174604564905, 0.5374484602361917], [0.02900788001716137, 0.602266101166606, 0.030236154794692993, 0.03153318725526333, 0.02694644033908844, 0.026030631735920906, 0.03498893603682518, 0.02297878824174404, 0.030350498855113983], [0.03020802140235901, 0.0315284077078104, 0.026954183354973793, 0.02603067457675934, 0.034977203235030174, 0.022984176874160767, 0.030726358294487, 0.026045411825180054, 1.337838090956211], [1.3311423119157553, 0.03775783069431782, 0.021816838532686234, 0.02701430767774582, 0.03506973572075367, 0.024943115189671516, 0.03402089327573776, 0.020958933979272842, 0.03746917471289635], [0.03774961642920971, 0.02180871181190014, 0.02701587975025177, 0.03506677225232124, 0.024938859045505524, 0.034025680273771286, 0.02095142751932144, 0.03791120834648609, 0.020403288304805756], [0.03327649086713791, 0.043998392298817635, 0.009889386594295502, 0.03702814504504204, 0.023929035291075706, 0.033757977187633514, 0.02382226660847664, 0.02344903163611889, 0.030768336728215218], [0.03326950594782829, 0.04402313008904457, 0.009893951937556267, 0.03702978044748306, 0.0239325650036335, 0.0337531678378582, 0.023817595094442368, 0.023455604910850525, 0.030304450541734695], [0.2561016920953989, 0.026738755404949188, 0.027964476495981216, 0.032963139936327934, 0.028981832787394524, 0.025046391412615776, 0.029981834813952446, 0.028971321880817413, 0.03038140945136547], [0.026747053489089012, 0.0279691144824028, 0.03296087682247162, 0.02898622862994671, 0.025048956274986267, 0.029976867139339447, 0.02897654101252556, 0.030301999300718307, 0.02768474817276001], [0.028862986713647842, 0.030932344496250153, 0.025963908061385155, 0.029016807675361633, 0.028986772522330284, 0.025944450870156288, 0.03711257688701153, 0.019954120740294456, 0.0293717160820961], [0.028883405029773712, 0.03092760592699051, 0.025961903855204582, 0.029014505445957184, 0.028990479186177254, 0.025953687727451324, 0.03710574470460415, 0.01995408721268177, 0.028897523880004883], [0.601081183180213, 0.02980000153183937, 0.0379603635519743, 0.0179439727216959, 0.033008527010679245, 0.02202867716550827, 0.02799282781779766, 0.033051880076527596, 0.02523607574403286], [0.02978549525141716, 0.037960782647132874, 0.017939193174242973, 0.03299948014318943, 0.022029908373951912, 0.027997387573122978, 0.03305521607398987, 0.02564789168536663, 0.024875981733202934], [1.333828492090106, 0.323818476870656, 0.04196617566049099, 0.0402760524302721, 0.040095362812280655, 0.041916411370038986, 0.03954598866403103, 0.039972592145204544, 0.04057106748223305], [0.04198957979679108, 0.040272945538163185, 0.04010005295276642, 0.041900722309947014, 0.0395597442984581, 0.03997002728283405, 0.04051410034298897, 0.0385588388890028, 1.3493801690638065], [1.3447735849767923, 0.07219819165766239, 0.040999485179781914, 0.04151735082268715, 0.03960018791258335, 0.03957707807421684, 0.03975467011332512, 0.039717379957437515, 0.043076349422335625], [0.04100415296852589, 0.04150648042559624, 0.03959819674491882, 0.03959503956139088, 0.039743902161717415, 0.03971641696989536, 0.04340596683323383, 0.03742646798491478, 1.3435153439640999], [1.3564631920307875, 0.33279661275446415, 0.02589297480881214, 0.02916163206100464, 0.05083645135164261, 0.0060394927859306335, 0.032886927947402, 0.0375467911362648, 0.02375267632305622], [0.025881875306367874, 0.029174325987696648, 0.050835827365517616, 0.006030559539794922, 0.03288489207625389, 0.03755589947104454, 0.024102745577692986, 0.048682503402233124, 0.6740397457033396], [0.036855120211839676, 1.3388036824762821, 0.06974709592759609, 0.03600478917360306, 0.01999703049659729, 0.02893606573343277, 0.028933942317962646, 0.02798798866569996, 0.029418887570500374], [0.03601436875760555, 0.019998643547296524, 0.028937015682458878, 0.028937147930264473, 0.027994664385914803, 0.02934051863849163, 0.027697520330548286, 0.8331493437290192, 0.017584597691893578], [0.017925556749105453, 0.03554875962436199, 0.02229493111371994, 0.03545629419386387, 0.017505187541246414, 0.028977686539292336, 0.03297625295817852, 0.022115832194685936, 0.02782679721713066]], "generated_texts": ["\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\nOkay, the user sent \"null\".", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u4e0a\u6d77", "\n\u597d\u7684\uff0c\u7528\u6237\u7684\u95ee\u9898\u662f\u5173\u4e8e\u4e0a\u6d77\u5bab", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u4e0a\u6d77", "\n\u597d\u7684\uff0c\u7528\u6237\u95ee\u7684\u662f\u201c\u65f6\u5149\u5217\u8f66", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u7528\u6237\u7684\u95ee\u9898\u662f\u201c\u5357\u7fd4", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u9ec4", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u82cf\u5dde", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u56de\u7b54\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u4e0a\u6d77", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u4e0a\u6d77", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u56de\u7b54\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u56de\u7b54\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u7528\u6237\u7684\u95ee\u9898\u662f\u201c\u90d1\u6e58", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u56de\u7b54\u7528\u6237\u5173\u4e8e\u5e7f\u6c7d", "\n\u597d\u7684\uff0c\u7528\u6237\u95ee\u7684\u662f\u5e7f\u5dde\u54ea\u91cc\u6709", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u4e0a\u6d77", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u4e0a\u6d77", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u5e7f\u5dde", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u4e0a\u6d77", "\n\u597d\u7684\uff0c\u7528\u6237\u95ee\u7684\u662f\u5982\u4f55\u63d0\u524d\u8d2d\u4e70", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u7684\u95ee\u9898\uff1a\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u7528\u6237\u95ee\u7684\u662f\u676d\u5dde\u54ea\u5bb6\u4e1c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5e2e\u7528\u6237\u89e3\u51b3\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u6cf0\u56fd", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u7528\u6237\u7684\u95ee\u9898\u662f\u201c\u4e09\u7c7b", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u56de\u7b54\u7528\u6237\u5173\u4e8e\u201c", "\n\u597d\u7684\uff0c\u6211\u73b0\u5728\u9700\u8981\u5904\u7406\u7528\u6237\u5173\u4e8e\u201c"], "errors": ["", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", "", ""], "mean_ttft_ms": 1310.438703163527, "median_ttft_ms": 1447.4943205714226, "std_ttft_ms": 630.1523511942625, "p99_ttft_ms": 2831.788637209683, "mean_tpot_ms": 134.1971669785885, "median_tpot_ms": 133.12916250692476, "std_tpot_ms": 63.93852676737001, "p99_tpot_ms": 226.50873485331732, "mean_itl_ms": 134.19719576227683, "median_itl_ms": 28.990378603339195, "std_itl_ms": 315.47057592591364, "p99_itl_ms": 1339.9685584008694} ```

I found most of the itls are as expected, but there are some abnormally large values, for example 1.2977637965232134, which leads to the abnormally large average tpot.

[IAmMorrow]

I made the same observation. Generally speaking, it seem the first inference always "warm up" and then the other ones are way faster. And this is without any form of cache enabled. I don't know if the issue reside in VLLM or to the GPU power profile itself ?