Reduce logs in CLI scripts and plugin loader by mgoin · Pull Request #18970 · vllm-project/vllm (original) (raw)

vllm bench throughput --model RedHatAI/Meta-Llama-3.1-8B-FP8 --load-format dummy --input-len 1000 --output-len 100
INFO 05-30 18:21:32 [__init__.py:243] Automatically detected platform cuda.
When dataset path is not set, it will default to random dataset
INFO 05-30 18:21:36 [datasets.py:333] Sampling input_len from [999, 999] and output_len from [100, 100]
INFO 05-30 18:21:47 [config.py:813] This model supports multiple tasks: {'score', 'generate', 'reward', 'embed', 'classify'}. Defaulting to 'generate'.
INFO 05-30 18:21:47 [config.py:2143] Chunked prefill is enabled with max_num_batched_tokens=16384.
INFO 05-30 18:21:52 [__init__.py:243] Automatically detected platform cuda.
INFO 05-30 18:21:54 [core.py:448] Waiting for init message from front-end.
INFO 05-30 18:21:54 [core.py:68] Initializing a V1 LLM engine (v0.9.1.dev287+g89b1388d8) with config: model='RedHatAI/Meta-Llama-3.1-8B-FP8', speculative_config=None, tokenizer='RedHatAI/Meta-Llama-3.1-8B-FP8', skip_tokenizer_init=False, tokenizer_mode=auto, revision=None, override_neuron_config={}, tokenizer_revision=None, trust_remote_code=False, dtype=torch.float16, max_seq_len=131072, download_dir=None, load_format=LoadFormat.DUMMY, tensor_parallel_size=1, pipeline_parallel_size=1, disable_custom_all_reduce=False, quantization=compressed-tensors, enforce_eager=False, kv_cache_dtype=auto,  device_config=cuda, decoding_config=DecodingConfig(backend='auto', disable_fallback=False, disable_any_whitespace=False, disable_additional_properties=False, reasoning_backend=''), observability_config=ObservabilityConfig(show_hidden_metrics_for_version=None, otlp_traces_endpoint=None, collect_detailed_traces=None), seed=0, served_model_name=RedHatAI/Meta-Llama-3.1-8B-FP8, num_scheduler_steps=1, multi_step_stream_outputs=True, enable_prefix_caching=True, chunked_prefill_enabled=True, use_async_output_proc=True, pooler_config=None, compilation_config={"level":3,"debug_dump_path":"","cache_dir":"","backend":"","custom_ops":["none"],"splitting_ops":["vllm.unified_attention","vllm.unified_attention_with_output"],"use_inductor":true,"compile_sizes":[],"inductor_compile_config":{"enable_auto_functionalized_v2":false},"inductor_passes":{},"use_cudagraph":true,"cudagraph_num_of_warmups":1,"cudagraph_capture_sizes":[512,504,496,488,480,472,464,456,448,440,432,424,416,408,400,392,384,376,368,360,352,344,336,328,320,312,304,296,288,280,272,264,256,248,240,232,224,216,208,200,192,184,176,168,160,152,144,136,128,120,112,104,96,88,80,72,64,56,48,40,32,24,16,8,4,2,1],"cudagraph_copy_inputs":false,"full_cuda_graph":false,"max_capture_size":512,"local_cache_dir":null}
WARNING 05-30 18:21:54 [utils.py:2667] Methods determine_num_available_blocks,device_config,get_cache_block_size_bytes,initialize_cache not implemented in <vllm.v1.worker.gpu_worker.Worker object at 0x740f24ad1df0>
INFO 05-30 18:21:55 [parallel_state.py:1064] rank 0 in world size 1 is assigned as DP rank 0, PP rank 0, TP rank 0, EP rank 0
WARNING 05-30 18:21:55 [topk_topp_sampler.py:58] FlashInfer is not available. Falling back to the PyTorch-native implementation of top-p & top-k sampling. For the best performance, please install FlashInfer.
INFO 05-30 18:21:55 [gpu_model_runner.py:1543] Starting to load model RedHatAI/Meta-Llama-3.1-8B-FP8...
INFO 05-30 18:21:55 [cuda.py:209] Using Flash Attention backend on V1 engine.
INFO 05-30 18:21:55 [gpu_model_runner.py:1561] Model loading took 8.4890 GiB and 0.362240 seconds
INFO 05-30 18:22:01 [backends.py:461] Using cache directory: /home/mgoin/.cache/vllm/torch_compile_cache/a24d6bdd71/rank_0_0 for vLLM's torch.compile
INFO 05-30 18:22:01 [backends.py:471] Dynamo bytecode transform time: 5.45 s
INFO 05-30 18:22:04 [backends.py:134] Directly load the compiled graph(s) for shape None from the cache, took 3.087 s
INFO 05-30 18:22:05 [monitor.py:33] torch.compile takes 5.45 s in total
INFO 05-30 18:22:05 [kv_cache_utils.py:637] GPU KV cache size: 468,640 tokens
INFO 05-30 18:22:05 [kv_cache_utils.py:640] Maximum concurrency for 131,072 tokens per request: 3.58x
INFO 05-30 18:22:22 [gpu_model_runner.py:1948] Graph capturing finished in 17 secs, took 0.67 GiB
INFO 05-30 18:22:22 [core.py:169] init engine (profile, create kv cache, warmup model) took 26.76 seconds
Adding requests: 100%|███████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 1000/1000 [00:02<00:00, 380.05it/s]
Processed prompts: 100%|███████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 1000/1000 [00:22<00:00, 45.18it/s, est. speed input: 45103.32 toks/s, output: 4518.41 toks/s]
[rank0]:[W530 18:22:48.816661449 ProcessGroupNCCL.cpp:1476] Warning: WARNING: destroy_process_group() was not called before program exit, which can leak resources. For more info, please see https://pytorch.org/docs/stable/distributed.html#shutdown (function operator())
Throughput: 40.38 requests/s, 44341.04 total tokens/s, 4037.57 output tokens/s
Total num prompt tokens:  998212
Total num output tokens:  100000

