add some logs

Author: PatKamin

devops/scripts/benchmarks/main.py

@@ -26,7 +26,7 @@
 from utils.compute_runtime import *
 from utils.validate import Validate
 from utils.detect_versions import DetectVersion
-from utils.logger import log, LogLevel
+from utils.logger import log
 from presets import enabled_suites, presets
 
 
@@ -160,6 +160,9 @@ def collect_metadata(suites):
 def main(directory, additional_env_vars, save_name, compare_names, filter):
     prepare_workdir(directory, INTERNAL_WORKDIR_VERSION)
 
+    if options.dry_run:
+        log.info("Dry run mode enabled. No benchmarks will be executed.")
+
     if options.build_compute_runtime:
         log.info(f"Setting up Compute Runtime {options.compute_runtime_tag}")
         cr = get_compute_runtime()
@@ -231,6 +234,10 @@ def main(directory, additional_env_vars, save_name, compare_names, filter):
                 log.error(f"failed: {e}")
 
     results = []
+    if benchmarks:
+        log.info(f"Running {len(benchmarks)} benchmarks...")
+    elif not options.dry_run:
+        log.warning("No benchmarks to run.")
     for benchmark in benchmarks:
         try:
             merged_env_vars = {**additional_env_vars}
@@ -275,19 +282,22 @@ def main(directory, additional_env_vars, save_name, compare_names, filter):
     history = BenchmarkHistory(results_dir)
     # limit how many files we load.
     # should this be configurable?
+    log.info(f"Loading benchmark history from {results_dir}...")
     history.load(1000)
-
-    # remove duplicates. this can happen if e.g., --compare baseline is specified manually.
-    compare_names = (
-        list(dict.fromkeys(compare_names)) if compare_names is not None else []
-    )
-
-    for name in compare_names:
-        compare_result = history.get_compare(name)
-        if compare_result:
-            chart_data[name] = compare_result.results
+    log.info(f"Loaded {len(history.runs)} benchmark runs.")
+
+    if compare_names:
+        log.info(f"Comparing against {len(compare_names)} previous runs...")
+        # remove duplicates. this can happen if e.g., --compare baseline is specified manually.
+        compare_names = list(dict.fromkeys(compare_names))
+        for name in compare_names:
+            compare_result = history.get_compare(name)
+            if compare_result:
+                chart_data[name] = compare_result.results
+        log.info(f"Comparison complete.")
 
     if options.output_markdown:
+        log.info("Generating markdown with benchmark results...")
         markdown_content = generate_markdown(
             this_name, chart_data, failures, options.output_markdown, metadata
         )
@@ -309,16 +319,21 @@ def main(directory, additional_env_vars, save_name, compare_names, filter):
     # we calculate historical averages or get latest results for compare.
     # Otherwise we might be comparing the results to themselves.
     if not options.dry_run:
+        log.info(f"Saving benchmark results...")
         history.save(saved_name, results, save_name is not None)
         if saved_name not in compare_names:
             compare_names.append(saved_name)
+        log.info(f"Benchmark results saved.")
 
     if options.output_html:
         html_path = options.output_directory
         if options.output_directory is None:
-            html_path = os.path.join(os.path.dirname(__file__), "html")
-
+            html_path = os.path.normpath(
+                os.path.join(os.path.dirname(__file__), "html")
+            )
+        log.info(f"Generating HTML with benchmark results in {html_path}...")
         generate_html(history.runs, compare_names, html_path, metadata)
+        log.info(f"HTML with benchmark results has been generated")
 
 
 def validate_and_parse_env_args(env_args):
@@ -376,6 +391,7 @@ def validate_and_parse_env_args(env_args):
         type=str,
         help="Compare results against previously saved data.",
         action="append",
