optimize startup log

Signed-off-by: yewentao256 <zhyanwentao@126.com>
This commit is contained in:
yewentao256 2025-10-13 15:23:46 -07:00
parent 314285d4f2
commit 3967657957
14 changed files with 33 additions and 24 deletions

View File

@ -240,9 +240,9 @@ class CompilerManager:
if graph_index == 0: if graph_index == 0:
# adds some info logging for the first graph # adds some info logging for the first graph
if runtime_shape is None: if runtime_shape is None:
logger.info("Cache the graph for dynamic shape for later use") logger.debug("Cache the graph for dynamic shape for later use")
else: else:
logger.info( logger.debug(
"Cache the graph of shape %s for later use", str(runtime_shape) "Cache the graph of shape %s for later use", str(runtime_shape)
) )
if runtime_shape is None: if runtime_shape is None:
@ -601,7 +601,7 @@ class VllmBackend:
if disable_cache: if disable_cache:
logger.info("vLLM's torch.compile cache is disabled.") logger.info("vLLM's torch.compile cache is disabled.")
else: else:
logger.info( logger.debug(
"Using cache directory: %s for vLLM's torch.compile", local_cache_dir "Using cache directory: %s for vLLM's torch.compile", local_cache_dir
) )
@ -615,7 +615,7 @@ class VllmBackend:
from .monitor import torch_compile_start_time from .monitor import torch_compile_start_time
dynamo_time = time.time() - torch_compile_start_time dynamo_time = time.time() - torch_compile_start_time
logger.info("Dynamo bytecode transform time: %.2f s", dynamo_time) logger.debug("Dynamo bytecode transform time: %.2f s", dynamo_time)
self.compilation_config.compilation_time += dynamo_time self.compilation_config.compilation_time += dynamo_time
# we control the compilation process, each instance can only be # we control the compilation process, each instance can only be

View File

@ -34,7 +34,7 @@ def _can_p2p(rank: int, world_size: int) -> bool:
if i == rank: if i == rank:
continue continue
if envs.VLLM_SKIP_P2P_CHECK: if envs.VLLM_SKIP_P2P_CHECK:
logger.info("Skipping P2P check and trusting the driver's P2P report.") logger.debug("Skipping P2P check and trusting the driver's P2P report.")
return torch.cuda.can_device_access_peer(rank, i) return torch.cuda.can_device_access_peer(rank, i)
if not gpu_p2p_access_check(rank, i): if not gpu_p2p_access_check(rank, i):
return False return False

View File

@ -299,7 +299,7 @@ class MessageQueue:
remote_addr_ipv6=remote_addr_ipv6, remote_addr_ipv6=remote_addr_ipv6,
) )
logger.info("vLLM message queue communication handle: %s", self.handle) logger.debug("vLLM message queue communication handle: %s", self.handle)
def export_handle(self) -> Handle: def export_handle(self) -> Handle:
return self.handle return self.handle

View File

