Fix incorrect logging in mi_gpu_spec.py (#626)

* Move console logging to logger function to avoid circular dependency in utils module

Signed-off-by: coleramos425 <colramos@amd.com>

* Apply python formatting

Signed-off-by: coleramos425 <colramos@amd.com>

* Remove the default StreamHandler before adding the custom

 If you are not explicitly removing this default handler, it could be causing duplicate outputs.

Signed-off-by: coleramos425 <colramos@amd.com>

* Fix lingering bugs from merge conflict resolution

Signed-off-by: coleramos425 <colramos@amd.com>

* Comply to python formatting and update pre-commit hook helper

Signed-off-by: coleramos425 <colramos@amd.com>

* Removing redundant console_log call as the get_mi300_num_xcds() call, otherwise ALL Mi200 profiling runs will print this message

Signed-off-by: coleramos425 <colramos@amd.com>

---------

Signed-off-by: coleramos425 <colramos@amd.com>

.pre-commit-config.yaml

@@ -2,18 +2,18 @@ default_stages: [pre-commit]
 fail_fast: true
 repos:
   - repo: https://github.com/pre-commit/pre-commit-hooks
-    rev: v2.3.0
+    rev: v5.0.0
     hooks:
       - id: check-yaml
       - id: end-of-file-fixer
       - id: trailing-whitespace
   # Python import sorting
   - repo: https://github.com/pycqa/isort
-    rev: 5.12.0
+    rev: 6.0.1
     hooks:
       - id: isort
   # Python formatting (Using this mirror lets us use mypyc-compiled black, which is about 2x faster)
   - repo: https://github.com/psf/black-pre-commit-mirror
-    rev: 24.8.0
+    rev: 25.1.0
     hooks:
       - id: black

src/rocprof-compute

@@ -36,7 +36,7 @@ try:
     from importlib import metadata
 
     from rocprof_compute_base import RocProfCompute
-    from utils.utils import console_error
+    from utils.logger import console_error
 except ImportError as e:
     # print("Failed to import required modules: " + str(e))
     pass

src/rocprof_compute_analyze/analysis_base.py

@@ -30,14 +30,8 @@ from collections import OrderedDict
 from pathlib import Path
 
 from utils import file_io, parser, schema
-from utils.utils import (
-    console_debug,
-    console_error,
-    console_log,
-    demarcate,
-    is_workload_empty,
-    merge_counters_spatial_multiplex,
-)
+from utils.logger import console_debug, console_error, console_log, demarcate
+from utils.utils import is_workload_empty, merge_counters_spatial_multiplex
 
 
 class OmniAnalyze_Base:

src/rocprof_compute_analyze/analysis_cli.py

@@ -25,7 +25,7 @@
 from rocprof_compute_analyze.analysis_base import OmniAnalyze_Base
 from utils import file_io, parser, tty
 from utils.kernel_name_shortener import kernel_name_shortener
-from utils.utils import console_error, demarcate
+from utils.logger import console_error, demarcate
 
 
 class cli_analysis(OmniAnalyze_Base):

src/rocprof_compute_analyze/analysis_webui.py

@@ -35,7 +35,7 @@ from dash.dependencies import Input, Output, State
 from rocprof_compute_analyze.analysis_base import OmniAnalyze_Base
 from utils import file_io, parser
 from utils.gui import build_bar_chart, build_table_chart
-from utils.utils import console_debug, console_error, demarcate
+from utils.logger import console_debug, console_error, demarcate
 
 PROJECT_NAME = "rocprofiler-compute"
 

src/rocprof_compute_base.py

@@ -38,6 +38,11 @@ import config
 from argparser import omniarg_parser
 from utils import file_io, parser, schema
 from utils.logger import (
+    console_debug,
+    console_error,
+    console_log,
+    console_warning,
+    demarcate,
     setup_console_handler,
     setup_file_handler,
     setup_logging_priority,
@@ -45,11 +50,6 @@ from utils.logger import (
 from utils.mi_gpu_spec import get_gpu_series_dict, parse_mi_gpu_spec
 from utils.specs import MachineSpecs, generate_machine_specs
 from utils.utils import (
-    console_debug,
-    console_error,
-    console_log,
-    console_warning,
-    demarcate,
     detect_rocprof,
     get_submodules,
     get_version,

src/rocprof_compute_profile/profiler_base.py

@@ -35,13 +35,15 @@ import pandas as pd
 from tqdm import tqdm
 
 import config
-from utils.utils import (
-    capture_subprocess_output,
+from utils.logger import (
     console_debug,
     console_error,
     console_log,
     console_warning,
     demarcate,
+)
+from utils.utils import (
+    capture_subprocess_output,
     gen_sysinfo,
     print_status,
     run_prof,

src/rocprof_compute_profile/profiler_rocprof_v1.py

@@ -27,7 +27,8 @@ from pathlib import Path
 
 import config
 from rocprof_compute_profile.profiler_base import RocProfCompute_Base
-from utils.utils import console_log, demarcate, replace_timestamps, store_app_cmd
+from utils.logger import console_log, demarcate
+from utils.utils import replace_timestamps, store_app_cmd
 
 
 class rocprof_v1_profiler(RocProfCompute_Base):

src/rocprof_compute_profile/profiler_rocprof_v2.py

@@ -28,7 +28,8 @@ from pathlib import Path
 
 import config
 from rocprof_compute_profile.profiler_base import RocProfCompute_Base
-from utils.utils import console_log, demarcate, replace_timestamps, store_app_cmd
+from utils.logger import console_log, demarcate
+from utils.utils import replace_timestamps, store_app_cmd
 
 
 class rocprof_v2_profiler(RocProfCompute_Base):

src/rocprof_compute_profile/profiler_rocprof_v3.py

@@ -28,7 +28,7 @@ from pathlib import Path
 
 import config
 from rocprof_compute_profile.profiler_base import RocProfCompute_Base
-from utils.utils import console_error, console_log, demarcate, replace_timestamps
+from utils.logger import console_error, console_log, demarcate
 
 
 class rocprof_v3_profiler(RocProfCompute_Base):

src/rocprof_compute_profile/profiler_rocscope.py

@@ -23,7 +23,7 @@
 ##############################################################################el
 
 from rocprof_compute_profile.profiler_base import RocProfCompute_Base
-from utils.utils import console_log, demarcate
+from utils.logger import console_log, demarcate
 
 
 class rocscope_profiler(RocProfCompute_Base):

src/rocprof_compute_soc/soc_base.py

@@ -35,16 +35,18 @@ import pandas as pd
 import yaml
 
 import config
-from utils.mi_gpu_spec import get_gpu_model, get_gpu_series
-from utils.parser import build_in_vars, supported_denom
-from utils.utils import (
-    capture_subprocess_output,
+from utils.logger import (
     console_debug,
     console_error,
     console_log,
     console_warning,
-    convert_metric_id_to_panel_idx,
     demarcate,
+)
+from utils.mi_gpu_spec import get_gpu_model, get_gpu_series
+from utils.parser import build_in_vars, supported_denom
+from utils.utils import (
+    capture_subprocess_output,
+    convert_metric_id_to_panel_idx,
     detect_rocprof,
     get_submodules,
     is_tcc_channel_counter,

src/rocprof_compute_soc/soc_gfx906.py

@@ -26,7 +26,7 @@ from pathlib import Path
 
 import config
 from rocprof_compute_soc.soc_base import OmniSoC_Base
-from utils.utils import console_error, demarcate
+from utils.logger import console_error, demarcate
 
 
 class gfx906_soc(OmniSoC_Base):

src/rocprof_compute_soc/soc_gfx908.py

@@ -26,7 +26,7 @@ from pathlib import Path
 
 import config
 from rocprof_compute_soc.soc_base import OmniSoC_Base
-from utils.utils import console_error, demarcate
+from utils.logger import console_error, demarcate
 
 
 class gfx908_soc(OmniSoC_Base):

src/rocprof_compute_soc/soc_gfx90a.py

@@ -27,7 +27,8 @@ from pathlib import Path
 import config
 from rocprof_compute_soc.soc_base import OmniSoC_Base
 from roofline import Roofline
-from utils.utils import console_log, demarcate, mibench
+from utils.logger import console_log, demarcate
+from utils.utils import mibench
 
 
 class gfx90a_soc(OmniSoC_Base):

src/rocprof_compute_soc/soc_gfx940.py

@@ -27,7 +27,8 @@ from pathlib import Path
 import config
 from rocprof_compute_soc.soc_base import OmniSoC_Base
 from roofline import Roofline
-from utils.utils import console_error, console_log, demarcate, mibench
+from utils.logger import console_error, console_log, demarcate
+from utils.utils import mibench
 
 
 class gfx940_soc(OmniSoC_Base):

src/rocprof_compute_soc/soc_gfx941.py

@@ -27,7 +27,8 @@ from pathlib import Path
 import config
 from rocprof_compute_soc.soc_base import OmniSoC_Base
 from roofline import Roofline
-from utils.utils import console_error, console_log, demarcate, mibench
+from utils.logger import console_error, console_log, demarcate
+from utils.utils import mibench
 
 
 class gfx941_soc(OmniSoC_Base):

src/rocprof_compute_soc/soc_gfx942.py

@@ -27,7 +27,8 @@ from pathlib import Path
 import config
 from rocprof_compute_soc.soc_base import OmniSoC_Base
 from roofline import Roofline
-from utils.utils import console_error, console_log, demarcate, mibench
+from utils.logger import console_error, console_log, demarcate
+from utils.utils import mibench
 
 
 class gfx942_soc(OmniSoC_Base):

src/roofline.py

@@ -33,6 +33,12 @@ import pandas as pd
 import plotly.graph_objects as go
 from dash import dcc, html
 
+from utils.logger import (
+    console_debug,
+    console_error,
+    console_log,
+    demarcate,
+)
 from utils.roofline_calc import (
     MFMA_DATATYPES,
     PEAK_OPS_DATATYPES,
@@ -40,14 +46,7 @@ from utils.roofline_calc import (
     calc_ai,
     constuct_roof,
 )
-from utils.utils import (
-    console_debug,
-    console_error,
-    console_log,
-    demarcate,
-    gen_sysinfo,
-    mibench,
-)
+from utils.utils import mibench
 
 SYMBOLS = [0, 1, 2, 3, 4, 5, 13, 17, 18, 20]
 

src/utils/db_connector.py

@@ -32,14 +32,14 @@ from pymongo import MongoClient
 from tqdm import tqdm
 
 from utils.kernel_name_shortener import kernel_name_shortener
-from utils.utils import (
+from utils.logger import (
     console_debug,
     console_error,
     console_log,
     console_warning,
     demarcate,
-    is_workload_empty,
 )
+from utils.utils import is_workload_empty
 
 MAX_SERVER_SEL_DELAY = 5000  # 5 sec connection timeout
 

src/utils/file_io.py

@@ -36,7 +36,7 @@ import yaml
 import config
 from utils import schema
 from utils.kernel_name_shortener import kernel_name_shortener
-from utils.utils import console_debug, console_error, console_log, demarcate
+from utils.logger import console_debug, console_error, console_log, demarcate
 
 # TODO: use pandas chunksize or dask to read really large csv file
 # from dask import dataframe as dd

src/utils/gui.py

@@ -28,7 +28,7 @@ import plotly.express as px
 from dash import dash_table, html
 
 from utils import schema
-from utils.utils import console_error
+from utils.logger import console_error
 
 pd.set_option(
     "mode.chained_assignment", None

src/utils/gui_components/memchart.py

@@ -25,7 +25,7 @@
 from dash import html
 from dash_svg import G, Path, Rect, Svg, Text
 
-from utils.utils import console_error
+from utils.logger import console_error
 
 hidden_columns = ["Tips", "coll_level"]
 

src/utils/kernel_name_shortener.py

@@ -28,7 +28,7 @@ from pathlib import Path
 
 import pandas as pd
 
-from utils.utils import console_debug, console_error, console_log
+from utils.logger import console_debug, console_error, console_log
 
 cache = dict()
 

src/utils/logger.py

@@ -27,8 +27,6 @@ import os
 import sys
 from pathlib import Path
 
-from utils.utils import trace_logger
-
 # Define the colors
 BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE = range(8)
 RESET_SEQ = "\033[0m"
@@ -44,6 +42,54 @@ COLORS = {
 }
 
 
+def demarcate(function):
+    def wrap_function(*args, **kwargs):
+        logging.trace("----- [entering function] -> %s()" % (function.__qualname__))
+        result = function(*args, **kwargs)
+        logging.trace("----- [exiting  function] -> %s()" % function.__qualname__)
+        return result
+
+    return wrap_function
+
+
+def console_error(*argv, exit=True):
+    if len(argv) > 1:
+        logging.error(f"[{argv[0]}] {argv[1]}")
+    else:
+        logging.error(f"{argv[0]}")
+    if exit:
+        sys.exit(1)
+
+
+def console_log(*argv, indent_level=0):
+    indent = ""
+    if indent_level >= 1:
+        indent = " " * 3 * indent_level + "|-> "  # spaces per indent level
+
+    if len(argv) > 1:
+        logging.info(indent + f"[{argv[0]}] {argv[1]}")
+    else:
+        logging.info(indent + f"{argv[0]}")
+
+
+def console_debug(*argv):
+    if len(argv) > 1:
+        logging.debug(f"[{argv[0]}] {argv[1]}")
+    else:
+        logging.debug(f"{argv[0]}")
+
+
+def console_warning(*argv):
+    if len(argv) > 1:
+        logging.warning(f"[{argv[0]}] {argv[1]}")
+    else:
+        logging.warning(f"{argv[0]}")
+
+
+def trace_logger(message, *args, **kwargs):
+    logging.log(logging.TRACE, message, *args, **kwargs)
+
+
 # Define the formatter
 class ColoredFormatter(logging.Formatter):
     def format(self, record):
@@ -78,6 +124,7 @@ class PlainFormatter(logging.Formatter):
 # Setup console handler - provided as separate function to be called
 # prior to argument parsing
 def setup_console_handler():
+    logging.getLogger().handlers.clear()
     # register a trace level logger
     logging.TRACE = logging.DEBUG - 5
     logging.addLevelName(logging.TRACE, "TRACE")

src/utils/mi_gpu_spec.py

@@ -1,4 +1,3 @@
-import logging
 import os
 import sys
 from dataclasses import dataclass, field
@@ -6,6 +5,8 @@ from typing import Any, Dict, List, Optional, Union
 
 import yaml
 
+from utils.logger import console_debug, console_error, console_log, console_warning
+
 # Constants for MI series
 # NOTE: Currently supports MI50, MI100, MI200, MI300
 MI50 = 0
@@ -96,7 +97,7 @@ class MIGPU(Singleton):
         if self.is_mi300:
             # NOTE: currently, all mi300 series gpus shall have compute partition information
             if self.compute_partition is None:
-                logging.warning(
+                console_warning(
                     "[MIGPU post init] mi300 gpu detected, but no num_xcd/compute partition data detected!!!"
                 )
 
@@ -108,7 +109,7 @@ class MIGPU(Singleton):
         All mi300 series gpus shall have compute partition information.
         """
         if num_xcds is None:
-            logging.warning(
+            console_warning(
                 "[MIGPU post init] mi300 gpu detected, but no num_xcd/compute partition data detected!!!"
             )
 
@@ -150,17 +151,17 @@ def load_yaml(file_path: str) -> Dict[str, Any]:
         Dict[str, Any]: Parsed YAML data as a nested dictionary.
                         Exit with console error if an error occurs.
     """
-    logging.debug("[load_yaml]")
+    console_debug("[load_yaml]")
     try:
         with open(file_path, "r") as file:
             data = yaml.safe_load(file)
             return data
     except FileNotFoundError:
-        logging.error(f"Error: The file '{file_path}' was not found.")
+        console_error(f"Error: The file '{file_path}' was not found.")
     except yaml.YAMLError as exc:
-        logging.error(f"Error parsing YAML file '{file_path}': {exc}")
+        console_error(f"Error parsing YAML file '{file_path}': {exc}")
     except Exception as e:
-        logging.error(
+        console_error(
             f"An unexpected error occurred while loading YAML file '{file_path}': {e}"
         )
 
@@ -186,7 +187,7 @@ def parse_mi_gpu_spec():
 
     for mi_index, mi_series in MI_CONSTANS.items():
         if mi_series != MI_CONSTANS[MI300]:
-            logging.debug("[parse_mi_gpu_spec] Processing series: %s" % mi_series)
+            console_debug("[parse_mi_gpu_spec] Processing series: %s" % mi_series)
             for key, value in yaml_data.items():
                 # parse out gpu series and gpu model information for mi50, 100, 200
                 curr_gpu_arch = value[mi_index]["gpu_archs"][0]["gpu_arch"]
@@ -235,7 +236,7 @@ def parse_mi_gpu_spec():
 
 def get_gpu_series_dict():
     if not gpu_series_dict:
-        logging.error(
+        console_error(
             "gpu_series_dict not yet populated, did you run parse_mi_gpu_spec()?"
         )
         return None
@@ -244,7 +245,7 @@ def get_gpu_series_dict():
 
 def get_gpu_series(gpu_arch_):
     if not gpu_series_dict:
-        logging.error(
+        console_error(
             "gpu_series_dict not yet populated, did you run parse_mi_gpu_spec()?"
         )
         return None
@@ -254,14 +255,14 @@ def get_gpu_series(gpu_arch_):
     if gpu_series:
         return gpu_series
 
-    logging.warning(f"No matching gpu series found for gpu arch: {gpu_arch_}")
+    console_warning(f"No matching gpu series found for gpu arch: {gpu_arch_}")
     return None
 
 
 def get_gpu_model(gpu_arch_, chip_id_):
     # Check that gpu_model_dict is populated first
     if not gpu_model_dict:
-        logging.error(
+        console_error(
             "gpu_model_dict not yet populated. Did you run parse_mi_gpu_spec()?"
         )
         return None
@@ -273,7 +274,7 @@ def get_gpu_model(gpu_arch_, chip_id_):
         if chip_id_ and int(chip_id_) in mi300_chip_id_dict:
             gpu_model = mi300_chip_id_dict.get(int(chip_id_))
         else:
-            logging.warning(f"No gpu model found for chip id: {chip_id_}")
+            console_warning(f"No gpu model found for chip id: {chip_id_}")
             return None
 
     # Otherwise use gpu_model_dict mapping for other mi architectures
@@ -281,11 +282,11 @@ def get_gpu_model(gpu_arch_, chip_id_):
         # NOTE: take the first element works for now
         gpu_model = gpu_model_dict[gpu_arch_lower][0]
     else:
-        logging.warning(f"No gpu model found for gpu arch: {gpu_arch_lower}")
+        console_warning(f"No gpu model found for gpu arch: {gpu_arch_lower}")
         return None
 
     if not gpu_model:
-        logging.warning(f"No gpu model found for gpu arch: {gpu_arch_lower}")
+        console_warning(f"No gpu model found for gpu arch: {gpu_arch_lower}")
         return None
 
     return gpu_model
@@ -293,7 +294,7 @@ def get_gpu_model(gpu_arch_, chip_id_):
 
 def get_mi300_archs_dict():
     if not mi300_archs_dict:
-        logging.error(
+        console_error(
             "mi300_archs_dict not yet populated, did you run parse_mi_gpu_spec()?"
         )
         return None
@@ -302,7 +303,7 @@ def get_mi300_archs_dict():
 
 def get_mi300_num_xcds(gpu_model_, compute_partition_):
     if not mi300_num_xcds_dict:
-        logging.error(
+        console_error(
             "mi300_num_xcds_dict not yet populated, did you run parse_mi_gpu_spec()?"
         )
         return None
@@ -311,17 +312,16 @@ def get_mi300_num_xcds(gpu_model_, compute_partition_):
     partition_lower = compute_partition_.lower()
 
     if gpu_model_lower not in mi300_num_xcds_dict:
-        logging.info(f"Current system is not a mi300 system: {gpu_model_}")
         return None
 
     model_dict = mi300_num_xcds_dict[gpu_model_lower]
     if partition_lower not in model_dict:
-        logging.info(f"Unknown compute partition: {compute_partition_}")
+        console_log(f"Unknown compute partition: {compute_partition_}")
         return None
 
     num_xcds = model_dict[partition_lower]
     if not num_xcds:
-        logging.warning(
+        console_warning(
             "Unknown compute partition found for %s / %s", compute_partition_, gpu_model_
         )
         return None
@@ -333,6 +333,6 @@ def get_mi300_chip_id_dict():
     if mi300_chip_id_dict:
         return mi300_chip_id_dict
     else:
-        logging.error(
+        console_error(
             "mi300_chip_id_dict not yet populated, did you run parse_mi_gpu_spec()?"
         )

src/utils/parser.py

@@ -32,7 +32,7 @@ import numpy as np
 import pandas as pd
 
 from utils import schema
-from utils.utils import console_error, console_warning, demarcate
+from utils.logger import console_error, console_warning, demarcate
 
 # ------------------------------------------------------------------------------
 # Internal global definitions

src/utils/roofline_calc.py

@@ -26,7 +26,7 @@ import csv
 from dataclasses import dataclass
 from pathlib import Path
 
-from utils.utils import console_debug
+from utils.logger import console_debug
 
 ################################################
 # Global vars

src/utils/specs.py

@@ -38,16 +38,15 @@ from pathlib import Path as path
 import pandas as pd
 
 import config
-from utils.mi_gpu_spec import get_gpu_series_dict, get_mi300_chip_id_dict
-from utils.tty import get_table_string
-from utils.utils import (
+from utils.logger import (
     console_debug,
     console_error,
     console_log,
     console_warning,
-    get_version,
-    total_xcds,
 )
+from utils.mi_gpu_spec import get_gpu_series_dict, get_mi300_chip_id_dict
+from utils.tty import get_table_string
+from utils.utils import get_version, total_xcds
 
 VERSION_LOC = [
     "version",

src/utils/tty.py

@@ -29,7 +29,8 @@ import pandas as pd
 from tabulate import tabulate
 
 from utils import parser
-from utils.utils import console_log, console_warning, convert_metric_id_to_panel_idx
+from utils.logger import console_log, console_warning
+from utils.utils import convert_metric_id_to_panel_idx
 
 hidden_columns = ["Tips", "coll_level"]
 hidden_sections = [1900, 2000]

src/utils/utils.py

@@ -42,6 +42,7 @@ from pathlib import Path as path
 import pandas as pd
 
 import config
+from utils.logger import console_debug, console_error, console_log, console_warning
 from utils.mi_gpu_spec import get_mi300_num_xcds
 
 rocprof_cmd = ""
@@ -60,54 +61,6 @@ def using_v3():
     return "ROCPROF" in os.environ.keys() and os.environ["ROCPROF"].endswith("rocprofv3")
 
 
-def demarcate(function):
-    def wrap_function(*args, **kwargs):
-        logging.trace("----- [entering function] -> %s()" % (function.__qualname__))
-        result = function(*args, **kwargs)
-        logging.trace("----- [exiting  function] -> %s()" % function.__qualname__)
-        return result
-
-    return wrap_function
-
-
-def console_error(*argv, exit=True):
-    if len(argv) > 1:
-        logging.error(f"[{argv[0]}] {argv[1]}")
-    else:
-        logging.error(f"{argv[0]}")
-    if exit:
-        sys.exit(1)
-
-
-def console_log(*argv, indent_level=0):
-    indent = ""
-    if indent_level >= 1:
-        indent = " " * 3 * indent_level + "|-> "  # spaces per indent level
-
-    if len(argv) > 1:
-        logging.info(indent + f"[{argv[0]}] {argv[1]}")
-    else:
-        logging.info(indent + f"{argv[0]}")
-
-
-def console_debug(*argv):
-    if len(argv) > 1:
-        logging.debug(f"[{argv[0]}] {argv[1]}")
-    else:
-        logging.debug(f"{argv[0]}")
-
-
-def console_warning(*argv):
-    if len(argv) > 1:
-        logging.warning(f"[{argv[0]}] {argv[1]}")
-    else:
-        logging.warning(f"{argv[0]}")
-
-
-def trace_logger(message, *args, **kwargs):
-    logging.log(logging.TRACE, message, *args, **kwargs)
-
-
 def get_version(rocprof_compute_home) -> dict:
     """Return ROCm Compute Profiler versioning info"""