vllm bench throughput --model RedHatAI/Meta-Llama-3.1-8B-FP8 --load-format dummy --input-len 1000 --output-len 100
INFO 05-30 18:24:19 [__init__.py:243] Automatically detected platform cuda.
INFO 05-30 18:24:21 [__init__.py:31] Available plugins for group vllm.general_plugins:
INFO 05-30 18:24:21 [__init__.py:33] - lora_filesystem_resolver -> vllm.plugins.lora_resolvers.filesystem_resolver:register_filesystem_resolver
INFO 05-30 18:24:21 [__init__.py:36] All plugins in this group will be loaded. Set `VLLM_PLUGINS` to control which plugins to load.
When dataset path is not set, it will default to random dataset
Namespace(subparser='bench', bench_type='throughput', dispatch_function=<function BenchmarkThroughputSubcommand.cmd at 0x771e6e849da0>, backend='vllm', dataset_name='random', dataset=None, dataset_path=None, input_len=1000, output_len=100, n=1, num_prompts=1000, hf_max_batch_size=None, output_json=None, async_engine=False, disable_frontend_multiprocessing=False, disable_detokenize=False, lora_path=None, prefix_len=0, random_range_ratio=0.0, hf_subset=None, hf_split=None, model='RedHatAI/Meta-Llama-3.1-8B-FP8', task='auto', tokenizer='RedHatAI/Meta-Llama-3.1-8B-FP8', tokenizer_mode='auto', trust_remote_code=False, dtype='auto', seed=0, hf_config_path=None, allowed_local_media_path='', revision=None, code_revision=None, rope_scaling={}, rope_theta=None, tokenizer_revision=None, max_model_len=None, quantization=None, enforce_eager=False, max_seq_len_to_capture=8192, max_logprobs=20, disable_sliding_window=False, disable_cascade_attn=False, skip_tokenizer_init=False, enable_prompt_embeds=False, served_model_name=None, disable_async_output_proc=False, config_format='auto', hf_token=None, hf_overrides={}, override_neuron_config={}, override_pooler_config=None, logits_processor_pattern=None, generation_config='auto', override_generation_config={}, enable_sleep_mode=False, model_impl='auto', load_format='dummy', download_dir=None, model_loader_extra_config={}, ignore_patterns=None, use_tqdm_on_load=True, qlora_adapter_name_or_path=None, pt_load_map_location='cpu', guided_decoding_backend='auto', guided_decoding_disable_fallback=False, guided_decoding_disable_any_whitespace=False, guided_decoding_disable_additional_properties=False, enable_reasoning=None, reasoning_parser='', distributed_executor_backend=None, pipeline_parallel_size=1, tensor_parallel_size=1, data_parallel_size=1, data_parallel_size_local=None, data_parallel_address=None, data_parallel_rpc_port=None, enable_expert_parallel=False, max_parallel_loading_workers=None, ray_workers_use_nsight=False, disable_custom_all_reduce=False, worker_cls='auto', worker_extension_cls='', block_size=None, gpu_memory_utilization=0.9, swap_space=4, kv_cache_dtype='auto', num_gpu_blocks_override=None, enable_prefix_caching=None, prefix_caching_hash_algo='builtin', cpu_offload_gb=0, calculate_kv_scales=False, tokenizer_pool_size=0, tokenizer_pool_type='ray', tokenizer_pool_extra_config={}, limit_mm_per_prompt={}, mm_processor_kwargs=None, disable_mm_preprocessor_cache=False, enable_lora=None, enable_lora_bias=False, max_loras=1, max_lora_rank=16, lora_extra_vocab_size=256, lora_dtype='auto', long_lora_scaling_factors=None, max_cpu_loras=None, fully_sharded_loras=False, enable_prompt_adapter=None, max_prompt_adapters=1, max_prompt_adapter_token=0, device='auto', speculative_config=None, show_hidden_metrics_for_version=None, otlp_traces_endpoint=None, collect_detailed_traces=None, max_num_batched_tokens=None, max_num_seqs=None, max_num_partial_prefills=1, max_long_partial_prefills=1, cuda_graph_sizes=[512], long_prefill_token_threshold=0, num_lookahead_slots=0, scheduler_delay_factor=0.0, preemption_mode=None, num_scheduler_steps=1, multi_step_stream_outputs=True, scheduling_policy='fcfs', enable_chunked_prefill=None, disable_chunked_mm_input=False, scheduler_cls='vllm.core.scheduler.Scheduler', kv_transfer_config=None, kv_events_config=None, compilation_config={"level":0,"debug_dump_path":"","cache_dir":"","backend":"","custom_ops":[],"splitting_ops":[],"use_inductor":true,"compile_sizes":null,"inductor_compile_config":{"enable_auto_functionalized_v2":false},"inductor_passes":{},"use_cudagraph":false,"cudagraph_num_of_warmups":0,"cudagraph_capture_sizes":null,"cudagraph_copy_inputs":false,"full_cuda_graph":false,"max_capture_size":null,"local_cache_dir":null}, additional_config={}, use_v2_block_manager=True, disable_log_stats=False, disable_log_requests=False)
INFO 05-30 18:24:23 [datasets.py:333] Sampling input_len from [999, 999]
INFO 05-30 18:24:23 [datasets.py:334] Sampling output_len from [100, 100]
INFO 05-30 18:24:33 [config.py:813] This model supports multiple tasks: {'reward', 'generate', 'score', 'embed', 'classify'}. Defaulting to 'generate'.
INFO 05-30 18:24:34 [config.py:2143] Chunked prefill is enabled with max_num_batched_tokens=16384.
INFO 05-30 18:24:38 [__init__.py:243] Automatically detected platform cuda.
INFO 05-30 18:24:40 [core.py:448] Waiting for init message from front-end.
INFO 05-30 18:24:40 [__init__.py:31] Available plugins for group vllm.general_plugins:
INFO 05-30 18:24:40 [__init__.py:33] - lora_filesystem_resolver -> vllm.plugins.lora_resolvers.filesystem_resolver:register_filesystem_resolver
INFO 05-30 18:24:40 [__init__.py:36] All plugins in this group will be loaded. Set `VLLM_PLUGINS` to control which plugins to load.
INFO 05-30 18:24:40 [core.py:68] Initializing a V1 LLM engine (v0.9.1.dev287+g89b1388d8) with config: model='RedHatAI/Meta-Llama-3.1-8B-FP8', speculative_config=None, tokenizer='RedHatAI/Meta-Llama-3.1-8B-FP8', skip_tokenizer_init=False, tokenizer_mode=auto, revision=None, override_neuron_config={}, tokenizer_revision=None, trust_remote_code=False, dtype=torch.float16, max_seq_len=131072, download_dir=None, load_format=LoadFormat.DUMMY, tensor_parallel_size=1, pipeline_parallel_size=1, disable_custom_all_reduce=False, quantization=compressed-tensors, enforce_eager=False, kv_cache_dtype=auto,  device_config=cuda, decoding_config=DecodingConfig(backend='auto', disable_fallback=False, disable_any_whitespace=False, disable_additional_properties=False, reasoning_backend=''), observability_config=ObservabilityConfig(show_hidden_metrics_for_version=None, otlp_traces_endpoint=None, collect_detailed_traces=None), seed=0, served_model_name=RedHatAI/Meta-Llama-3.1-8B-FP8, num_scheduler_steps=1, multi_step_stream_outputs=True, enable_prefix_caching=True, chunked_prefill_enabled=True, use_async_output_proc=True, pooler_config=None, compilation_config={"level":3,"debug_dump_path":"","cache_dir":"","backend":"","custom_ops":["none"],"splitting_ops":["vllm.unified_attention","vllm.unified_attention_with_output"],"use_inductor":true,"compile_sizes":[],"inductor_compile_config":{"enable_auto_functionalized_v2":false},"inductor_passes":{},"use_cudagraph":true,"cudagraph_num_of_warmups":1,"cudagraph_capture_sizes":[512,504,496,488,480,472,464,456,448,440,432,424,416,408,400,392,384,376,368,360,352,344,336,328,320,312,304,296,288,280,272,264,256,248,240,232,224,216,208,200,192,184,176,168,160,152,144,136,128,120,112,104,96,88,80,72,64,56,48,40,32,24,16,8,4,2,1],"cudagraph_copy_inputs":false,"full_cuda_graph":false,"max_capture_size":512,"local_cache_dir":null}
WARNING 05-30 18:24:40 [utils.py:2667] Methods determine_num_available_blocks,device_config,get_cache_block_size_bytes,initialize_cache not implemented in <vllm.v1.worker.gpu_worker.Worker object at 0x734155fd4e00>
INFO 05-30 18:24:41 [parallel_state.py:1064] rank 0 in world size 1 is assigned as DP rank 0, PP rank 0, TP rank 0, EP rank 0
WARNING 05-30 18:24:41 [topk_topp_sampler.py:58] FlashInfer is not available. Falling back to the PyTorch-native implementation of top-p & top-k sampling. For the best performance, please install FlashInfer.
INFO 05-30 18:24:41 [gpu_model_runner.py:1543] Starting to load model RedHatAI/Meta-Llama-3.1-8B-FP8...
INFO 05-30 18:24:41 [cuda.py:209] Using Flash Attention backend on V1 engine.
INFO 05-30 18:24:41 [backends.py:37] Using InductorAdaptor
INFO 05-30 18:24:41 [gpu_model_runner.py:1561] Model loading took 8.4890 GiB and 0.303456 seconds
INFO 05-30 18:24:47 [backends.py:461] Using cache directory: /home/mgoin/.cache/vllm/torch_compile_cache/a24d6bdd71/rank_0_0 for vLLM's torch.compile
INFO 05-30 18:24:47 [backends.py:471] Dynamo bytecode transform time: 5.28 s
INFO 05-30 18:24:51 [backends.py:134] Directly load the compiled graph(s) for shape None from the cache, took 3.721 s
INFO 05-30 18:24:51 [monitor.py:33] torch.compile takes 5.28 s in total
INFO 05-30 18:24:52 [kv_cache_utils.py:637] GPU KV cache size: 468,640 tokens
INFO 05-30 18:24:52 [kv_cache_utils.py:640] Maximum concurrency for 131,072 tokens per request: 3.58x
INFO 05-30 18:25:08 [gpu_model_runner.py:1948] Graph capturing finished in 16 secs, took 0.67 GiB
INFO 05-30 18:25:08 [core.py:169] init engine (profile, create kv cache, warmup model) took 26.90 seconds
Adding requests: 100%|███████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 1000/1000 [00:02<00:00, 387.63it/s]
Processed prompts: 100%|███████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████████| 1000/1000 [00:22<00:00, 45.31it/s, est. speed input: 45276.92 toks/s, output: 4531.04 toks/s]
[rank0]:[W530 18:25:34.071039772 ProcessGroupNCCL.cpp:1476] Warning: WARNING: destroy_process_group() was not called before program exit, which can leak resources. For more info, please see https://pytorch.org/docs/stable/distributed.html#shutdown (function operator())
Throughput: 40.56 requests/s, 44587.50 total tokens/s, 4056.14 output tokens/s
Total num prompt tokens:  999260
Total num output tokens:  100000