@ -1157,7 +1157,7 @@ def init_distributed_environment(
ip = parallel_config.data_parallel_master_ip ip = parallel_config.data_parallel_master_ip
port = parallel_config.get_next_dp_init_port() port = parallel_config.get_next_dp_init_port()
distributed_init_method = get_distributed_init_method(ip, port) distributed_init_method = get_distributed_init_method(ip, port)
logger.info( logger.debug(
"Adjusting world_size=%d rank=%d distributed_init_method=%s for DP", "Adjusting world_size=%d rank=%d distributed_init_method=%s for DP",
world_size, world_size,
rank, rank,
@ -1322,7 +1322,7 @@ def initialize_model_parallel(
group_ranks, get_world_group().local_rank, backend, group_name="ep" group_ranks, get_world_group().local_rank, backend, group_name="ep"
) )
logger.info( logger.debug(
"rank %s in world size %s is assigned as " "rank %s in world size %s is assigned as "
"DP rank %s, PP rank %s, TP rank %s, EP rank %s", "DP rank %s, PP rank %s, TP rank %s, EP rank %s",
rank, rank,

View File

@ -1137,7 +1137,7 @@ class FusedMoE(CustomOp):
) )
self.local_num_experts = local_num_experts self.local_num_experts = local_num_experts
self.register_buffer("expert_map", expert_map) self.register_buffer("expert_map", expert_map)
logger.info_once( logger.debug_once(
"[EP Rank %s/%s] Expert parallelism is enabled. Expert " "[EP Rank %s/%s] Expert parallelism is enabled. Expert "
"placement strategy: %s. Local/global" "placement strategy: %s. Local/global"
" number of experts: %s/%s. Experts local to global index map:" " number of experts: %s/%s. Experts local to global index map:"

View File

@ -13,6 +13,7 @@ from transformers.utils import SAFE_WEIGHTS_INDEX_NAME
from vllm.config import ModelConfig from vllm.config import ModelConfig
from vllm.config.load import LoadConfig from vllm.config.load import LoadConfig
from vllm.distributed.parallel_state import is_global_first_rank
from vllm.logger import init_logger from vllm.logger import init_logger
from vllm.model_executor.layers.quantization.torchao import torchao_version_at_least from vllm.model_executor.layers.quantization.torchao import torchao_version_at_least
from vllm.model_executor.model_loader.base_loader import BaseModelLoader from vllm.model_executor.model_loader.base_loader import BaseModelLoader
@ -311,10 +312,12 @@ class DefaultModelLoader(BaseModelLoader):
loaded_weights = load_weights_and_online_quantize(self, model, model_config) loaded_weights = load_weights_and_online_quantize(self, model, model_config)
self.counter_after_loading_weights = time.perf_counter() self.counter_after_loading_weights = time.perf_counter()
logger.info( if is_global_first_rank():
"Loading weights took %.2f seconds", logger.info(
self.counter_after_loading_weights - self.counter_before_loading_weights, "Loading weights took %.2f seconds",
) self.counter_after_loading_weights
- self.counter_before_loading_weights,
)
# We only enable strict check for non-quantized models # We only enable strict check for non-quantized models
# that have loaded weights tracking currently. # that have loaded weights tracking currently.
if model_config.quantization is None and loaded_weights is not None: if model_config.quantization is None and loaded_weights is not None:

View File

@ -416,7 +416,7 @@ def download_weights_from_hf(
e, e,
) )
logger.info("Using model weights format %s", allow_patterns) logger.debug("Using model weights format %s", allow_patterns)
# Use file lock to prevent multiple processes from # Use file lock to prevent multiple processes from
# downloading the same model weights at the same time. # downloading the same model weights at the same time.
with get_lock(model_name_or_path, cache_dir): with get_lock(model_name_or_path, cache_dir):

View File

@ -221,10 +221,12 @@ def resolve_current_platform_cls_qualname() -> str:
) )
elif len(activated_builtin_plugins) == 1: elif len(activated_builtin_plugins) == 1:
platform_cls_qualname = builtin_platform_plugins[activated_builtin_plugins[0]]() platform_cls_qualname = builtin_platform_plugins[activated_builtin_plugins[0]]()
logger.info("Automatically detected platform %s.", activated_builtin_plugins[0]) logger.debug(
"Automatically detected platform %s.", activated_builtin_plugins[0]
)
else: else:
platform_cls_qualname = "vllm.platforms.interface.UnspecifiedPlatform" platform_cls_qualname = "vllm.platforms.interface.UnspecifiedPlatform"
logger.info("No platform detected, vLLM is running on UnspecifiedPlatform") logger.debug("No platform detected, vLLM is running on UnspecifiedPlatform")
return platform_cls_qualname return platform_cls_qualname

View File

@ -37,7 +37,7 @@ class GCDebugConfig:
except Exception: except Exception:
self.enabled = False self.enabled = False
logger.error("Failed to parse VLLM_GC_DEBUG(%s)", VLLM_GC_DEBUG) logger.error("Failed to parse VLLM_GC_DEBUG(%s)", VLLM_GC_DEBUG)
logger.info("GC Debug Config. %s", str(self)) logger.debug("GC Debug Config. %s", str(self))
def __repr__(self) -> str: def __repr__(self) -> str:
return f"enabled:{self.enabled},top_objects:{self.top_objects}" return f"enabled:{self.enabled},top_objects:{self.top_objects}"

View File

@ -19,7 +19,6 @@ import zmq
from vllm.config import ParallelConfig, VllmConfig from vllm.config import ParallelConfig, VllmConfig
from vllm.distributed import stateless_destroy_torch_distributed_process_group from vllm.distributed import stateless_destroy_torch_distributed_process_group
from vllm.distributed.parallel_state import is_global_first_rank
from vllm.logger import init_logger from vllm.logger import init_logger
from vllm.logging_utils.dump_input import dump_engine_exception from vllm.logging_utils.dump_input import dump_engine_exception
from vllm.lora.request import LoRARequest from vllm.lora.request import LoRARequest
@ -92,7 +91,7 @@ class EngineCore:
load_general_plugins() load_general_plugins()
self.vllm_config = vllm_config self.vllm_config = vllm_config
if is_global_first_rank(): if vllm_config.parallel_config.data_parallel_rank == 0:
logger.info( logger.info(
"Initializing a V1 LLM engine (v%s) with config: %s", "Initializing a V1 LLM engine (v%s) with config: %s",
VLLM_VERSION, VLLM_VERSION,
@ -726,7 +725,6 @@ class EngineCoreProc(EngineCore):
) )
# Receive initialization message. # Receive initialization message.
logger.info("Waiting for init message from front-end.")
if not handshake_socket.poll(timeout=HANDSHAKE_TIMEOUT_MINS * 60_000): if not handshake_socket.poll(timeout=HANDSHAKE_TIMEOUT_MINS * 60_000):
raise RuntimeError( raise RuntimeError(
"Did not receive response from front-end " "Did not receive response from front-end "

View File

@ -170,7 +170,7 @@ class LoggingStatLogger(StatLoggerBase):
def log_engine_initialized(self): def log_engine_initialized(self):
if self.vllm_config.cache_config.num_gpu_blocks: if self.vllm_config.cache_config.num_gpu_blocks:
logger.info( logger.debug(
"Engine %03d: vllm cache_config_info with initialization " "Engine %03d: vllm cache_config_info with initialization "
"after num_gpu_blocks is: %d", "after num_gpu_blocks is: %d",
self.engine_index, self.engine_index,

View File

@ -8,6 +8,7 @@ from packaging import version
from vllm import envs from vllm import envs
from vllm.config.model import LogprobsMode from vllm.config.model import LogprobsMode
from vllm.distributed.parallel_state import is_global_first_rank
from vllm.logger import init_logger from vllm.logger import init_logger
from vllm.platforms import CpuArchEnum, current_platform from vllm.platforms import CpuArchEnum, current_platform
@ -55,7 +56,8 @@ class TopKTopPSampler(nn.Module):
# None means False, while in V1, None means True. This is # None means False, while in V1, None means True. This is
# why we use the condition # why we use the condition
# `envs.VLLM_USE_FLASHINFER_SAMPLER is not False` here. # `envs.VLLM_USE_FLASHINFER_SAMPLER is not False` here.
logger.info_once("Using FlashInfer for top-p & top-k sampling.") if is_global_first_rank():
logger.info_once("Using FlashInfer for top-p & top-k sampling.")
self.forward = self.forward_cuda self.forward = self.forward_cuda
else: else:
logger.warning_once( logger.warning_once(

View File

@ -2846,7 +2846,8 @@ class GPUModelRunner(LoRAModelRunnerMixin, KVConnectorModelRunnerMixin):
Args: Args:
eep_scale_up: the model loading is for elastic EP scale up. eep_scale_up: the model loading is for elastic EP scale up.
""" """
logger.info("Starting to load model %s...", self.model_config.model) if is_global_first_rank():
logger.info_once("Starting to load model %s...", self.model_config.model)
if eep_scale_up: if eep_scale_up:
from vllm.distributed.parallel_state import get_ep_group from vllm.distributed.parallel_state import get_ep_group

View File

@ -20,7 +20,10 @@ from vllm.distributed import (
set_custom_all_reduce, set_custom_all_reduce,
) )
from vllm.distributed.kv_transfer import ensure_kv_transfer_initialized from vllm.distributed.kv_transfer import ensure_kv_transfer_initialized
from vllm.distributed.parallel_state import get_pp_group, get_tp_group from vllm.distributed.parallel_state import (
get_pp_group,
get_tp_group,
)
from vllm.logger import init_logger from vllm.logger import init_logger
from vllm.lora.request import LoRARequest from vllm.lora.request import LoRARequest
from vllm.model_executor import set_random_seed from vllm.model_executor import set_random_seed