+        default=[],
     )
     parser.add_argument(
         "--iterations",
@@ -574,7 +590,6 @@ def validate_and_parse_env_args(env_args):
     additional_env_vars = validate_and_parse_env_args(args.env)
 
     options.workdir = args.benchmark_directory
-    options.verbose = args.verbose
     options.rebuild = not args.no_rebuild
     options.redownload = args.redownload
     options.sycl = args.sycl
@@ -599,15 +614,8 @@ def validate_and_parse_env_args(env_args):
     options.build_jobs = args.build_jobs
     options.hip_arch = args.hip_arch
 
-    # Set the log level
-    log_level = (
-        LogLevel.DEBUG.value
-        if args.verbose
-        else LogLevel.from_string(args.log_level).value
-    )
-    log.logger.setLevel(log_level)
-    for handler in log.logger.handlers:
-        handler.setLevel(log_level)
+    # Initialize logger with command line arguments
+    log.initialize(args.verbose, args.log_level)
 
     if args.build_igc and args.compute_runtime is None:
         parser.error("--build-igc requires --compute-runtime to be set")

devops/scripts/benchmarks/options.py

@@ -2,8 +2,6 @@
 from enum import Enum
 import multiprocessing
 
-from presets import presets
-
 
 class Compare(Enum):
     LATEST = "latest"
@@ -41,6 +39,7 @@ class DetectVersionsOptions:
     # Max amount of api calls permitted on each run of the benchmark scripts
     max_api_calls = 4
 
+
 @dataclass
 class Options:
     workdir: str = None
@@ -53,7 +52,6 @@ class Options:
     benchmark_cwd: str = "INVALID"
     timeout: float = 600
     iterations: int = 3
-    verbose: bool = False
     compare: Compare = Compare.LATEST
     compare_max: int = 10  # average/median over how many results
     output_markdown: MarkdownSize = MarkdownSize.SHORT

devops/scripts/benchmarks/output_html.py

@@ -49,7 +49,7 @@ def generate_html(
             json.dump(output.default_compare_names, f, indent=2)
             f.write(";\n")
 
-        log.info(f"See {os.getcwd()}/html/index.html for the results.")
+        log.info(f"See {html_path}/index.html for the results.")
     else:
         # For remote format, we write a single JSON file
         data_path = os.path.join(html_path, "data.json")

devops/scripts/benchmarks/utils/compute_runtime.py

@@ -7,7 +7,6 @@
 import re
 import yaml
 
-from pathlib import Path
 from .utils import *
 from options import options
 
@@ -51,6 +50,7 @@ def env_vars(self) -> dict:
         }
 
     def build_gmmlib(self, repo, commit):
+        log.info("Building GMMLib...")
         self.gmmlib_repo = git_clone(options.workdir, "gmmlib-repo", repo, commit)
         self.gmmlib_build = os.path.join(options.workdir, "gmmlib-build")
         self.gmmlib_install = os.path.join(options.workdir, "gmmlib-install")
@@ -64,9 +64,11 @@ def build_gmmlib(self, repo, commit):
         run(configure_command)
         run(f"cmake --build {self.gmmlib_build} -j {options.build_jobs}")
         run(f"cmake --install {self.gmmlib_build}")
+        log.info("GMMLib build complete.")
         return self.gmmlib_install
 
     def build_level_zero(self, repo, commit):
+        log.info("Building Level Zero...")
         self.level_zero_repo = git_clone(
             options.workdir, "level-zero-repo", repo, commit
         )
@@ -89,9 +91,11 @@ def build_level_zero(self, repo, commit):
         run(configure_command)
         run(f"cmake --build {self.level_zero_build} -j {options.build_jobs}")
         run(f"cmake --install {self.level_zero_build}")
+        log.info("Level Zero build complete.")
         return self.level_zero_install
 
     def build_igc(self, repo, commit):
+        log.info("Building IGC...")
         self.igc_repo = git_clone(options.workdir, "igc", repo, commit)
         self.vc_intr = git_clone(
             options.workdir,
@@ -151,6 +155,7 @@ def build_igc(self, repo, commit):
         )
         # cmake --install doesn't work...
         run("make install", cwd=self.igc_build)
+        log.info("IGC build complete.")
         return self.igc_install
 
     def read_manifest(self, manifest_path):
@@ -204,6 +209,7 @@ def build_compute_runtime(self):
         # Remove -Werror...
         replace_in_file(cmakelists_path, r"\s-Werror(?:=[a-zA-Z]*)?", "")
 
+        log.info("Building Compute Runtime...")
         configure_command = [
             "cmake",
             f"-B {self.compute_runtime_build}",
@@ -220,6 +226,7 @@ def build_compute_runtime(self):
 
         run(configure_command)
         run(f"cmake --build {self.compute_runtime_build} -j {options.build_jobs}")
+        log.info("Compute Runtime build complete.")
         return self.compute_runtime_build
 
 

devops/scripts/benchmarks/utils/logger.py

@@ -5,80 +5,90 @@
 
 import logging
 import sys
-from enum import Enum
+from typing import Optional, Type, Any
 
 
-class LogLevel(Enum):
-    DEBUG = logging.DEBUG
-    INFO = logging.INFO
-    WARNING = logging.WARNING
-    ERROR = logging.ERROR
-    CRITICAL = logging.CRITICAL
-
-    @staticmethod
-    def from_string(level_str):
-        level_map = {
-            "debug": LogLevel.DEBUG,
-            "info": LogLevel.INFO,
-            "warning": LogLevel.WARNING,
-            "error": LogLevel.ERROR,
-            "critical": LogLevel.CRITICAL,
-        }
-        return level_map.get(level_str.lower(), LogLevel.INFO)
+# Define log level mapping as a module-level function
+def _get_log_level(level_str: str) -> int:
+    """Convert a string log level to a logging module level constant."""
+    level_map = {
+        "debug": logging.DEBUG,
+        "info": logging.INFO,
+        "warning": logging.WARNING,
+        "error": logging.ERROR,
+        "critical": logging.CRITICAL,
+    }
+    return level_map.get(level_str.lower(), logging.INFO)
 
 
 class BenchmarkLogger:
-    """Logger for the Unified Runtime Benchmark Runner.
+    """Logger for the Benchmark Runner.
 
     This logger provides different log levels (DEBUG, INFO, WARNING, ERROR, CRITICAL)
-    that can be controlled via command-line arguments.
+    that can be controlled via command-line arguments. Call initialize() with the
+    appropriate parameters after parsing command line arguments.
     """
 
-    _instance = None
+    _instance: Optional["BenchmarkLogger"] = None
 
-    def __new__(cls):
+    def __new__(cls: Type["BenchmarkLogger"]) -> "BenchmarkLogger":
         if cls._instance is None:
             cls._instance = super(BenchmarkLogger, cls).__new__(cls)
-            cls._instance._initialize_logger()
         return cls._instance
 
-    def _initialize_logger(self):
-        """Initialize the logger with the appropriate log level."""
-        self.logger = logging.getLogger("ur_benchmarks")
+    def __init__(self) -> None:
+        """Create logger but don't configure it until initialize() is called."""
+        self._logger: logging.Logger = logging.getLogger("ur_benchmarks")
+
+    def initialize(self, verbose: bool = False, log_level: str = "info") -> None:
+        """Configure the logger with the appropriate log level.
+
+        Args:
+            verbose: If True, sets the log level to DEBUG regardless of log_level
+            log_level: One of "debug", "info", "warning", "error", "critical"
+
+        Note:
+            This method will only initialize the logger once. Subsequent calls will be ignored.
+        """
+        # Return early if logger is already initialized (has handlers)
+        if self._logger.handlers:
+            return
 
-        # Create console handler
         console_handler = logging.StreamHandler(sys.stdout)
 
-        # Set default log level (INFO)
-        self.logger.setLevel(logging.INFO)
-        console_handler.setLevel(logging.INFO)
+        level = logging.DEBUG if verbose else _get_log_level(log_level)
+        self._logger.setLevel(level)
+        console_handler.setLevel(level)
 
-        # Create formatter
         formatter = logging.Formatter("%(asctime)s - %(levelname)s - %(message)s")
         console_handler.setFormatter(formatter)
 
-        # Add the handler to the logger
-        self.logger.addHandler(console_handler)
+        self._logger.addHandler(console_handler)
 
-    def debug(self, message):
+    def debug(self, message: Any) -> None:
         """Log a debug message."""
-        self.logger.debug(message)
+        if self._logger.handlers:
+            self._logger.debug(message)
 
-    def info(self, message):
+    def info(self, message: Any) -> None:
         """Log an info message."""
-        self.logger.info(message)
+        if self._logger.handlers:
+            self._logger.info(message)
 
-    def warning(self, message):
+    def warning(self, message: Any) -> None:
         """Log a warning message."""
-        self.logger.warning(message)
+        if self._logger.handlers:
+            self._logger.warning(message)
 
-    def error(self, message):
+    def error(self, message: Any) -> None:
         """Log an error message."""
-        self.logger.error(message)
+        if self._logger.handlers:
+            self._logger.error(message)
 
-    def critical(self, message):
+    def critical(self, message: Any) -> None:
         """Log a critical message."""
-        self.logger.critical(message)
+        if self._logger.handlers:
+            self._logger.critical(message)
 
 
 # Global logger instance

devops/scripts/benchmarks/utils/utils.py

@@ -79,6 +79,7 @@ def run(
 
 def git_clone(dir, name, repo, commit):
     repo_path = os.path.join(dir, name)
+    log.debug(f"Cloning {repo} into {repo_path} at commit {commit}")
 
     if os.path.isdir(repo_path) and os.path.isdir(os.path.join(repo_path, ".git")):
         run("git fetch", cwd=repo_path)
@@ -91,6 +92,7 @@ def git_clone(dir, name, repo, commit):
         raise Exception(
             f"The directory {repo_path} exists but is not a git repository."
         )
+    log.debug(f"Cloned {repo} into {repo_path} at commit {commit}")
     return repo_path
 
 
@@ -118,7 +120,8 @@ def prepare_workdir(dir, version):
                 shutil.rmtree(dir)
         else:
             raise Exception(
-                f"The directory {dir} exists but is not a benchmark work directory."
+                f"The directory {dir} exists but is not a benchmark work directory. "
+                f"A BENCH_WORKDIR_VERSION file is expected with version {version} but not found at {version_file_path}."
             )
 
     os.makedirs(dir)