"""Logging configuration for vLLM.""" import datetime import json import logging import os import sys from functools import partial from logging import Logger from logging.config import dictConfig from os import path from typing import Dict, Optional import vllm.envs as envs VLLM_CONFIGURE_LOGGING = envs.VLLM_CONFIGURE_LOGGING VLLM_LOGGING_CONFIG_PATH = envs.VLLM_LOGGING_CONFIG_PATH VLLM_LOGGING_LEVEL = envs.VLLM_LOGGING_LEVEL VLLM_LOGGING_PREFIX = envs.VLLM_LOGGING_PREFIX _FORMAT = (f"{VLLM_LOGGING_PREFIX}%(levelname)s %(asctime)s " "%(filename)s:%(lineno)d] %(message)s") _DATE_FORMAT = "%m-%d %H:%M:%S" DEFAULT_LOGGING_CONFIG = { "formatters": { "vllm": { "class": "vllm.logging_utils.NewLineFormatter", "datefmt": _DATE_FORMAT, "format": _FORMAT, }, }, "handlers": { "vllm": { "class": "logging.StreamHandler", "formatter": "vllm", "level": VLLM_LOGGING_LEVEL, "stream": "ext://sys.stdout", }, }, "loggers": { "vllm": { "handlers": ["vllm"], "level": "DEBUG", "propagate": False, }, }, "version": 1, "disable_existing_loggers": False } def _configure_vllm_root_logger() -> None: logging_config: Optional[Dict] = None if not VLLM_CONFIGURE_LOGGING and VLLM_LOGGING_CONFIG_PATH: raise RuntimeError( "VLLM_CONFIGURE_LOGGING evaluated to false, but " "VLLM_LOGGING_CONFIG_PATH was given. VLLM_LOGGING_CONFIG_PATH " "implies VLLM_CONFIGURE_LOGGING. Please enable " "VLLM_CONFIGURE_LOGGING or unset VLLM_LOGGING_CONFIG_PATH.") if VLLM_CONFIGURE_LOGGING: logging_config = DEFAULT_LOGGING_CONFIG if VLLM_LOGGING_CONFIG_PATH: if not path.exists(VLLM_LOGGING_CONFIG_PATH): raise RuntimeError( "Could not load logging config. File does not exist: %s", VLLM_LOGGING_CONFIG_PATH) with open(VLLM_LOGGING_CONFIG_PATH, encoding="utf-8") as file: custom_config = json.loads(file.read()) if not isinstance(custom_config, dict): raise ValueError("Invalid logging config. Expected Dict, got %s.", type(custom_config).__name__) logging_config = custom_config if logging_config: dictConfig(logging_config) def init_logger(name: str) -> Logger: """The main purpose of this function is to ensure that loggers are retrieved in such a way that we can be sure the root vllm logger has already been configured.""" return logging.getLogger(name) # The root logger is initialized when the module is imported. # This is thread-safe as the module is only imported once, # guaranteed by the Python GIL. _configure_vllm_root_logger() logger = init_logger(__name__) def _trace_calls(log_path, root_dir, frame, event, arg=None): if event in ['call', 'return']: # Extract the filename, line number, function name, and the code object filename = frame.f_code.co_filename lineno = frame.f_lineno func_name = frame.f_code.co_name if not filename.startswith(root_dir): # only log the functions in the vllm root_dir return # Log every function call or return try: last_frame = frame.f_back if last_frame is not None: last_filename = last_frame.f_code.co_filename last_lineno = last_frame.f_lineno last_func_name = last_frame.f_code.co_name else: # initial frame last_filename = "" last_lineno = 0 last_func_name = "" with open(log_path, 'a') as f: if event == 'call': f.write(f"{datetime.datetime.now()} Call to" f" {func_name} in {filename}:{lineno}" f" from {last_func_name} in {last_filename}:" f"{last_lineno}\n") else: f.write(f"{datetime.datetime.now()} Return from" f" {func_name} in {filename}:{lineno}" f" to {last_func_name} in {last_filename}:" f"{last_lineno}\n") except NameError: # modules are deleted during shutdown pass return partial(_trace_calls, log_path, root_dir) def enable_trace_function_call(log_file_path: str, root_dir: Optional[str] = None): """ Enable tracing of every function call in code under `root_dir`. This is useful for debugging hangs or crashes. `log_file_path` is the path to the log file. `root_dir` is the root directory of the code to trace. If None, it is the vllm root directory. Note that this call is thread-level, any threads calling this function will have the trace enabled. Other threads will not be affected. """ logger.warning( "VLLM_TRACE_FUNCTION is enabled. It will record every" " function executed by Python. This will slow down the code. It " "is suggested to be used for debugging hang or crashes only.") logger.info("Trace frame log is saved to %s", log_file_path) if root_dir is None: # by default, this is the vllm root directory root_dir = os.path.dirname(os.path.dirname(__file__)) sys.settrace(partial(_trace_calls, log_file_path, root_dir))