| 1 | # SPDX-License-Identifier: Apache-2.0 |
| 2 | # SPDX-FileCopyrightText: Copyright contributors to the vLLM project |
| 3 | import asyncio |
| 4 | import subprocess |
| 5 | import sys |
| 6 | import tempfile |
| 7 | import time |
| 8 | from http import HTTPStatus |
| 9 | |
| 10 | import openai |
| 11 | import pytest |
| 12 | import pytest_asyncio |
| 13 | import requests |
| 14 | from prometheus_client.parser import text_string_to_metric_families |
| 15 | from transformers import AutoTokenizer |
| 16 | |
| 17 | from tests.conftest import LocalAssetServer |
| 18 | from tests.utils import RemoteOpenAIServer |
| 19 | from vllm import version |
| 20 | from vllm.utils.network_utils import get_open_port |
| 21 | |
| 22 | MODELS = { |
| 23 | "text": "TinyLlama/TinyLlama-1.1B-Chat-v1.0", |
| 24 | "multimodal": "HuggingFaceTB/SmolVLM-256M-Instruct", |
| 25 | } |
| 26 | PREV_MINOR_VERSION = version._prev_minor_version() |
| 27 | |
| 28 | |
| 29 | @pytest.fixture(scope="module", params=list(MODELS.keys())) |
| 30 | def model_key(request): |
| 31 | yield request.param |
| 32 | |
| 33 | |
| 34 | @pytest.fixture(scope="module") |
| 35 | def default_server_args(): |
| 36 | return [ |
| 37 | # use half precision for speed and memory savings in CI environment |
| 38 | "--dtype", |
| 39 | "bfloat16", |
| 40 | "--max-model-len", |
| 41 | "1024", |
| 42 | "--enforce-eager", |
| 43 | "--max-num-seqs", |
| 44 | "128", |
| 45 | ] |
| 46 | |
| 47 | |
| 48 | @pytest.fixture( |
| 49 | scope="module", |
| 50 | params=[ |
| 51 | "", |
| 52 | "--enable-chunked-prefill", |
| 53 | f"--show-hidden-metrics-for-version={PREV_MINOR_VERSION}", |
| 54 | ], |
| 55 | ) |
| 56 | def server(model_key, default_server_args, request): |
| 57 | if request.param: |
| 58 | default_server_args.append(request.param) |
| 59 | |
| 60 | model_name = MODELS[model_key] |
| 61 | with RemoteOpenAIServer(model_name, default_server_args) as remote_server: |
| 62 | yield remote_server |
| 63 | |
| 64 | |
| 65 | @pytest_asyncio.fixture |
| 66 | async def client(server): |
| 67 | async with server.get_async_client() as cl: |
| 68 | yield cl |
| 69 | |
| 70 | |
| 71 | _PROMPT = "Hello my name is Robert and I love magic" |
| 72 | |
| 73 | |
| 74 | def _get_expected_values(num_requests: int, prompt_ids: list[int], max_tokens: int): |
| 75 | num_prompt_tokens = len(prompt_ids) |
| 76 | |
| 77 | # {metric_family: [(suffix, expected_value)]} |
| 78 | return { |
| 79 | "vllm:time_to_first_token_seconds": [("_count", num_requests)], |
| 80 | "vllm:inter_token_latency_seconds": [ |
| 81 | ("_count", num_requests * (max_tokens - 1)) |
| 82 | ], |
| 83 | "vllm:e2e_request_latency_seconds": [("_count", num_requests)], |
| 84 | "vllm:request_queue_time_seconds": [("_count", num_requests)], |
| 85 | "vllm:request_inference_time_seconds": [("_count", num_requests)], |
| 86 | "vllm:request_prefill_time_seconds": [("_count", num_requests)], |
| 87 | "vllm:request_decode_time_seconds": [("_count", num_requests)], |
| 88 | "vllm:request_num_preemptions": [("_count", num_requests)], |
| 89 | "vllm:request_prompt_tokens": [ |
| 90 | ("_sum", num_requests * num_prompt_tokens), |
| 91 | ("_count", num_requests), |
| 92 | ], |
| 93 | "vllm:request_generation_tokens": [ |
| 94 | ("_sum", num_requests * max_tokens), |
| 95 | ("_count", num_requests), |
| 96 | ], |
| 97 | "vllm:request_params_n": [("_count", num_requests)], |
| 98 | "vllm:request_params_max_tokens": [ |
| 99 | ("_sum", num_requests * max_tokens), |
| 100 | ("_count", num_requests), |
| 101 | ], |
| 102 | "vllm:iteration_tokens_total": [ |
| 103 | ( |
| 104 | "_sum", |
| 105 | num_requests * (num_prompt_tokens + max_tokens), |
| 106 | ), |
| 107 | ("_count", num_requests * max_tokens), |
| 108 | ], |
| 109 | "vllm:prompt_tokens": [("_total", num_requests * num_prompt_tokens)], |
| 110 | "vllm:generation_tokens": [("_total", num_requests * max_tokens)], |
| 111 | "vllm:request_success": [("_total", num_requests)], |
| 112 | } |
| 113 | |
| 114 | |
| 115 | @pytest.mark.asyncio |
| 116 | async def test_metrics_counts( |
| 117 | server: RemoteOpenAIServer, |
| 118 | client: openai.AsyncClient, |
| 119 | model_key: str, |
| 120 | ): |
| 121 | if model_key == "multimodal": |
| 122 | pytest.skip("Unnecessary test") |
| 123 | |
| 124 | model_name = MODELS[model_key] |
| 125 | tokenizer = AutoTokenizer.from_pretrained(model_name) |
| 126 | prompt_ids = tokenizer.encode(_PROMPT) |
| 127 | num_requests = 10 |
| 128 | max_tokens = 10 |
| 129 | |
| 130 | for _ in range(num_requests): |
| 131 | # sending a request triggers the metrics to be logged. |
| 132 | await client.completions.create( |
| 133 | model=model_name, |
| 134 | prompt=prompt_ids, |
| 135 | max_tokens=max_tokens, |
| 136 | ) |
| 137 | |
| 138 | response = requests.get(server.url_for("metrics")) |
| 139 | print(response.text) |
| 140 | assert response.status_code == HTTPStatus.OK |
| 141 | |
| 142 | # Loop over all expected metric_families |
| 143 | expected_values = _get_expected_values(num_requests, prompt_ids, max_tokens) |
| 144 | for metric_family, suffix_values_list in expected_values.items(): |
| 145 | if metric_family not in EXPECTED_METRICS_V1 or ( |
| 146 | not server.show_hidden_metrics |
| 147 | and metric_family in HIDDEN_DEPRECATED_METRICS |
| 148 | ): |
| 149 | continue |
| 150 | |
| 151 | found_metric = False |
| 152 | |
| 153 | # Check to see if the metric_family is found in the prom endpoint. |
| 154 | for family in text_string_to_metric_families(response.text): |
| 155 | if family.name == metric_family: |
| 156 | found_metric = True |
| 157 | |
| 158 | # Check that each suffix is found in the prom endpoint. |
| 159 | for suffix, expected_value in suffix_values_list: |
| 160 | metric_name_w_suffix = f"{metric_family}{suffix}" |
| 161 | found_suffix = False |
| 162 | |
| 163 | for sample in family.samples: |
| 164 | if sample.name == metric_name_w_suffix: |
| 165 | found_suffix = True |
| 166 | |
| 167 | # For each suffix, value sure the value matches |
| 168 | # what we expect. |
| 169 | assert sample.value == expected_value, ( |
| 170 | f"{metric_name_w_suffix} expected value of " |
| 171 | f"{expected_value} did not match found value " |
| 172 | f"{sample.value}" |
| 173 | ) |
| 174 | break |
| 175 | assert found_suffix, ( |
| 176 | f"Did not find {metric_name_w_suffix} in prom endpoint" |
| 177 | ) |
| 178 | break |
| 179 | |
| 180 | assert found_metric, f"Did not find {metric_family} in prom endpoint" |
| 181 | |
| 182 | |
| 183 | EXPECTED_METRICS_V1 = [ |
| 184 | "vllm:num_requests_running", |
| 185 | "vllm:num_requests_waiting", |
| 186 | "vllm:num_requests_waiting_by_reason", |
| 187 | "vllm:kv_cache_usage_perc", |
| 188 | "vllm:prefix_cache_queries", |
| 189 | "vllm:prefix_cache_hits", |
| 190 | "vllm:num_preemptions_total", |
| 191 | "vllm:prompt_tokens_total", |
| 192 | "vllm:generation_tokens_total", |
| 193 | "vllm:iteration_tokens_total", |
| 194 | "vllm:cache_config_info", |
| 195 | "vllm:request_success_total", |
| 196 | "vllm:request_prompt_tokens_sum", |
| 197 | "vllm:request_prompt_tokens_bucket", |
| 198 | "vllm:request_prompt_tokens_count", |
| 199 | "vllm:request_generation_tokens_sum", |
| 200 | "vllm:request_generation_tokens_bucket", |
| 201 | "vllm:request_generation_tokens_count", |
| 202 | "vllm:request_params_n_sum", |
| 203 | "vllm:request_params_n_bucket", |
| 204 | "vllm:request_params_n_count", |
| 205 | "vllm:request_params_max_tokens_sum", |
| 206 | "vllm:request_params_max_tokens_bucket", |
| 207 | "vllm:request_params_max_tokens_count", |
| 208 | "vllm:time_to_first_token_seconds_sum", |
| 209 | "vllm:time_to_first_token_seconds_bucket", |
| 210 | "vllm:time_to_first_token_seconds_count", |
| 211 | "vllm:inter_token_latency_seconds_sum", |
| 212 | "vllm:inter_token_latency_seconds_bucket", |
| 213 | "vllm:inter_token_latency_seconds_count", |
| 214 | "vllm:e2e_request_latency_seconds_sum", |
| 215 | "vllm:e2e_request_latency_seconds_bucket", |
| 216 | "vllm:e2e_request_latency_seconds_count", |
| 217 | "vllm:request_queue_time_seconds_sum", |
| 218 | "vllm:request_queue_time_seconds_bucket", |
| 219 | "vllm:request_queue_time_seconds_count", |
| 220 | "vllm:request_inference_time_seconds_sum", |
| 221 | "vllm:request_inference_time_seconds_bucket", |
| 222 | "vllm:request_inference_time_seconds_count", |
| 223 | "vllm:request_prefill_time_seconds_sum", |
| 224 | "vllm:request_prefill_time_seconds_bucket", |
| 225 | "vllm:request_prefill_time_seconds_count", |
| 226 | "vllm:request_decode_time_seconds_sum", |
| 227 | "vllm:request_decode_time_seconds_bucket", |
| 228 | "vllm:request_decode_time_seconds_count", |
| 229 | "vllm:request_num_preemptions_sum", |
| 230 | "vllm:request_num_preemptions_bucket", |
| 231 | "vllm:request_num_preemptions_count", |
| 232 | ] |
| 233 | |
| 234 | EXPECTED_METRICS_MM = [ |
| 235 | "vllm:mm_cache_queries", |
| 236 | "vllm:mm_cache_hits", |
| 237 | ] |
| 238 | |
| 239 | HIDDEN_DEPRECATED_METRICS: list[str] = [] |
| 240 | |
| 241 | |
| 242 | @pytest.mark.asyncio |
| 243 | async def test_metrics_exist( |
| 244 | local_asset_server: LocalAssetServer, |
| 245 | server: RemoteOpenAIServer, |
| 246 | client: openai.AsyncClient, |
| 247 | model_key: str, |
| 248 | ): |
| 249 | model_name = MODELS[model_key] |
| 250 | |
| 251 | # sending a request triggers the metrics to be logged. |
| 252 | if model_key == "text": |
| 253 | await client.completions.create( |
| 254 | model=model_name, |
| 255 | prompt="Hello, my name is", |
| 256 | max_tokens=5, |
| 257 | temperature=0.0, |
| 258 | ) |
| 259 | else: |
| 260 | # https://upload.wikimedia.org/wikipedia/commons/thumb/d/dd/Gfp-wisconsin-madison-the-nature-boardwalk.jpg/2560px-Gfp-wisconsin-madison-the-nature-boardwalk.jpg |
| 261 | await client.chat.completions.create( |
| 262 | model=model_name, |
| 263 | messages=[ |
| 264 | { |
| 265 | "role": "user", |
| 266 | "content": [ |
| 267 | { |
| 268 | "type": "image_url", |
| 269 | "image_url": { |
| 270 | "url": local_asset_server.url_for( |
| 271 | "2560px-Gfp-wisconsin-madison-the-nature-boardwalk.jpg" |
| 272 | ), |
| 273 | }, |
| 274 | }, |
| 275 | {"type": "text", "text": "What's in this image?"}, |
| 276 | ], |
| 277 | } |
| 278 | ], |
| 279 | max_tokens=5, |
| 280 | temperature=0.0, |
| 281 | ) |
| 282 | |
| 283 | response = requests.get(server.url_for("metrics")) |
| 284 | assert response.status_code == HTTPStatus.OK |
| 285 | |
| 286 | expected_metrics = EXPECTED_METRICS_V1 |
| 287 | if model_key == "multimodal": |
| 288 | # NOTE: Don't use in-place assignment |
| 289 | expected_metrics = expected_metrics + EXPECTED_METRICS_MM |
| 290 | |
| 291 | for metric in expected_metrics: |
| 292 | if metric in HIDDEN_DEPRECATED_METRICS and not server.show_hidden_metrics: |
| 293 | continue |
| 294 | assert metric in response.text |
| 295 | |
| 296 | cache_config_samples = [ |
| 297 | sample |
| 298 | for family in text_string_to_metric_families(response.text) |
| 299 | if family.name == "vllm:cache_config_info" |
| 300 | for sample in family.samples |
| 301 | ] |
| 302 | assert cache_config_samples |
| 303 | for sample in cache_config_samples: |
| 304 | assert sample.labels.get("kv_cache_size_tokens") not in (None, "None", "") |
| 305 | assert sample.labels.get("kv_cache_max_concurrency") not in (None, "None", "") |
| 306 | |
| 307 | |
| 308 | @pytest.mark.asyncio |
| 309 | async def test_abort_metrics_reset( |
| 310 | server: RemoteOpenAIServer, |
| 311 | client: openai.AsyncClient, |
| 312 | model_key: str, |
| 313 | ): |
| 314 | model_name = MODELS[model_key] |
| 315 | tokenizer = AutoTokenizer.from_pretrained(model_name) |
| 316 | prompt_ids = tokenizer.encode(_PROMPT) |
| 317 | |
| 318 | running_requests, waiting_requests, kv_cache_usage = _get_running_metrics_from_api( |
| 319 | server, |
| 320 | ) |
| 321 | |
| 322 | # Expect no running requests or kvcache usage |
| 323 | assert running_requests == 0 |
| 324 | assert waiting_requests == 0 |
| 325 | assert kv_cache_usage == 0.0 |
| 326 | |
| 327 | # Start some long-running requests that we can abort |
| 328 | tasks = [] |
| 329 | for _ in range(3): |
| 330 | task = asyncio.create_task( |
| 331 | client.completions.create( |
| 332 | model=model_name, |
| 333 | prompt=prompt_ids, |
| 334 | max_tokens=500, # Long generation to give time to abort |
| 335 | temperature=0.0, |
| 336 | ) |
| 337 | ) |
| 338 | tasks.append(task) |
| 339 | |
| 340 | # Poll until we see running requests rather than using a fixed sleep, |
| 341 | # since generation speed varies across hardware. |
| 342 | try: |
| 343 | await _poll_until( |
| 344 | lambda: _get_running_metrics_from_api(server)[0] > 0, |
| 345 | timeout=10.0, |
| 346 | interval=0.1, |
| 347 | description="running_requests > 0", |
| 348 | ) |
| 349 | except TimeoutError: |
| 350 | for task in tasks: |
| 351 | task.cancel() |
| 352 | await asyncio.gather(*tasks, return_exceptions=True) |
| 353 | pytest.fail("Requests never appeared as running in metrics") |
| 354 | |
| 355 | # Check that we have running requests |
| 356 | running_requests, waiting_requests, kv_cache_usage = _get_running_metrics_from_api( |
| 357 | server, |
| 358 | ) |
| 359 | |
| 360 | # Expect running requests and kvcache usage |
| 361 | assert running_requests > 0 |
| 362 | assert kv_cache_usage > 0 |
| 363 | |
| 364 | # Cancel all tasks to abort the requests |
| 365 | for task in tasks: |
| 366 | task.cancel() |
| 367 | await asyncio.gather(*tasks, return_exceptions=True) |
| 368 | |
| 369 | # Poll until metrics reset rather than using a fixed sleep |
| 370 | await _poll_until( |
| 371 | lambda: _get_running_metrics_from_api(server) == (0, 0, 0), |
| 372 | timeout=10.0, |
| 373 | interval=0.2, |
| 374 | description="gauge metrics back to zero", |
| 375 | ) |
| 376 | |
| 377 | # Verify running and waiting requests counts and KV cache usage are zero |
| 378 | running_requests_after, waiting_requests_after, kv_cache_usage_after = ( |
| 379 | _get_running_metrics_from_api(server) |
| 380 | ) |
| 381 | |
| 382 | assert running_requests_after == 0, ( |
| 383 | f"Expected 0 running requests after abort, got {running_requests_after}" |
| 384 | ) |
| 385 | assert waiting_requests_after == 0, ( |
| 386 | f"Expected 0 waiting requests after abort, got {waiting_requests_after}" |
| 387 | ) |
| 388 | assert kv_cache_usage_after == 0, ( |
| 389 | f"Expected 0% KV cache usage after abort, got {kv_cache_usage_after}" |
| 390 | ) |
| 391 | |
| 392 | |
| 393 | async def _poll_until( |
| 394 | predicate, *, timeout: float, interval: float = 0.5, description: str = "condition" |
| 395 | ): |
| 396 | """Poll until predicate() returns True, or raise TimeoutError.""" |
| 397 | start = time.time() |
| 398 | while time.time() - start < timeout: |
| 399 | if predicate(): |
| 400 | return |
| 401 | await asyncio.sleep(interval) |
| 402 | raise TimeoutError(f"Timed out after {timeout}s waiting for: {description}") |
| 403 | |
| 404 | |
| 405 | def _get_running_metrics_from_api(server: RemoteOpenAIServer): |
| 406 | """Return (running_count, waiting_count, kv_cache_usage).""" |
| 407 | response = requests.get(server.url_for("metrics")) |
| 408 | assert response.status_code == HTTPStatus.OK |
| 409 | |
| 410 | # Verify running and waiting requests counts and KV cache usage are zero |
| 411 | running_requests, waiting_requests, kv_cache_usage = None, None, None |
| 412 | |
| 413 | kv_cache_usage_metric = "vllm:kv_cache_usage_perc" |
| 414 | |
| 415 | for family in text_string_to_metric_families(response.text): |
| 416 | if family.name == "vllm:num_requests_running": |
| 417 | for sample in family.samples: |
| 418 | if sample.name == "vllm:num_requests_running": |
| 419 | running_requests = sample.value |
| 420 | break |
| 421 | elif family.name == "vllm:num_requests_waiting": |
| 422 | for sample in family.samples: |
| 423 | if sample.name == "vllm:num_requests_waiting": |
| 424 | waiting_requests = sample.value |
| 425 | break |
| 426 | elif family.name == kv_cache_usage_metric: |
| 427 | for sample in family.samples: |
| 428 | if sample.name == kv_cache_usage_metric: |
| 429 | kv_cache_usage = sample.value |
| 430 | break |
| 431 | |
| 432 | assert running_requests is not None |
| 433 | assert waiting_requests is not None |
| 434 | assert kv_cache_usage is not None |
| 435 | |
| 436 | return running_requests, waiting_requests, kv_cache_usage |
| 437 | |
| 438 | |
| 439 | def test_metrics_exist_run_batch(): |
| 440 | input_batch = """{"custom_id": "request-0", "method": "POST", "url": "/v1/embeddings", "body": {"model": "intfloat/multilingual-e5-small", "input": "You are a helpful assistant."}}""" # noqa: E501 |
| 441 | |
| 442 | base_url = "0.0.0.0" |
| 443 | port = str(get_open_port()) |
| 444 | server_url = f"http://{base_url}:{port}" |
| 445 | |
| 446 | with ( |
| 447 | tempfile.NamedTemporaryFile("w") as input_file, |
| 448 | tempfile.NamedTemporaryFile("r") as output_file, |
| 449 | ): |
| 450 | input_file.write(input_batch) |
| 451 | input_file.flush() |
| 452 | proc = subprocess.Popen( |
| 453 | [ |
| 454 | sys.executable, |
| 455 | "-m", |
| 456 | "vllm.entrypoints.launchers.run_batch", |
| 457 | "-i", |
| 458 | input_file.name, |
| 459 | "-o", |
| 460 | output_file.name, |
| 461 | "--model", |
| 462 | "intfloat/multilingual-e5-small", |
| 463 | "--enable-metrics", |
| 464 | "--host", |
| 465 | base_url, |
| 466 | "--port", |
| 467 | port, |
| 468 | ], |
| 469 | ) |
| 470 | |
| 471 | try: |
| 472 | |
| 473 | def is_server_up(url): |
| 474 | try: |
| 475 | response = requests.get(url) |
| 476 | return response.status_code == 200 |
| 477 | except requests.ConnectionError: |
| 478 | return False |
| 479 | |
| 480 | start = time.time() |
| 481 | timeout = 120 |
| 482 | while not is_server_up(server_url): |
| 483 | if proc.poll() is not None: |
| 484 | pytest.fail( |
| 485 | f"Batch process exited early with returncode={proc.returncode}" |
| 486 | ) |
| 487 | if time.time() - start > timeout: |
| 488 | pytest.fail("Batch server did not start within timeout") |
| 489 | time.sleep(1) |
| 490 | |
| 491 | response = requests.get(server_url + "/metrics") |
| 492 | assert response.status_code == HTTPStatus.OK |
| 493 | finally: |
| 494 | proc.terminate() |
| 495 | try: |
| 496 | proc.wait(timeout=15) |
| 497 | except subprocess.TimeoutExpired: |
| 498 | proc.kill() |
| 499 | proc.wait(timeout=5) |