From: "Michael D Kinney" <michael.d.kinney@intel.com>
To: "mikuback@linux.microsoft.com" <mikuback@linux.microsoft.com>,
"devel@edk2.groups.io" <devel@edk2.groups.io>
Cc: Sean Brogan <sean.brogan@microsoft.com>,
"Gao, Liming" <gaoliming@byosoft.com.cn>,
"Kinney, Michael D" <michael.d.kinney@intel.com>
Subject: Re: [edk2-devel] [PATCH v1 7/7] .pytool/Plugin: Add DebugMacroCheck
Date: Thu, 7 Sep 2023 01:35:58 +0000 [thread overview]
Message-ID: <CO1PR11MB492916CC4E6F908777C29A10D2EEA@CO1PR11MB4929.namprd11.prod.outlook.com> (raw)
In-Reply-To: <20230814204859.257-8-mikuback@linux.microsoft.com>
Reviewed-by: Michael D Kinney <michael.d.kinney@intel.com>
Really like the inclusion of unit tests. If any issues are
found, can update unit test to cover that case.
One quick question. I see a global disable through env var.
I also see it says that is it runs on packages that use the
compiler plugin. Is there a way to disable this plugin at
the package scope? Many plugins support a "skip" setting today.
Thanks,
Mike
> -----Original Message-----
> From: mikuback@linux.microsoft.com <mikuback@linux.microsoft.com>
> Sent: Monday, August 14, 2023 1:49 PM
> To: devel@edk2.groups.io
> Cc: Sean Brogan <sean.brogan@microsoft.com>; Kinney, Michael D
> <michael.d.kinney@intel.com>; Gao, Liming <gaoliming@byosoft.com.cn>
> Subject: [PATCH v1 7/7] .pytool/Plugin: Add DebugMacroCheck
>
> From: Michael Kubacki <michael.kubacki@microsoft.com>
>
> Adds a plugin that finds debug macro formatting issues. These errors
> often creep into debug prints in error conditions not frequently
> executed and make debug more difficult when they are encountered.
>
> The code can be as a standalone script which is useful to find
> problems in a large codebase that has not been checked before or as
> a CI plugin that notifies a developer of an error right away.
>
> The script was already used to find numerous issues in edk2 in the
> past so there's not many code fixes in this change. More details
> are available in the readme file:
>
> .pytool\Plugin\DebugMacroCheck\Readme.md
>
> Cc: Sean Brogan <sean.brogan@microsoft.com>
> Cc: Michael D Kinney <michael.d.kinney@intel.com>
> Cc: Liming Gao <gaoliming@byosoft.com.cn>
> Signed-off-by: Michael Kubacki <michael.kubacki@microsoft.com>
> ---
> .pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheckBuildPlugin.py
> | 127 +++
> .pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheck_plug_in.yaml
> | 11 +
> .pytool/Plugin/DebugMacroCheck/DebugMacroCheck.py
> | 859 ++++++++++++++++++++
> .pytool/Plugin/DebugMacroCheck/Readme.md
> | 253 ++++++
> .pytool/Plugin/DebugMacroCheck/tests/DebugMacroDataSet.py
> | 674 +++++++++++++++
> .pytool/Plugin/DebugMacroCheck/tests/MacroTest.py
> | 131 +++
> .pytool/Plugin/DebugMacroCheck/tests/__init__.py
> | 0
> .pytool/Plugin/DebugMacroCheck/tests/test_DebugMacroCheck.py
> | 201 +++++
> 8 files changed, 2256 insertions(+)
>
> diff --git
> a/.pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheckBuildPlugin.p
> y
> b/.pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheckBuildPlugin.p
> y
> new file mode 100644
> index 000000000000..b1544666025e
> --- /dev/null
> +++
> b/.pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheckBuildPlugin.p
> y
> @@ -0,0 +1,127 @@
> +# @file DebugMacroCheckBuildPlugin.py
> +#
> +# A build plugin that checks if DEBUG macros are formatted properly.
> +#
> +# In particular, that print format specifiers are defined
> +# with the expected number of arguments in the variable
> +# argument list.
> +#
> +# Copyright (c) Microsoft Corporation. All rights reserved.
> +# SPDX-License-Identifier: BSD-2-Clause-Patent
> +##
> +
> +import logging
> +import os
> +import pathlib
> +import sys
> +import yaml
> +
> +# Import the build plugin
> +plugin_file = pathlib.Path(__file__)
> +sys.path.append(str(plugin_file.parent.parent))
> +
> +# flake8 (E402): Ignore flake8 module level import not at top of file
> +import DebugMacroCheck # noqa: E402
> +
> +from edk2toolext import edk2_logging #
> noqa: E402
> +from edk2toolext.environment.plugintypes.uefi_build_plugin import \
> + IUefiBuildPlugin #
> noqa: E402
> +from edk2toolext.environment.uefi_build import UefiBuilder #
> noqa: E402
> +from edk2toollib.uefi.edk2.path_utilities import Edk2Path #
> noqa: E402
> +from pathlib import Path #
> noqa: E402
> +
> +
> +class DebugMacroCheckBuildPlugin(IUefiBuildPlugin):
> +
> + def do_pre_build(self, builder: UefiBuilder) -> int:
> + """Debug Macro Check pre-build functionality.
> +
> + The plugin is invoked in pre-build since it can operate
> independently
> + of build tools and to notify the user of any errors earlier in
> the
> + build process to reduce feedback time.
> +
> + Args:
> + builder (UefiBuilder): A UEFI builder object for this build.
> +
> + Returns:
> + int: The number of debug macro errors found. Zero indicates
> the
> + check either did not run or no errors were found.
> + """
> +
> + # Check if disabled in the environment
> + env_disable = builder.env.GetValue("DISABLE_DEBUG_MACRO_CHECK")
> + if env_disable:
> + return 0
> +
> + # Only run on targets with compilation
> + build_target = builder.env.GetValue("TARGET").lower()
> + if "no-target" in build_target:
> + return 0
> +
> + pp = builder.pp.split(os.pathsep)
> + edk2 = Edk2Path(builder.ws, pp)
> + package = edk2.GetContainingPackage(
> + builder.mws.join(builder.ws,
> + builder.env.GetValue(
> + "ACTIVE_PLATFORM")))
> + package_path = Path(
> +
> edk2.GetAbsolutePathOnThisSystemFromEdk2RelativePath(
> + package))
> +
> + # Every debug macro is printed at DEBUG logging level.
> + # Ensure the level is above DEBUG while executing the macro
> check
> + # plugin to avoid flooding the log handler.
> + handler_level_context = []
> + for h in logging.getLogger().handlers:
> + if h.level < logging.INFO:
> + handler_level_context.append((h, h.level))
> + h.setLevel(logging.INFO)
> +
> + edk2_logging.log_progress("Checking DEBUG Macros")
> +
> + # There are two ways to specify macro substitution data for this
> + # plugin. If multiple options are present, data is appended from
> + # each option.
> + #
> + # 1. Specify the substitution data in the package CI YAML file.
> + # 2. Specify a standalone substitution data YAML file.
> + ##
> + sub_data = {}
> +
> + # 1. Allow substitution data to be specified in a
> "DebugMacroCheck" of
> + # the package CI YAML file. This is used to provide a familiar
> per-
> + # package customization flow for a package maintainer.
> + package_config_file = Path(
> + os.path.join(
> + package_path, package + ".ci.yaml"))
> + if package_config_file.is_file():
> + with open(package_config_file, 'r') as cf:
> + package_config_file_data = yaml.safe_load(cf)
> + if "DebugMacroCheck" in package_config_file_data and \
> + "StringSubstitutions" in \
> + package_config_file_data["DebugMacroCheck"]:
> + logging.info(f"Loading substitution data in "
> + f"{str(package_config_file)}")
> + sub_data |=
> package_config_file_data["DebugMacroCheck"]["StringSubstitutions"] # noqa
> +
> + # 2. Allow a substitution file to be specified as an environment
> + # variable. This is used to provide flexibility in how to
> specify a
> + # substitution file. The value can be set anywhere prior to this
> plugin
> + # getting called such as pre-existing build script.
> + sub_file = builder.env.GetValue("DEBUG_MACRO_CHECK_SUB_FILE")
> + if sub_file:
> + logging.info(f"Loading substitution file {sub_file}")
> + with open(sub_file, 'r') as sf:
> + sub_data |= yaml.safe_load(sf)
> +
> + try:
> + error_count = DebugMacroCheck.check_macros_in_directory(
> + package_path,
> + ignore_git_submodules=False,
> + show_progress_bar=False,
> + **sub_data)
> + finally:
> + for h, l in handler_level_context:
> + h.setLevel(l)
> +
> + return error_count
> diff --git
> a/.pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheck_plug_in.yaml
> b/.pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheck_plug_in.yaml
> new file mode 100644
> index 000000000000..50f97cbd3935
> --- /dev/null
> +++
> b/.pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheck_plug_in.yaml
> @@ -0,0 +1,11 @@
> +## @file
> +# Build plugin used to check that debug macros are formatted properly.
> +#
> +# Copyright (c) Microsoft Corporation. All rights reserved.
> +# SPDX-License-Identifier: BSD-2-Clause-Patent
> +##
> +{
> + "scope": "global",
> + "name": "Debug Macro Check Plugin",
> + "module": "DebugMacroCheckBuildPlugin"
> +}
> diff --git a/.pytool/Plugin/DebugMacroCheck/DebugMacroCheck.py
> b/.pytool/Plugin/DebugMacroCheck/DebugMacroCheck.py
> new file mode 100644
> index 000000000000..ffabcdf91b60
> --- /dev/null
> +++ b/.pytool/Plugin/DebugMacroCheck/DebugMacroCheck.py
> @@ -0,0 +1,859 @@
> +# @file DebugMacroCheck.py
> +#
> +# A script that checks if DEBUG macros are formatted properly.
> +#
> +# In particular, that print format specifiers are defined
> +# with the expected number of arguments in the variable
> +# argument list.
> +#
> +# Copyright (c) Microsoft Corporation. All rights reserved.
> +# SPDX-License-Identifier: BSD-2-Clause-Patent
> +##
> +
> +from argparse import RawTextHelpFormatter
> +import logging
> +import os
> +import re
> +import regex
> +import sys
> +import shutil
> +import timeit
> +import yaml
> +
> +from edk2toollib.utility_functions import RunCmd
> +from io import StringIO
> +from pathlib import Path, PurePath
> +from typing import Dict, Iterable, List, Optional, Tuple
> +
> +
> +PROGRAM_NAME = "Debug Macro Checker"
> +
> +
> +class GitHelpers:
> + """
> + Collection of Git helpers.
> +
> + Will be moved to a more generic module and imported in the future.
> + """
> +
> + @staticmethod
> + def get_git_ignored_paths(directory_path: PurePath) -> List[Path]:
> + """Returns ignored files in this git repository.
> +
> + Args:
> + directory_path (PurePath): Path to the git directory.
> +
> + Returns:
> + List[Path]: List of file absolute paths to all files ignored
> + in this git repository. If git is not found, an
> empty
> + list will be returned.
> + """
> + if not shutil.which("git"):
> + logging.warn(
> + "Git is not found on this system. Git submodule paths
> will "
> + "not be considered.")
> + return []
> +
> + out_stream_buffer = StringIO()
> + exit_code = RunCmd("git", "ls-files --other",
> + workingdir=str(directory_path),
> + outstream=out_stream_buffer,
> + logging_level=logging.NOTSET)
> + if exit_code != 0:
> + return []
> +
> + rel_paths = out_stream_buffer.getvalue().strip().splitlines()
> + abs_paths = []
> + for path in rel_paths:
> + abs_paths.append(Path(directory_path, path))
> + return abs_paths
> +
> + @staticmethod
> + def get_git_submodule_paths(directory_path: PurePath) -> List[Path]:
> + """Returns submodules in the given workspace directory.
> +
> + Args:
> + directory_path (PurePath): Path to the git directory.
> +
> + Returns:
> + List[Path]: List of directory absolute paths to the root of
> + each submodule found from this folder. If submodules are not
> + found, an empty list will be returned.
> + """
> + if not shutil.which("git"):
> + return []
> +
> + if os.path.isfile(directory_path.joinpath(".gitmodules")):
> + out_stream_buffer = StringIO()
> + exit_code = RunCmd(
> + "git", "config --file .gitmodules --get-regexp path",
> + workingdir=str(directory_path),
> + outstream=out_stream_buffer,
> + logging_level=logging.NOTSET)
> + if exit_code != 0:
> + return []
> +
> + submodule_paths = []
> + for line in
> out_stream_buffer.getvalue().strip().splitlines():
> + submodule_paths.append(
> + Path(directory_path, line.split()[1]))
> +
> + return submodule_paths
> + else:
> + return []
> +
> +
> +class QuietFilter(logging.Filter):
> + """A logging filter that temporarily suppresses message output."""
> +
> + def __init__(self, quiet: bool = False):
> + """Class constructor method.
> +
> + Args:
> + quiet (bool, optional): Indicates if messages are currently
> being
> + printed (False) or not (True). Defaults to False.
> + """
> +
> + self._quiet = quiet
> +
> + def filter(self, record: logging.LogRecord) -> bool:
> + """Quiet filter method.
> +
> + Args:
> + record (logging.LogRecord): A log record object that the
> filter is
> + applied to.
> +
> + Returns:
> + bool: True if messages are being suppressed. Otherwise,
> False.
> + """
> + return not self._quiet
> +
> +
> +class ProgressFilter(logging.Filter):
> + """A logging filter that suppresses 'Progress' messages."""
> +
> + def filter(self, record: logging.LogRecord) -> bool:
> + """Progress filter method.
> +
> + Args:
> + record (logging.LogRecord): A log record object that the
> filter is
> + applied to.
> +
> + Returns:
> + bool: True if the message is not a 'Progress' message.
> Otherwise,
> + False.
> + """
> + return not record.getMessage().startswith("\rProgress")
> +
> +
> +class CacheDuringProgressFilter(logging.Filter):
> + """A logging filter that suppresses messages during progress
> operations."""
> +
> + _message_cache = []
> +
> + @property
> + def message_cache(self) -> List[logging.LogRecord]:
> + """Contains a cache of messages accumulated during time of
> operation.
> +
> + Returns:
> + List[logging.LogRecord]: List of log records stored while
> the
> + filter was active.
> + """
> + return self._message_cache
> +
> + def filter(self, record: logging.LogRecord):
> + """Cache progress filter that suppresses messages during
> progress
> + display output.
> +
> + Args:
> + record (logging.LogRecord): A log record to cache.
> + """
> + self._message_cache.append(record)
> +
> +
> +def check_debug_macros(macros: Iterable[Dict[str, str]],
> + file_dbg_path: str,
> + **macro_subs: str
> + ) -> Tuple[int, int, int]:
> + """Checks if debug macros contain formatting errors.
> +
> + Args:
> + macros (Iterable[Dict[str, str]]): : A groupdict of macro
> matches.
> + This is an iterable of dictionaries with group names from the
> regex
> + match as the key and the matched string as the value for the
> key.
> +
> + file_dbg_path (str): The file path (or other custom string) to
> display
> + in debug messages.
> +
> + macro_subs (Dict[str,str]): Variable-length keyword and
> replacement
> + value string pairs to substitute during debug macro checks.
> +
> + Returns:
> + Tuple[int, int, int]: A tuple of the number of formatting
> errors,
> + number of print specifiers, and number of arguments for the
> macros
> + given.
> + """
> +
> + macro_subs = {k.lower(): v for k, v in macro_subs.items()}
> +
> + arg_cnt, failure_cnt, print_spec_cnt = 0, 0, 0
> + for macro in macros:
> + # Special Specifier Handling
> + processed_dbg_str = macro['dbg_str'].strip().lower()
> +
> + logging.debug(f"Inspecting macro: {macro}")
> +
> + # Make any macro substitutions so further processing is applied
> + # to the substituted value.
> + for k in macro_subs.keys():
> + processed_dbg_str = processed_dbg_str.replace(k,
> macro_subs[k])
> +
> + logging.debug("Debug macro string after replacements: "
> + f"{processed_dbg_str}")
> +
> + # These are very rarely used in debug strings. They are somewhat
> + # more common in HII code to control text displayed on the
> + # console. Due to the rarity and likelihood usage is a mistake,
> + # a warning is shown if found.
> + specifier_display_replacements = ['%n', '%h', '%e', '%b', '%v']
> + for s in specifier_display_replacements:
> + if s in processed_dbg_str:
> + logging.warning(f"File: {file_dbg_path}")
> + logging.warning(f" {s} found in string and ignored:")
> + logging.warning(f" \"{processed_dbg_str}\"")
> + processed_dbg_str = processed_dbg_str.replace(s, '')
> +
> + # These are miscellaneous print specifiers that do not require
> + # special parsing and simply need to be replaced since they do
> + # have a corresponding argument associated with them.
> + specifier_other_replacements = ['%%', '\r', '\n']
> + for s in specifier_other_replacements:
> + if s in processed_dbg_str:
> + processed_dbg_str = processed_dbg_str.replace(s, '')
> +
> + processed_dbg_str = re.sub(
> + r'%[.\-+ ,Ll0-9]*\*[.\-+ ,Ll0-9]*[a-zA-Z]', '%_%_',
> + processed_dbg_str)
> + logging.debug(f"Final macro before print specifier scan: "
> + f"{processed_dbg_str}")
> +
> + print_spec_cnt = processed_dbg_str.count('%')
> +
> + # Need to take into account parentheses between args in function
> + # calls that might be in the args list. Use regex module for
> + # this one since the recursive pattern match helps simplify
> + # only matching commas outside nested call groups.
> + if macro['dbg_args'] is None:
> + processed_arg_str = ""
> + else:
> + processed_arg_str = macro['dbg_args'].strip()
> +
> + argument_other_replacements = ['\r', '\n']
> + for r in argument_other_replacements:
> + if s in processed_arg_str:
> + processed_arg_str = processed_arg_str.replace(s, '')
> + processed_arg_str = re.sub(r' +', ' ', processed_arg_str)
> +
> + # Handle special case of commas in arg strings - remove them for
> + # final count to pick up correct number of argument separating
> + # commas.
> + processed_arg_str = re.sub(
> + r'([\"\'])(?:|\\.|[^\\])*?(\1)',
> + '',
> + processed_arg_str)
> +
> + arg_matches = regex.findall(
> + r'(?:\((?:[^)(]+|(?R))*+\))|(,)',
> + processed_arg_str,
> + regex.MULTILINE)
> +
> + arg_cnt = 0
> + if processed_arg_str != '':
> + arg_cnt = arg_matches.count(',')
> +
> + if print_spec_cnt != arg_cnt:
> + logging.error(f"File: {file_dbg_path}")
> + logging.error(f" Message = {macro['dbg_str']}")
> + logging.error(f" Arguments =
> \"{processed_arg_str}\"")
> + logging.error(f" Specifier Count = {print_spec_cnt}")
> + logging.error(f" Argument Count = {arg_cnt}")
> +
> + failure_cnt += 1
> +
> + return failure_cnt, print_spec_cnt, arg_cnt
> +
> +
> +def get_debug_macros(file_contents: str) -> List[Dict[str, str]]:
> + """Extract debug macros from the given file contents.
> +
> + Args:
> + file_contents (str): A string of source file contents that may
> + contain debug macros.
> +
> + Returns:
> + List[Dict[str, str]]: A groupdict of debug macro regex matches
> + within the file contents provided.
> + """
> +
> + # This is the main regular expression that is responsible for
> identifying
> + # DEBUG macros within source files and grouping the macro message
> string
> + # and macro arguments strings so they can be further processed.
> + r = regex.compile(
> +
> r'(?>(?P<prologue>DEBUG\s*\(\s*\((?:.*?,))(?:\s*))(?P<dbg_str>.*?(?:\"'
> +
> r'(?:[^\"\\]|\\.)*\".*?)*)(?:(?(?=,)(?<dbg_args>.*?(?=(?:\s*\)){2}\s*;'
> + r'))))(?:\s*\)){2,};?',
> + regex.MULTILINE | regex.DOTALL)
> + return [m.groupdict() for m in r.finditer(file_contents)]
> +
> +
> +def check_macros_in_string(src_str: str,
> + file_dbg_path: str,
> + **macro_subs: str) -> Tuple[int, int, int]:
> + """Checks for debug macro formatting errors in a string.
> +
> + Args:
> + src_str (str): Contents of the string with debug macros.
> +
> + file_dbg_path (str): The file path (or other custom string) to
> display
> + in debug messages.
> +
> + macro_subs (Dict[str,str]): Variable-length keyword and
> replacement
> + value string pairs to substitute during debug macro checks.
> +
> + Returns:
> + Tuple[int, int, int]: A tuple of the number of formatting
> errors,
> + number of print specifiers, and number of arguments for the
> macros
> + in the string given.
> + """
> + return check_debug_macros(
> + get_debug_macros(src_str), file_dbg_path, **macro_subs)
> +
> +
> +def check_macros_in_file(file: PurePath,
> + file_dbg_path: str,
> + show_utf8_decode_warning: bool = False,
> + **macro_subs: str) -> Tuple[int, int, int]:
> + """Checks for debug macro formatting errors in a file.
> +
> + Args:
> + file (PurePath): The file path to check.
> +
> + file_dbg_path (str): The file path (or other custom string) to
> display
> + in debug messages.
> +
> + show_utf8_decode_warning (bool, optional): Indicates whether to
> show
> + warnings if UTF-8 files fail to decode. Defaults to False.
> +
> + macro_subs (Dict[str,str]): Variable-length keyword and
> replacement
> + value string pairs to substitute during debug macro checks.
> +
> + Returns:
> + Tuple[int, int, int]: A tuple of the number of formatting
> errors,
> + number of print specifiers, and number of arguments for the
> macros
> + in the file given.
> + """
> + try:
> + return check_macros_in_string(
> + file.read_text(encoding='utf-8'), file_dbg_path,
> + **macro_subs)
> + except UnicodeDecodeError as e:
> + if show_utf8_decode_warning:
> + logging.warning(
> + f"{file_dbg_path} UTF-8 decode error.\n"
> + " Debug macro code check skipped!\n"
> + f" -> {str(e)}")
> + return 0, 0, 0
> +
> +
> +def check_macros_in_directory(directory: PurePath,
> + file_extensions: Iterable[str] = ('.c',),
> + ignore_git_ignore_files: Optional[bool] =
> True,
> + ignore_git_submodules: Optional[bool] =
> True,
> + show_progress_bar: Optional[bool] = True,
> + show_utf8_decode_warning: bool = False,
> + **macro_subs: str
> + ) -> int:
> + """Checks files with the given extension in the given directory for
> debug
> + macro formatting errors.
> +
> + Args:
> + directory (PurePath): The path to the directory to check.
> + file_extensions (Iterable[str], optional): An iterable of
> strings
> + representing file extensions to check. Defaults to ('.c',).
> +
> + ignore_git_ignore_files (Optional[bool], optional): Indicates
> whether
> + files ignored by git should be ignored for the debug macro
> check.
> + Defaults to True.
> +
> + ignore_git_submodules (Optional[bool], optional): Indicates
> whether
> + files located in git submodules should not be checked. Defaults
> to
> + True.
> +
> + show_progress_bar (Optional[bool], optional): Indicates whether
> to
> + show a progress bar to show progress status while checking
> macros.
> + This is more useful on a very large directories. Defaults to
> True.
> +
> + show_utf8_decode_warning (bool, optional): Indicates whether to
> show
> + warnings if UTF-8 files fail to decode. Defaults to False.
> +
> + macro_subs (Dict[str,str]): Variable-length keyword and
> replacement
> + value string pairs to substitute during debug macro checks.
> +
> + Returns:
> + int: Count of debug macro errors in the directory.
> + """
> + def _get_file_list(root_directory: PurePath,
> + extensions: Iterable[str]) -> List[Path]:
> + """Returns a list of files recursively located within the path.
> +
> + Args:
> + root_directory (PurePath): A directory Path object to the
> root
> + folder.
> +
> + extensions (Iterable[str]): An iterable of strings that
> + represent file extensions to recursively search for within
> + root_directory.
> +
> + Returns:
> + List[Path]: List of file Path objects to files found in the
> + given directory with the given extensions.
> + """
> + def _show_file_discovered_message(file_count: int,
> + elapsed_time: float) -> None:
> + print(f"\rDiscovered {file_count:,} files in",
> + f"{current_start_delta:-.0f}s"
> + f"{'.' * min(int(current_start_delta), 40)}",
> end="\r")
> +
> + start_time = timeit.default_timer()
> + previous_indicator_time = start_time
> +
> + files = []
> + for file in root_directory.rglob('*'):
> + if file.suffix in extensions:
> + files.append(Path(file))
> +
> + # Give an indicator progress is being made
> + # This has a negligible impact on overall performance
> + # with print emission limited to half second intervals.
> + current_time = timeit.default_timer()
> + current_start_delta = current_time - start_time
> +
> + if current_time - previous_indicator_time >= 0.5:
> + # Since this rewrites the line, it can be considered a
> form
> + # of progress bar
> + if show_progress_bar:
> + _show_file_discovered_message(len(files),
> + current_start_delta)
> + previous_indicator_time = current_time
> +
> + if show_progress_bar:
> + _show_file_discovered_message(len(files),
> current_start_delta)
> + print()
> +
> + return files
> +
> + logging.info(f"Checking Debug Macros in directory: "
> + f"{directory.resolve()}\n")
> +
> + logging.info("Gathering the overall file list. This might take a"
> + "while.\n")
> +
> + start_time = timeit.default_timer()
> + file_list = set(_get_file_list(directory, file_extensions))
> + end_time = timeit.default_timer() - start_time
> +
> + logging.debug(f"[PERF] File search found {len(file_list):,} files in
> "
> + f"{end_time:.2f} seconds.")
> +
> + if ignore_git_ignore_files:
> + logging.info("Getting git ignore files...")
> + start_time = timeit.default_timer()
> + ignored_file_paths = GitHelpers.get_git_ignored_paths(directory)
> + end_time = timeit.default_timer() - start_time
> +
> + logging.debug(f"[PERF] File ignore gathering took {end_time:.2f}
> "
> + f"seconds.")
> +
> + logging.info("Ignoring git ignore files...")
> + logging.debug(f"File list count before git ignore
> {len(file_list):,}")
> + start_time = timeit.default_timer()
> + file_list = file_list.difference(ignored_file_paths)
> + end_time = timeit.default_timer() - start_time
> + logging.info(f" {len(ignored_file_paths):,} files are ignored
> by git")
> + logging.info(f" {len(file_list):,} files after removing "
> + f"ignored files")
> +
> + logging.debug(f"[PERF] File ignore calculation took
> {end_time:.2f} "
> + f"seconds.")
> +
> + if ignore_git_submodules:
> + logging.info("Ignoring git submodules...")
> + submodule_paths = GitHelpers.get_git_submodule_paths(directory)
> + if submodule_paths:
> + logging.debug(f"File list count before git submodule
> exclusion "
> + f"{len(file_list):,}")
> + start_time = timeit.default_timer()
> + file_list = [f for f in file_list
> + if not f.is_relative_to(*submodule_paths)]
> + end_time = timeit.default_timer() - start_time
> +
> + for path in enumerate(submodule_paths):
> + logging.debug(" {0}. {1}".format(*path))
> +
> + logging.info(f" {len(submodule_paths):,} submodules found")
> + logging.info(f" {len(file_list):,} files will be examined
> after "
> + f"excluding files in submodules")
> +
> + logging.debug(f"[PERF] Submodule exclusion calculation took
> "
> + f"{end_time:.2f} seconds.")
> + else:
> + logging.warning("No submodules found")
> +
> + logging.info(f"\nStarting macro check on {len(file_list):,} files.")
> +
> + cache_progress_filter = CacheDuringProgressFilter()
> + handler = next((h for h in logging.getLogger().handlers if
> h.get_name() ==
> + 'stdout_logger_handler'), None)
> +
> + if handler is not None:
> + handler.addFilter(cache_progress_filter)
> +
> + start_time = timeit.default_timer()
> +
> + failure_cnt, file_cnt = 0, 0
> + for file_cnt, file in enumerate(file_list):
> + file_rel_path = str(file.relative_to(directory))
> + failure_cnt += check_macros_in_file(
> + file, file_rel_path,
> show_utf8_decode_warning,
> + **macro_subs)[0]
> + if show_progress_bar:
> + _show_progress(file_cnt, len(file_list),
> + f" {failure_cnt} errors" if failure_cnt > 0
> else "")
> +
> + if show_progress_bar:
> + _show_progress(len(file_list), len(file_list),
> + f" {failure_cnt} errors" if failure_cnt > 0 else
> "")
> + print("\n", flush=True)
> +
> + end_time = timeit.default_timer() - start_time
> +
> + if handler is not None:
> + handler.removeFilter(cache_progress_filter)
> +
> + for record in cache_progress_filter.message_cache:
> + handler.emit(record)
> +
> + logging.debug(f"[PERF] The macro check operation took {end_time:.2f}
> "
> + f"seconds.")
> +
> + _log_failure_count(failure_cnt, file_cnt)
> +
> + return failure_cnt
> +
> +
> +def _log_failure_count(failure_count: int, file_count: int) -> None:
> + """Logs the failure count.
> +
> + Args:
> + failure_count (int): Count of failures to log.
> +
> + file_count (int): Count of files with failures.
> + """
> + if failure_count > 0:
> + logging.error("\n")
> + logging.error(f"{failure_count:,} debug macro errors in "
> + f"{file_count:,} files")
> +
> +
> +def _show_progress(step: int, total: int, suffix: str = '') -> None:
> + """Print progress of tick to total.
> +
> + Args:
> + step (int): The current step count.
> +
> + total (int): The total step count.
> +
> + suffix (str): String to print at the end of the progress bar.
> + """
> + global _progress_start_time
> +
> + if step == 0:
> + _progress_start_time = timeit.default_timer()
> +
> + terminal_col = shutil.get_terminal_size().columns
> + var_consume_len = (len("Progress|\u2588| 000.0% Complete 000s") +
> + len(suffix))
> + avail_len = terminal_col - var_consume_len
> +
> + percent = f"{100 * (step / float(total)):3.1f}"
> + filled = int(avail_len * step // total)
> + bar = '\u2588' * filled + '-' * (avail_len - filled)
> + step_time = timeit.default_timer() - _progress_start_time
> +
> + print(f'\rProgress|{bar}| {percent}% Complete {step_time:-3.0f}s'
> + f'{suffix}', end='\r')
> +
> +
> +def _module_invocation_check_macros_in_directory_wrapper() -> int:
> + """Provides an command-line argument wrapper for checking debug
> macros.
> +
> + Returns:
> + int: The system exit code value.
> + """
> + import argparse
> + import builtins
> +
> + def _check_dir_path(dir_path: str) -> bool:
> + """Returns the absolute path if the path is a directory."
> +
> + Args:
> + dir_path (str): A directory file system path.
> +
> + Raises:
> + NotADirectoryError: The directory path given is not a
> directory.
> +
> + Returns:
> + bool: True if the path is a directory else False.
> + """
> + abs_dir_path = os.path.abspath(dir_path)
> + if os.path.isdir(dir_path):
> + return abs_dir_path
> + else:
> + raise NotADirectoryError(abs_dir_path)
> +
> + def _check_file_path(file_path: str) -> bool:
> + """Returns the absolute path if the path is a file."
> +
> + Args:
> + file_path (str): A file path.
> +
> + Raises:
> + FileExistsError: The path is not a valid file.
> +
> + Returns:
> + bool: True if the path is a valid file else False.
> + """
> + abs_file_path = os.path.abspath(file_path)
> + if os.path.isfile(file_path):
> + return abs_file_path
> + else:
> + raise FileExistsError(file_path)
> +
> + def _quiet_print(*args, **kwargs):
> + """Replaces print when quiet is requested to prevent printing
> messages.
> + """
> + pass
> +
> + root_logger = logging.getLogger()
> + root_logger.setLevel(logging.DEBUG)
> +
> + stdout_logger_handler = logging.StreamHandler(sys.stdout)
> + stdout_logger_handler.set_name('stdout_logger_handler')
> + stdout_logger_handler.setLevel(logging.INFO)
> + stdout_logger_handler.setFormatter(logging.Formatter('%(message)s'))
> + root_logger.addHandler(stdout_logger_handler)
> +
> + parser = argparse.ArgumentParser(
> + prog=PROGRAM_NAME,
> + description=(
> + "Checks for debug macro formatting "
> + "errors within files recursively located
> within "
> + "a given directory."),
> + formatter_class=RawTextHelpFormatter)
> +
> + io_req_group = parser.add_mutually_exclusive_group(required=True)
> + io_opt_group = parser.add_argument_group(
> + "Optional input and output")
> + git_group = parser.add_argument_group("Optional git control")
> +
> + io_req_group.add_argument('-w', '--workspace-directory',
> + type=_check_dir_path,
> + help="Directory of source files to
> check.\n\n")
> +
> + io_req_group.add_argument('-i', '--input-file', nargs='?',
> + type=_check_file_path,
> + help="File path for an input file to
> check.\n\n"
> + "Note that some other options do not
> apply "
> + "if a single file is specified such
> as "
> + "the\ngit options and file
> extensions.\n\n")
> +
> + io_opt_group.add_argument('-l', '--log-file',
> + nargs='?',
> + default=None,
> + const='debug_macro_check.log',
> + help="File path for log output.\n"
> + "(default: if the flag is given with
> no "
> + "file path then a file called\n"
> + "debug_macro_check.log is created and
> used "
> + "in the current directory)\n\n")
> +
> + io_opt_group.add_argument('-s', '--substitution-file',
> + type=_check_file_path,
> + help="A substitution YAML file specifies
> string "
> + "substitutions to perform within the
> debug "
> + "macro.\n\nThis is intended to be a
> simple "
> + "mechanism to expand the rare cases
> of pre-"
> + "processor\nmacros without directly "
> + "involving the pre-processor. The
> file "
> + "consists of one or more\nstring
> value "
> + "pairs where the key is the
> identifier to "
> + "replace and the value is the
> value\nto "
> + "replace it with.\n\nThis can also be
> used "
> + "as a method to ignore results by "
> + "replacing the problematic
> string\nwith a "
> + "different string.\n\n")
> +
> + io_opt_group.add_argument('-v', '--verbose-log-file',
> + action='count',
> + default=0,
> + help="Set file logging verbosity level.\n"
> + " - None: Info & > level
> messages\n"
> + " - '-v': + Debug level
> messages\n"
> + " - '-vv': + File name and
> function\n"
> + " - '-vvv': + Line number\n"
> + " - '-vvvv': + Timestamp\n"
> + "(default: verbose logging is not
> enabled)"
> + "\n\n")
> +
> + io_opt_group.add_argument('-n', '--no-progress-bar',
> action='store_true',
> + help="Disables progress bars.\n"
> + "(default: progress bars are used in
> some"
> + "places to show progress)\n\n")
> +
> + io_opt_group.add_argument('-q', '--quiet', action='store_true',
> + help="Disables console output.\n"
> + "(default: console output is
> enabled)\n\n")
> +
> + io_opt_group.add_argument('-u', '--utf8w', action='store_true',
> + help="Shows warnings for file UTF-8 decode
> "
> + "errors.\n"
> + "(default: UTF-8 decode errors are
> not "
> + "shown)\n\n")
> +
> + git_group.add_argument('-df', '--do-not-ignore-git-ignore-files',
> + action='store_true',
> + help="Do not ignore git ignored files.\n"
> + "(default: files in git ignore files are
> "
> + "ignored)\n\n")
> +
> + git_group.add_argument('-ds', '--do-not-ignore-git_submodules',
> + action='store_true',
> + help="Do not ignore files in git
> submodules.\n"
> + "(default: files in git submodules are "
> + "ignored)\n\n")
> +
> + parser.add_argument('-e', '--extensions', nargs='*', default=['.c'],
> + help="List of file extensions to include.\n"
> + "(default: %(default)s)")
> +
> + args = parser.parse_args()
> +
> + if args.quiet:
> + # Don't print in the few places that directly print
> + builtins.print = _quiet_print
> + stdout_logger_handler.addFilter(QuietFilter(args.quiet))
> +
> + if args.log_file:
> + file_logger_handler =
> logging.FileHandler(filename=args.log_file,
> + mode='w',
> encoding='utf-8')
> +
> + # In an ideal world, everyone would update to the latest Python
> + # minor version (3.10) after a few weeks/months. Since that's
> not the
> + # case, resist from using structural pattern matching in Python
> 3.10.
> + # https://peps.python.org/pep-0636/
> +
> + if args.verbose_log_file == 0:
> + file_logger_handler.setLevel(logging.INFO)
> + file_logger_formatter = logging.Formatter(
> + '%(levelname)-8s %(message)s')
> + elif args.verbose_log_file == 1:
> + file_logger_handler.setLevel(logging.DEBUG)
> + file_logger_formatter = logging.Formatter(
> + '%(levelname)-8s %(message)s')
> + elif args.verbose_log_file == 2:
> + file_logger_handler.setLevel(logging.DEBUG)
> + file_logger_formatter = logging.Formatter(
> + '[%(filename)s - %(funcName)20s() ] %(levelname)-8s '
> + '%(message)s')
> + elif args.verbose_log_file == 3:
> + file_logger_handler.setLevel(logging.DEBUG)
> + file_logger_formatter = logging.Formatter(
> + '[%(filename)s:%(lineno)s - %(funcName)20s() ] '
> + '%(levelname)-8s %(message)s')
> + elif args.verbose_log_file == 4:
> + file_logger_handler.setLevel(logging.DEBUG)
> + file_logger_formatter = logging.Formatter(
> + '%(asctime)s [%(filename)s:%(lineno)s - %(funcName)20s()
> ]'
> + ' %(levelname)-8s %(message)s')
> + else:
> + file_logger_handler.setLevel(logging.DEBUG)
> + file_logger_formatter = logging.Formatter(
> + '%(asctime)s [%(filename)s:%(lineno)s - %(funcName)20s()
> ]'
> + ' %(levelname)-8s %(message)s')
> +
> + file_logger_handler.addFilter(ProgressFilter())
> + file_logger_handler.setFormatter(file_logger_formatter)
> + root_logger.addHandler(file_logger_handler)
> +
> + logging.info(PROGRAM_NAME + "\n")
> +
> + substitution_data = {}
> + if args.substitution_file:
> + logging.info(f"Loading substitution file
> {args.substitution_file}")
> + with open(args.substitution_file, 'r') as sf:
> + substitution_data = yaml.safe_load(sf)
> +
> + if args.workspace_directory:
> + return check_macros_in_directory(
> + Path(args.workspace_directory),
> + args.extensions,
> + not args.do_not_ignore_git_ignore_files,
> + not args.do_not_ignore_git_submodules,
> + not args.no_progress_bar,
> + args.utf8w,
> + **substitution_data)
> + else:
> + curr_dir = Path(__file__).parent
> + input_file = Path(args.input_file)
> +
> + rel_path = str(input_file)
> + if input_file.is_relative_to(curr_dir):
> + rel_path = str(input_file.relative_to(curr_dir))
> +
> + logging.info(f"Checking Debug Macros in File: "
> + f"{input_file.resolve()}\n")
> +
> + start_time = timeit.default_timer()
> + failure_cnt = check_macros_in_file(
> + input_file,
> + rel_path,
> + args.utf8w,
> + **substitution_data)[0]
> + end_time = timeit.default_timer() - start_time
> +
> + logging.debug(f"[PERF] The file macro check operation took "
> + f"{end_time:.2f} seconds.")
> +
> + _log_failure_count(failure_cnt, 1)
> +
> + return failure_cnt
> +
> +
> +if __name__ == '__main__':
> + # The exit status value is the number of macro formatting errors
> found.
> + # Therefore, if no macro formatting errors are found, 0 is returned.
> + # Some systems require the return value to be in the range 0-127, so
> + # a lower maximum of 100 is enforced to allow a wide range of
> potential
> + # values with a reasonably large maximum.
> + try:
> +
> sys.exit(max(_module_invocation_check_macros_in_directory_wrapper(),
> + 100))
> + except KeyboardInterrupt:
> + logging.warning("Exiting due to keyboard interrupt.")
> + # Actual formatting errors are only allowed to reach 100.
> + # 101 signals a keyboard interrupt.
> + sys.exit(101)
> + except FileExistsError as e:
> + # 102 signals a file not found error.
> + logging.critical(f"Input file {e.args[0]} does not exist.")
> + sys.exit(102)
> diff --git a/.pytool/Plugin/DebugMacroCheck/Readme.md
> b/.pytool/Plugin/DebugMacroCheck/Readme.md
> new file mode 100644
> index 000000000000..33f1ad9790ed
> --- /dev/null
> +++ b/.pytool/Plugin/DebugMacroCheck/Readme.md
> @@ -0,0 +1,253 @@
> +# Debug Macro Check
> +
> +This Python application scans all files in a build package for debug
> macro formatting issues. It is intended to be a
> +fundamental build-time check that is part of a normal developer build
> process to catch errors right away.
> +
> +As a build plugin, it is capable of finding these errors early in the
> development process after code is initially
> +written to ensure that all code tested is free of debug macro formatting
> errors. These errors often creep into debug
> +prints in error conditions that are not frequently executed making debug
> even more difficult and confusing when they
> +are encountered. In other cases, debug macros with these errors in the
> main code path can lead to unexpected behavior
> +when executed. As a standalone script, it can be easily run manually or
> integrated into other CI processes.
> +
> +The plugin is part of a set of debug macro check scripts meant to be
> relatively portable so they can be applied to
> +additional code bases with minimal effort.
> +
> +## 1. BuildPlugin/DebugMacroCheckBuildPlugin.py
> +
> +This is the build plugin. It is discovered within the Stuart Self-
> Describing Environment (SDE) due to the accompanying
> +file `DebugMacroCheck_plugin_in.yaml`.
> +
> +Since macro errors are considered a coding bug that should be found and
> fixed during the build phase of the developer
> +process (before debug and testing), this plugin is run in pre-build. It
> will run within the scope of the package
> +being compiled. For a platform build, this means it will run against the
> package being built. In a CI build, it will
> +run in pre-build for each package as each package is built.
> +
> +The build plugin has the following attributes:
> +
> + 1. Registered at `global` scope. This means it will always run.
> +
> + 2. Called only on compilable build targets (i.e. does nothing on `"NO-
> TARGET"`).
> +
> + 3. Runs as a pre-build step. This means it gives results right away to
> ensure compilation follows on a clean slate.
> + This also means it runs in platform build and CI. It is run in CI
> as a pre-build step when the `CompilerPlugin`
> + compiles code. This ensures even if the plugin was not run locally,
> all code submissions have been checked.
> +
> + 4. Reports any errors in the build log and fails the build upon error
> making it easy to discover problems.
> +
> + 5. Supports two methods of configuration via "substitution strings":
> +
> + 1. By setting a build variable called `DEBUG_MACRO_CHECK_SUB_FILE`
> with the name of a substitution YAML file to
> + use.
> +
> + **Example:**
> +
> + ```python
> + shell_environment.GetBuildVars().SetValue(
> +
> "DEBUG_MACRO_CHECK_SUB_FILE",
> +
> os.path.join(self.GetWorkspaceRoot(), "DebugMacroCheckSub.yaml"),
> + "Set in CISettings.py")
> + ```
> +
> + **Substitution File Content Example:**
> +
> + ```yaml
> + ---
> + # OvmfPkg/CpuHotplugSmm/ApicId.h
> + # Reason: Substitute with macro value
> + FMT_APIC_ID: 0x%08x
> +
> + # DynamicTablesPkg/Include/ConfigurationManagerObject.h
> + # Reason: Substitute with macro value
> + FMT_CM_OBJECT_ID: 0x%lx
> +
> + # OvmfPkg/IntelTdx/TdTcg2Dxe/TdTcg2Dxe.c
> + # Reason: Acknowledging use of two format specifiers in string
> with one argument
> + # Replace ternary operator in debug string with single
> specifier
> + 'Index == COLUME_SIZE/2 ? " | %02x" : " %02x"': "%d"
> +
> + #
> DynamicTablesPkg/Library/Common/TableHelperLib/ConfigurationManagerObject
> Parser.c
> + # ShellPkg/Library/UefiShellAcpiViewCommandLib/AcpiParser.c
> + # Reason: Acknowledge that string *should* expand to one
> specifier
> + # Replace variable with expected number of specifiers
> (1)
> + Parser[Index].Format: "%d"
> + ```
> +
> + 2. By entering the string substitutions directory into a dictionary
> called `StringSubstitutions` in a
> + `DebugMacroCheck` section of the package CI YAML file.
> +
> + **Example:**
> +
> + ```yaml
> + "DebugMacroCheck": {
> + "StringSubstitutions": {
> + "SUB_A": "%Lx"
> + }
> + }
> + ```
> +
> +### Debug Macro Check Build Plugin: Simple Disable
> +
> +The build plugin can simply be disabled by setting an environment
> variable named `"DISABLE_DEBUG_MACRO_CHECK"`. The
> +plugin is disabled on existence of the variable. The contents of the
> variable are not inspected at this time.
> +
> +## 2. DebugMacroCheck.py
> +
> +This is the main Python module containing the implementation logic. The
> build plugin simply wraps around it.
> +
> +When first running debug macro check against a new, large code base, it
> is recommended to first run this standalone
> +script and address all of the issues and then enable the build plugin.
> +
> +The module supports a number of configuration parameters to ease debug
> of errors and to provide flexibility for
> +different build environments.
> +
> +### EDK 2 PyTool Library Dependency
> +
> +This script has minimal library dependencies. However, it has one
> dependency you might not be familiar with on the
> +Tianocore EDK 2 PyTool Library (edk2toollib):
> +
> +```py
> +from edk2toollib.utility_functions import RunCmd
> +```
> +
> +You simply need to install the following pip module to use this library:
> `edk2-pytool-library`
> +(e.g. `pip install edk2-pytool-library`)
> +
> +More information is available here:
> +
> +- PyPI page: [edk2-pytool-library](https://pypi.org/project/edk2-pytool-
> library/)
> +- GitHub repo: [tianocore/edk2-pytool-
> library](https://github.com/tianocore/edk2-pytool-library)
> +
> +If you strongly prefer not including this additional dependency, the
> functionality imported here is relatively
> +simple to substitute with the Python
> [`subprocess`](https://docs.python.org/3/library/subprocess.html) built-
> in
> +module.
> +
> +### Examples
> +
> +Simple run against current directory:
> +
> +`> python DebugMacroCheck.py -w .`
> +
> +Simple run against a single file:
> +
> +`> python DebugMacroCheck.py -i filename.c`
> +
> +Run against a directory with output placed into a file called
> "debug_macro_check.log":
> +
> +`> python DebugMacroCheck.py -w . -l`
> +
> +Run against a directory with output placed into a file called
> "custom.log" and debug log messages enabled:
> +
> +`> python DebugMacroCheck.py -w . -l custom.log -v`
> +
> +Run against a directory with output placed into a file called
> "custom.log", with debug log messages enabled including
> +python script function and line number, use a substitution file called
> "file_sub.yaml", do not show the progress bar,
> +and run against .c and .h files:
> +
> +`> python DebugMacroCheck.py -w . -l custom.log -vv -s file_sub.yaml -n
> -e .c .h`
> +
> +> **Note**: It is normally not recommended to run against .h files as
> they and many other non-.c files normally do
> + not have full `DEBUG` macro prints.
> +
> +```plaintext
> +usage: Debug Macro Checker [-h] (-w WORKSPACE_DIRECTORY | -i
> [INPUT_FILE]) [-l [LOG_FILE]] [-s SUBSTITUTION_FILE] [-v] [-n] [-q] [-u]
> + [-df] [-ds] [-e [EXTENSIONS ...]]
> +
> +Checks for debug macro formatting errors within files recursively
> located within a given directory.
> +
> +options:
> + -h, --help show this help message and exit
> + -w WORKSPACE_DIRECTORY, --workspace-directory WORKSPACE_DIRECTORY
> + Directory of source files to check.
> +
> + -i [INPUT_FILE], --input-file [INPUT_FILE]
> + File path for an input file to check.
> +
> + Note that some other options do not apply if a
> single file is specified such as the
> + git options and file extensions.
> +
> + -e [EXTENSIONS ...], --extensions [EXTENSIONS ...]
> + List of file extensions to include.
> + (default: ['.c'])
> +
> +Optional input and output:
> + -l [LOG_FILE], --log-file [LOG_FILE]
> + File path for log output.
> + (default: if the flag is given with no file path
> then a file called
> + debug_macro_check.log is created and used in the
> current directory)
> +
> + -s SUBSTITUTION_FILE, --substitution-file SUBSTITUTION_FILE
> + A substitution YAML file specifies string
> substitutions to perform within the debug macro.
> +
> + This is intended to be a simple mechanism to
> expand the rare cases of pre-processor
> + macros without directly involving the pre-
> processor. The file consists of one or more
> + string value pairs where the key is the
> identifier to replace and the value is the value
> + to replace it with.
> +
> + This can also be used as a method to ignore
> results by replacing the problematic string
> + with a different string.
> +
> + -v, --verbose-log-file
> + Set file logging verbosity level.
> + - None: Info & > level messages
> + - '-v': + Debug level messages
> + - '-vv': + File name and function
> + - '-vvv': + Line number
> + - '-vvvv': + Timestamp
> + (default: verbose logging is not enabled)
> +
> + -n, --no-progress-bar
> + Disables progress bars.
> + (default: progress bars are used in some places
> to show progress)
> +
> + -q, --quiet Disables console output.
> + (default: console output is enabled)
> +
> + -u, --utf8w Shows warnings for file UTF-8 decode errors.
> + (default: UTF-8 decode errors are not shown)
> +
> +
> +Optional git control:
> + -df, --do-not-ignore-git-ignore-files
> + Do not ignore git ignored files.
> + (default: files in git ignore files are ignored)
> +
> + -ds, --do-not-ignore-git_submodules
> + Do not ignore files in git submodules.
> + (default: files in git submodules are ignored)
> +```
> +
> +## String Substitutions
> +
> +`DebugMacroCheck` currently runs separate from the compiler toolchain.
> This has the advantage that it is very portable
> +and can run early in the build process, but it also means pre-processor
> macro expansion does not happen when it is
> +invoked.
> +
> +In practice, it has been very rare that this is an issue for how most
> debug macros are written. In case it is, a
> +substitution file can be used to inform `DebugMacroCheck` about the
> string substitution the pre-processor would
> +perform.
> +
> +This pattern should be taken as a warning. It is just as difficult for
> humans to keep debug macro specifiers and
> +arguments balanced as it is for `DebugMacroCheck` pre-processor macro
> substitution is used. By separating the string
> +from the actual arguments provided, it is more likely for developers to
> make mistakes matching print specifiers in
> +the string to the arguments. If usage is reasonable, a string
> substitution can be used as needed.
> +
> +### Ignoring Errors
> +
> +Since substitution files perform a straight textual substitution in
> macros discovered, it can be used to replace
> +problematic text with text that passes allowing errors to be ignored.
> +
> +## Python Version Required (3.10)
> +
> +This script is written to take advantage of new Python language features
> in Python 3.10. If you are not using Python
> +3.10 or later, you can:
> +
> + 1. Upgrade to Python 3.10 or greater
> + 2. Run this script in a [virtual
> environment](https://docs.python.org/3/tutorial/venv.html) with Python
> 3.10
> + or greater
> + 3. Customize the script for compatibility with your Python version
> +
> +These are listed in order of recommendation. **(1)** is the simplest
> option and will upgrade your environment to a
> +newer, safer, and better Python experience. **(2)** is the simplest
> approach to isolate dependencies to what is needed
> +to run this script without impacting the rest of your system
> environment. **(3)** creates a one-off fork of the script
> +that, by nature, has a limited lifespan and will make accepting future
> updates difficult but can be done with relatively
> +minimal effort back to recent Python 3 releases.
> diff --git a/.pytool/Plugin/DebugMacroCheck/tests/DebugMacroDataSet.py
> b/.pytool/Plugin/DebugMacroCheck/tests/DebugMacroDataSet.py
> new file mode 100644
> index 000000000000..98629bb23333
> --- /dev/null
> +++ b/.pytool/Plugin/DebugMacroCheck/tests/DebugMacroDataSet.py
> @@ -0,0 +1,674 @@
> +# @file DebugMacroDataSet.py
> +#
> +# Contains a debug macro test data set for verifying debug macros are
> +# recognized and parsed properly.
> +#
> +# This data is automatically converted into test cases. Just add the new
> +# data object here and run the tests.
> +#
> +# Copyright (c) Microsoft Corporation. All rights reserved.
> +# SPDX-License-Identifier: BSD-2-Clause-Patent
> +##
> +
> +from .MacroTest import (NoSpecifierNoArgumentMacroTest,
> + EqualSpecifierEqualArgumentMacroTest,
> + MoreSpecifiersThanArgumentsMacroTest,
> + LessSpecifiersThanArgumentsMacroTest,
> + IgnoredSpecifiersMacroTest,
> + SpecialParsingMacroTest,
> + CodeSnippetMacroTest)
> +
> +
> +# Ignore flake8 linter errors for lines that are too long (E501)
> +# flake8: noqa: E501
> +
> +# Data Set of DEBUG macros and expected results.
> +# macro: A string representing a DEBUG macro.
> +# result: A tuple with the following value representations.
> +# [0]: Count of total formatting errors
> +# [1]: Count of print specifiers found
> +# [2]: Count of macro arguments found
> +DEBUG_MACROS = [
> +
> #####################################################################
> + # Section: No Print Specifiers No Arguments
> +
> #####################################################################
> + NoSpecifierNoArgumentMacroTest(
> + r'',
> + (0, 0, 0)
> + ),
> + NoSpecifierNoArgumentMacroTest(
> + r'DEBUG ((DEBUG_ERROR, "\\"));',
> + (0, 0, 0)
> + ),
> + NoSpecifierNoArgumentMacroTest(
> + r'DEBUG ((DEBUG_EVENT, ""));',
> + (0, 0, 0)
> + ),
> + NoSpecifierNoArgumentMacroTest(
> + r'DEBUG ((DEBUG_EVENT, "\n"));',
> + (0, 0, 0)
> + ),
> + NoSpecifierNoArgumentMacroTest(
> + r'DEBUG ((DEBUG_EVENT, "\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n\n"));',
> + (0, 0, 0)
> + ),
> + NoSpecifierNoArgumentMacroTest(
> + r'DEBUG ((DEBUG_EVENT, "GCD:Initial GCD Memory Space Map\n"));',
> + (0, 0, 0)
> + ),
> + NoSpecifierNoArgumentMacroTest(
> + r'DEBUG ((DEBUG_GCD, "GCD:Initial GCD Memory Space Map\n"));',
> + (0, 0, 0)
> + ),
> + NoSpecifierNoArgumentMacroTest(
> + r'DEBUG ((DEBUG_INFO, " Retuning TimerCnt Disabled\n"));',
> + (0, 0, 0)
> + ),
> +
> +
> #####################################################################
> + # Section: Equal Print Specifiers to Arguments
> +
> #####################################################################
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_INFO, "%d", Number));',
> + (0, 1, 1)
> + ),
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_BLKIO, "NorFlashBlockIoReset(MediaId=0x%x)\n",
> This->Media->MediaId));',
> + (0, 1, 1)
> + ),
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_INFO, " Retuning TimerCnt %dseconds\n", 2 *
> (Capability->TimerCount - 1)));',
> + (0, 1, 1)
> + ),
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_ERROR, "UsbEnumerateNewDev: failed to reset port
> %d - %r\n", Port, Status));',
> + (0, 2, 2)
> + ),
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_ERROR, "UsbEnumerateNewDev: failed to reset port
> %d - %r\n", Port, Status));',
> + (0, 2, 2)
> + ),
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_INFO, "Find GPT Partition [0x%lx",
> PartitionEntryBuffer[Index].StartingLBA));',
> + (0, 1, 1)
> + ),
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_ERROR, "Failed to locate
> gEdkiiBootLogo2ProtocolGuid Status = %r. No Progress bar support. \n",
> Status));',
> + (0, 1, 1)
> + ),
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_LOAD, " (%s)", Image->ExitData));',
> + (0, 1, 1)
> + ),
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_DISPATCH, "%a%r%s%lx%p%c%g", Ascii, Status,
> Unicode, Hex, Pointer, Character, Guid));',
> + (0, 7, 7)
> + ),
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_INFO, "LoadCapsuleOnDisk - LoadRecoveryCapsule
> (%d) - %r\n", CapsuleInstance, Status));',
> + (0, 2, 2)
> + ),
> + EqualSpecifierEqualArgumentMacroTest(
> + r'DEBUG ((DEBUG_DISPATCH,
> "%a%r%s%lx%p%c%g%a%r%s%lx%p%c%g%a%r%s%lx%p%c%g%a%r%s%lx%p%c%g", Ascii,
> Status, Unicode, Hex, Pointer, Character, Guid, Ascii, Status, Unicode,
> Hex, Pointer, Character, Guid, Ascii, Status, Unicode, Hex, Pointer,
> Character, Guid, Ascii, Status, Unicode, Hex, Pointer, Character,
> Guid));',
> + (0, 28, 28)
> + ),
> +
> +
> #####################################################################
> + # Section: More Print Specifiers Than Arguments
> +
> #####################################################################
> + MoreSpecifiersThanArgumentsMacroTest(
> + r'DEBUG ((DEBUG_BLKIO, "NorFlashBlockIoReadBlocks(MediaId=0x%x,
> Lba=%ld, BufferSize=0x%x bytes (%d kB), BufferPtr @ 0x%08x)\n", MediaId,
> Lba, BufferSizeInBytes, Buffer));',
> + (1, 5, 4)
> + ),
> + MoreSpecifiersThanArgumentsMacroTest(
> + r'DEBUG ((DEBUG_INFO, "%a: Request=%s\n", __func__));',
> + (1, 2, 1)
> + ),
> + MoreSpecifiersThanArgumentsMacroTest(
> + r'DEBUG ((DEBUG_ERROR, "%a: Invalid request format %d for %d\n",
> CertFormat, CertRequest));',
> + (1, 3, 2)
> + ),
> +
> +
> #####################################################################
> + # Section: Less Print Specifiers Than Arguments
> +
> #####################################################################
> + LessSpecifiersThanArgumentsMacroTest(
> + r'DEBUG ((DEBUG_INFO, "Find GPT Partition [0x%lx",
> PartitionEntryBuffer[Index].StartingLBA, BlockDevPtr->LastBlock));',
> + (1, 1, 2)
> + ),
> + LessSpecifiersThanArgumentsMacroTest(
> + r'DEBUG ((DEBUG_INFO, " Retuning TimerCnt Disabled\n", 2 *
> (Capability->TimerCount - 1)));',
> + (1, 0, 1)
> + ),
> + LessSpecifiersThanArgumentsMacroTest(
> + r'DEBUG ((DEBUG_ERROR, "Failed to locate
> gEdkiiBootLogo2ProtocolGuid. No Progress bar support. \n", Status));',
> + (1, 0, 1)
> + ),
> + LessSpecifiersThanArgumentsMacroTest(
> + r'DEBUG ((DEBUG_ERROR, "UsbEnumeratePort: Critical Over
> Current\n", Port));',
> + (1, 0, 1)
> + ),
> + LessSpecifiersThanArgumentsMacroTest(
> + r'DEBUG ((DEBUG_ERROR, "[TPM2] Submit PP Request failure! Sync
> PPRQ/PPRM with PP variable.\n", Status));',
> + (1, 0, 1)
> + ),
> + LessSpecifiersThanArgumentsMacroTest(
> + r'DEBUG ((DEBUG_ERROR, ": Failed to update debug log index file:
> %r !\n", __func__, Status));',
> + (1, 1, 2)
> + ),
> + LessSpecifiersThanArgumentsMacroTest(
> + r'DEBUG ((DEBUG_ERROR, "%a - Failed to extract nonce from policy
> blob with return status %r\n", __func__,
> gPolicyBlobFieldName[MFCI_POLICY_TARGET_NONCE], Status));',
> + (1, 2, 3)
> + ),
> +
> +
> #####################################################################
> + # Section: Macros with Ignored Specifiers
> +
> #####################################################################
> + IgnoredSpecifiersMacroTest(
> + r'DEBUG ((DEBUG_INIT, "%HEmuOpenBlock: opened %a%N\n", Private-
> >Filename));',
> + (0, 1, 1)
> + ),
> + IgnoredSpecifiersMacroTest(
> + r'DEBUG ((DEBUG_LOAD, " (%hs)", Image->ExitData));',
> + (0, 1, 1)
> + ),
> + IgnoredSpecifiersMacroTest(
> + r'DEBUG ((DEBUG_LOAD, "%H%s%N: Unknown flag - ''%H%s%N''\r\n",
> String1, String2));',
> + (0, 2, 2)
> + ),
> +
> +
> #####################################################################
> + # Section: Macros with Special Parsing Scenarios
> +
> #####################################################################
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_INFO, " File Name: %a\n", "Document.txt"))',
> + (0, 1, 1),
> + "Malformatted Macro - Missing Semicolon"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG (DEBUG_INFO, " File Name: %a\n", "Document.txt");',
> + (0, 0, 0),
> + "Malformatted Macro - Missing Two Parentheses"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_INFO, "%a\n", "Removable Slot"));',
> + (0, 1, 1),
> + "Single String Argument in Quotes"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_INFO, " SDR50 Tuning %a\n", Capability-
> >TuningSDR50 ? "TRUE" : "FALSE"));',
> + (0, 1, 1),
> + "Ternary Operator Present"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_INFO, " SDR50 Tuning %a\n", Capability-
> >TuningSDR50 ? "TRUE" : "FALSE"));',
> + (0, 1, 1),
> + "Ternary Operator Present"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((DEBUG_ERROR, "\\"));
> + DEBUG ((DEBUG_ERROR, "\\"));
> + DEBUG ((DEBUG_ERROR, "\\"));
> + DEBUG ((DEBUG_ERROR, "\\"));
> + ''',
> + (0, 0, 0),
> + "Multiple Macros with an Escaped Character"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_INFO,
> + "UsbEnumerateNewDev: device uses translator (%d, %d)\n",
> + Child->Translator.TranslatorHubAddress,
> + Child->Translator.TranslatorPortNumber
> + ));
> + ''',
> + (0, 2, 2),
> + "Multi-line Macro"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_INFO,
> + "UsbEnumeratePort: port %d state - %02x, change - %02x on
> %p\n",
> + Port,
> + PortState.PortStatus,
> + PortState.PortChangeStatus,
> + HubIf
> + ));
> + ''',
> + (0, 4, 4),
> + "Multi-line Macro"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_ERROR,
> + "%a:%a: failed to allocate reserved pages: "
> + "BufferSize=%Lu LoadFile=\"%s\" FilePath=\"%s\"\n",
> + gEfiCallerBaseName,
> + __func__,
> + (UINT64)BufferSize,
> + LoadFileText,
> + FileText
> + ));
> + ''',
> + (0, 5, 5),
> + "Multi-line Macro with Compiler String Concatenation"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_ERROR,
> + "ERROR: GTDT: GT Block Frame Info Structures %d and %d have
> the same " \
> + "frame number: 0x%x.\n",
> + Index1,
> + Index2,
> + FrameNumber1
> + ));
> + ''',
> + (0, 3, 3),
> + "Multi-line Macro with Backslash String Concatenation"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_ERROR,
> + "ERROR: PPTT: Too many private resources. Count = %d. " \
> + "Maximum supported Processor Node size exceeded. " \
> + "Token = %p. Status = %r\n",
> + ProcInfoNode->NoOfPrivateResources,
> + ProcInfoNode->ParentToken,
> + Status
> + ));
> + ''',
> + (0, 3, 3),
> + "Multi-line Macro with Backslash String Concatenation"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_VERBOSE,
> + "% 20a % 20a % 20a % 20a\n",
> + "PhysicalStart(0x)",
> + "PhysicalSize(0x)",
> + "CpuStart(0x)",
> + "RegionState(0x)"
> + ));
> + ''',
> + (0, 4, 4),
> + "Multi-line Macro with Quoted String Arguments"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_ERROR,
> + "XenPvBlk: "
> + "%a error %d on %a at sector %Lx, num bytes %Lx\n",
> + Response->operation == BLKIF_OP_READ ? "read" : "write",
> + Status,
> + IoData->Dev->NodeName,
> + (UINT64)IoData->Sector,
> + (UINT64)IoData->Size
> + ));
> + ''',
> + (0, 5, 5),
> + "Multi-line Macro with Ternary Operator and Quoted String
> Arguments"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_ERROR,
> + "%a: Label=\"%s\" OldParentNodeId=%Lu OldName=\"%a\" "
> + "NewParentNodeId=%Lu NewName=\"%a\" Errno=%d\n",
> + __func__,
> + VirtioFs->Label,
> + OldParentNodeId,
> + OldName,
> + NewParentNodeId,
> + NewName,
> + CommonResp.Error
> + ));
> + ''',
> + (0, 7, 7),
> + "Multi-line Macro with Escaped Quotes and String Concatenation"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((DEBUG_WARN, "Failed to retrieve Variable:\"MebxData\",
> Status = %r\n", Status));
> + ''',
> + (0, 1, 1),
> + "Escaped Parentheses in Debug Message"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG((DEBUG_INFO, "%0d %s", XbB_ddr4[1][bankBit][xorBit],
> xorBit == (XaB_NUM_OF_BITS-1) ? "]": ", "));
> + ''',
> + (0, 2, 2),
> + "Parentheses in Ternary Operator Expression"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_INFO | DEBUG_EVENT | DEBUG_WARN, " %u\n",
> &Structure->Block.Value));',
> + (0, 1, 1),
> + "Multiple Print Specifier Levels Present"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s\n", ReturnString()));',
> + (0, 1, 1),
> + "Function Call Argument No Params"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s\n", ReturnString(&Param1)));',
> + (0, 1, 1),
> + "Function Call Argument 1 Param"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s\n", ReturnString(&Param1,
> Param2)));',
> + (0, 1, 1),
> + "Function Call Argument Multiple Params"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s\n", ReturnString(&Param1,
> ReturnParam())));',
> + (0, 1, 1),
> + "Function Call Argument 2-Level Depth No 2nd-Level Param"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s\n", ReturnString(&Param1,
> ReturnParam(*Param))));',
> + (0, 1, 1),
> + "Function Call Argument 2-Level Depth 1 2nd-Level Param"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s\n", ReturnString(&Param1,
> ReturnParam(*Param, &ParamNext))));',
> + (0, 1, 1),
> + "Function Call Argument 2-Level Depth Multiple 2nd-Level Param"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s\n", ReturnString(&Param1,
> ReturnParam(*Param, GetParam(1, 2, 3)))));',
> + (0, 1, 1),
> + "Function Call Argument 3-Level Depth Multiple Params"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s\n", ReturnString(&Param1,
> ReturnParam(*Param, GetParam(1, 2, 3), NextParam))));',
> + (0, 1, 1),
> + "Function Call Argument 3-Level Depth Multiple Params with Param
> After Function Call"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s-%a\n", ReturnString(&Param1),
> ReturnString2(&ParamN)));',
> + (0, 2, 2),
> + "Multiple Function Call Arguments"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s\n", ReturnString(&Param1),
> ReturnString2(&ParamN)));',
> + (1, 1, 2),
> + "Multiple Function Call Arguments with Imbalance"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s%s\n", (ReturnString(&Param1)),
> (ReturnString2(&ParamN))));',
> + (0, 2, 2),
> + "Multiple Function Call Arguments Surrounded with Parentheses"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, " %s\n",
> ((((ReturnString(&Param1)))))));',
> + (0, 1, 1),
> + "Multiple Function Call Arguments Surrounded with Many
> Parentheses"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, ""%B%08X%N: %-48a %V*%a*%N"", HexNumber,
> ReturnString(Array[Index]), &AsciiString[0]));',
> + (0, 3, 3),
> + "Complex String Print Specifier 1"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, "0x%-8x:%H%s%N % -64s(%73-.73s){%g}<%H% -
> 70s%N>\n. Size: 0x%-16x (%-,d) bytes.\n\n", HexNumber, GetUnicodeString
> (), &UnicodeString[4], UnicodeString2, &Guid, AnotherUnicodeString,
> Struct.SomeSize, CommaDecimalValue));',
> + (0, 8, 8),
> + "Multiple Complex Print Specifiers 1"
> + ),
> + SpecialParsingMacroTest(
> + r'DEBUG ((DEBUG_WARN, "0x%-8x:%H%s%N % -64s(%73-.73s){%g}<%H% -
> 70s%N%r>\n. Size: 0x%-16x (%-,d) bytes.\n\n", HexNumber,
> GetUnicodeString (), &UnicodeString[4], UnicodeString2, &Guid,
> AnotherUnicodeString, Struct.SomeSize, CommaDecimalValue));',
> + (1, 9, 8),
> + "Multiple Complex Print Specifiers Imbalance 1"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_ERROR,
> + ("%a: Label=\"%s\" CanonicalPathname=\"%a\" FileName=\"%s\" "
> + "OpenMode=0x%Lx Attributes=0x%Lx: nonsensical request to
> possibly "
> + "create a file marked read-only, for read-write access\n"),
> + __func__,
> + VirtioFs->Label,
> + VirtioFsFile->CanonicalPathname,
> + FileName,
> + OpenMode,
> + Attributes
> + ));
> + ''',
> + (0, 6, 6),
> + "Multi-Line with Parentheses Around Debug String Compiler String
> Concat"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG (
> + (DEBUG_INFO,
> + " %02x: %04x %02x/%02x/%02x %02x/%02x %04x %04x %04x:%04x\n",
> + (UINTN)Index,
> + (UINTN)LocalBbsTable[Index].BootPriority,
> + (UINTN)LocalBbsTable[Index].Bus,
> + (UINTN)LocalBbsTable[Index].Device,
> + (UINTN)LocalBbsTable[Index].Function,
> + (UINTN)LocalBbsTable[Index].Class,
> + (UINTN)LocalBbsTable[Index].SubClass,
> + (UINTN)LocalBbsTable[Index].DeviceType,
> + (UINTN)*(UINT16 *)&LocalBbsTable[Index].StatusFlags,
> + (UINTN)LocalBbsTable[Index].BootHandlerSegment,
> + (UINTN)LocalBbsTable[Index].BootHandlerOffset,
> + (UINTN)((LocalBbsTable[Index].MfgStringSegment << 4) +
> LocalBbsTable[Index].MfgStringOffset),
> + (UINTN)((LocalBbsTable[Index].DescStringSegment << 4) +
> LocalBbsTable[Index].DescStringOffset))
> + );
> + ''',
> + (1, 11, 13),
> + "Multi-line Macro with Many Arguments And Multi-Line
> Parentheses"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_WARN,
> + "0x%-8x:%H%s%N % -64s(%73-.73s){%g}<%H% -70s%N>\n. Size:
> 0x%-16x (%-,d) bytes.\n\n",
> + HexNumber,
> + GetUnicodeString (InnerFunctionCall(Arg1, &Arg2)),
> + &UnicodeString[4],
> + UnicodeString2,
> + &Guid,
> + AnotherUnicodeString,
> + Struct.SomeSize,
> + CommaDecimalValue
> + ));
> + ''',
> + (0, 8, 8),
> + "Multi-line Macro with Multiple Complex Print Specifiers 1 and
> 2-Depth Function Calls"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG (
> + (DEBUG_NET,
> + "TcpFastRecover: enter fast retransmission for TCB %p, recover
> point is %d\n",
> + Tcb,
> + Tcb->Recover)
> + );
> + ''',
> + (0, 2, 2),
> + "Multi-line Macro with Parentheses Separated"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_VERBOSE,
> + "%a: APIC ID " FMT_APIC_ID " was hot-plugged "
> + "before; ignoring it\n",
> + __func__,
> + NewApicId
> + ));
> + ''',
> + (1, 1, 2),
> + "Multi-line Imbalanced Macro with Indented String Concatenation"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_VERBOSE,
> + "%a: APIC ID was hot-plugged - %a",
> + __func__,
> + "String with , inside"
> + ));
> + ''',
> + (0, 2, 2),
> + "Multi-line with Quoted String Argument Containing Comma"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_VERBOSE,
> + "%a: APIC ID was hot-plugged - %a",
> + __func__,
> + "St,ring, with , ins,ide"
> + ));
> + ''',
> + (0, 2, 2),
> + "Multi-line with Quoted String Argument Containing Multiple
> Commas"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((DEBUG_VERBOSE, "%a: APIC ID was hot-plugged, \"%a\"",
> __func__, "S\"t,\"ring, with , ins,i\"de"));
> + ''',
> + (0, 2, 2),
> + "Quoted String Argument with Escaped Quotes and Multiple Commas"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_ERROR,
> + "%a: AddProcessor(" FMT_APIC_ID "): %r\n",
> + __func__,
> + Status
> + ));
> + ''',
> + (0, 2, 2),
> + "Quoted Parenthesized String Inside Debug Message String"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((
> + DEBUG_INFO,
> + "%a: hot-added APIC ID " FMT_APIC_ID ", SMBASE 0x%Lx, "
> +
> "EFI_SMM_CPU_SERVICE_PROTOCOL assigned number %Lu\n",
> + __func__,
> + (UINT64)mCpuHotPlugData->SmBase[NewSlot],
> + (UINT64)NewProcessorNumberByProtocol
> + ));
> + ''',
> + (0, 3, 3),
> + "Quoted String with Concatenation Inside Debug Message String"
> + ),
> + SpecialParsingMacroTest(
> + r'''
> + DEBUG ((DEBUG_INFO, Index == COLUMN_SIZE/2 ? "0" : " %02x",
> (UINTN)Data[Index]));
> + ''',
> + (0, 1, 1),
> + "Ternary Operating in Debug Message String"
> + ),
> +
> +
> #####################################################################
> + # Section: Code Snippet Tests
> +
> #####################################################################
> + CodeSnippetMacroTest(
> + r'''
> + /**
> + Print the BBS Table.
> +
> + @param LocalBbsTable The BBS table.
> + @param BbsCount The count of entry in BBS table.
> + **/
> + VOID
> + LegacyBmPrintBbsTable (
> + IN BBS_TABLE *LocalBbsTable,
> + IN UINT16 BbsCount
> + )
> + {
> + UINT16 Index;
> +
> + DEBUG ((DEBUG_INFO, "\n"));
> + DEBUG ((DEBUG_INFO, " NO Prio bb/dd/ff cl/sc Type Stat
> segm:offs\n"));
> + DEBUG ((DEBUG_INFO,
> "=============================================\n"));
> + for (Index = 0; Index < BbsCount; Index++) {
> + if (!LegacyBmValidBbsEntry (&LocalBbsTable[Index])) {
> + continue;
> + }
> +
> + DEBUG (
> + (DEBUG_INFO,
> + " %02x: %04x %02x/%02x/%02x %02x/%02x %04x %04x
> %04x:%04x\n",
> + (UINTN)Index,
> + (UINTN)LocalBbsTable[Index].BootPriority,
> + (UINTN)LocalBbsTable[Index].Bus,
> + (UINTN)LocalBbsTable[Index].Device,
> + (UINTN)LocalBbsTable[Index].Function,
> + (UINTN)LocalBbsTable[Index].Class,
> + (UINTN)LocalBbsTable[Index].SubClass,
> + (UINTN)LocalBbsTable[Index].DeviceType,
> + (UINTN)*(UINT16 *)&LocalBbsTable[Index].StatusFlags,
> + (UINTN)LocalBbsTable[Index].BootHandlerSegment,
> + (UINTN)LocalBbsTable[Index].BootHandlerOffset,
> + (UINTN)((LocalBbsTable[Index].MfgStringSegment << 4) +
> LocalBbsTable[Index].MfgStringOffset),
> + (UINTN)((LocalBbsTable[Index].DescStringSegment << 4) +
> LocalBbsTable[Index].DescStringOffset))
> + );
> + }
> +
> + DEBUG ((DEBUG_INFO, "\n"));
> + ''',
> + (1, 0, 0),
> + "Code Section with An Imbalanced Macro"
> + ),
> + CodeSnippetMacroTest(
> + r'''
> + if (*Buffer == AML_ROOT_CHAR) {
> + //
> + // RootChar
> + //
> + Buffer++;
> + DEBUG ((DEBUG_ERROR, "\\"));
> + } else if (*Buffer == AML_PARENT_PREFIX_CHAR) {
> + //
> + // ParentPrefixChar
> + //
> + do {
> + Buffer++;
> + DEBUG ((DEBUG_ERROR, "^"));
> + } while (*Buffer == AML_PARENT_PREFIX_CHAR);
> + }
> + DEBUG ((DEBUG_WARN, "Failed to retrieve Variable:\"MebxData\",
> Status = %r\n", Status));
> + ''',
> + (0, 1, 1),
> + "Code Section with Escaped Backslash and Escaped Quotes"
> + ),
> + CodeSnippetMacroTest(
> + r'''
> + if (EFI_ERROR (Status)) {
> + UINTN Offset;
> + UINTN Start;
> +
> + DEBUG ((
> + DEBUG_INFO,
> + "Variable FV header is not valid. It will be
> reinitialized.\n"
> + ));
> +
> + //
> + // Get FvbInfo to provide in FwhInstance.
> + //
> + Status = GetFvbInfo (Length, &GoodFwVolHeader);
> + ASSERT (!EFI_ERROR (Status));
> + }
> + ''',
> + (0, 0, 0),
> + "Code Section with Multi-Line Macro with No Arguments"
> + )
> +]
> diff --git a/.pytool/Plugin/DebugMacroCheck/tests/MacroTest.py
> b/.pytool/Plugin/DebugMacroCheck/tests/MacroTest.py
> new file mode 100644
> index 000000000000..3b966d31ffaa
> --- /dev/null
> +++ b/.pytool/Plugin/DebugMacroCheck/tests/MacroTest.py
> @@ -0,0 +1,131 @@
> +# @file MacroTest.py
> +#
> +# Contains the data classes that are used to compose debug macro tests.
> +#
> +# All data classes inherit from a single abstract base class that
> expects
> +# the subclass to define the category of test it represents.
> +#
> +# Copyright (c) Microsoft Corporation. All rights reserved.
> +# SPDX-License-Identifier: BSD-2-Clause-Patent
> +##
> +
> +from dataclasses import dataclass, field
> +from os import linesep
> +from typing import Tuple
> +
> +import abc
> +
> +
> +@dataclass(frozen=True)
> +class MacroTest(abc.ABC):
> + """Abstract base class for an individual macro test case."""
> +
> + macro: str
> + result: Tuple[int, int, int]
> + description: str = field(default='')
> +
> + @property
> + @abc.abstractmethod
> + def category(self) -> str:
> + """Returns the test class category identifier.
> +
> + Example: 'equal_specifier_equal_argument_macro_test'
> +
> + This string is used to bind test objects against this class.
> +
> + Returns:
> + str: Test category identifier string.
> + """
> + pass
> +
> + @property
> + def category_description(self) -> str:
> + """Returns the test class category description.
> +
> + Example: 'Test case with equal count of print specifiers to
> arguments.'
> +
> + This string is a human readable description of the test
> category.
> +
> + Returns:
> + str: String describing the test category.
> + """
> + return self.__doc__
> +
> + def __str__(self):
> + """Returns a macro test case description string."""
> +
> + s = [
> + f"{linesep}",
> + "=" * 80,
> + f"Macro Test Type: {self.category_description}",
> + f"{linesep}Macro: {self.macro}",
> + f"{linesep}Expected Result: {self.result}"
> + ]
> +
> + if self.description:
> + s.insert(3, f"Test Description: {self.description}")
> +
> + return f'{linesep}'.join(s)
> +
> +
> +@dataclass(frozen=True)
> +class NoSpecifierNoArgumentMacroTest(MacroTest):
> + """Test case with no print specifier and no arguments."""
> +
> + @property
> + def category(self) -> str:
> + return "no_specifier_no_argument_macro_test"
> +
> +
> +@dataclass(frozen=True)
> +class EqualSpecifierEqualArgumentMacroTest(MacroTest):
> + """Test case with equal count of print specifiers to arguments."""
> +
> + @property
> + def category(self) -> str:
> + return "equal_specifier_equal_argument_macro_test"
> +
> +
> +@dataclass(frozen=True)
> +class MoreSpecifiersThanArgumentsMacroTest(MacroTest):
> + """Test case with more print specifiers than arguments."""
> +
> + @property
> + def category(self) -> str:
> + return "more_specifiers_than_arguments_macro_test"
> +
> +
> +@dataclass(frozen=True)
> +class LessSpecifiersThanArgumentsMacroTest(MacroTest):
> + """Test case with less print specifiers than arguments."""
> +
> + @property
> + def category(self) -> str:
> + return "less_specifiers_than_arguments_macro_test"
> +
> +
> +@dataclass(frozen=True)
> +class IgnoredSpecifiersMacroTest(MacroTest):
> + """Test case to test ignored print specifiers."""
> +
> + @property
> + def category(self) -> str:
> + return "ignored_specifiers_macro_test"
> +
> +
> +@dataclass(frozen=True)
> +class SpecialParsingMacroTest(MacroTest):
> + """Test case with special (complicated) parsing scenarios."""
> +
> + @property
> + def category(self) -> str:
> + return "special_parsing_macro_test"
> +
> +
> +@dataclass(frozen=True)
> +class CodeSnippetMacroTest(MacroTest):
> + """Test case within a larger code snippet."""
> +
> + @property
> + def category(self) -> str:
> + return "code_snippet_macro_test"
> diff --git a/.pytool/Plugin/DebugMacroCheck/tests/__init__.py
> b/.pytool/Plugin/DebugMacroCheck/tests/__init__.py
> new file mode 100644
> index 000000000000..e69de29bb2d1
> diff --git a/.pytool/Plugin/DebugMacroCheck/tests/test_DebugMacroCheck.py
> b/.pytool/Plugin/DebugMacroCheck/tests/test_DebugMacroCheck.py
> new file mode 100644
> index 000000000000..db51d23e03d3
> --- /dev/null
> +++ b/.pytool/Plugin/DebugMacroCheck/tests/test_DebugMacroCheck.py
> @@ -0,0 +1,201 @@
> +# @file test_DebugMacroCheck.py
> +#
> +# Contains unit tests for the DebugMacroCheck build plugin.
> +#
> +# An example of running these tests from the root of the workspace:
> +# python -m unittest discover -s
> ./.pytool/Plugin/DebugMacroCheck/tests -v
> +#
> +# Copyright (c) Microsoft Corporation. All rights reserved.
> +# SPDX-License-Identifier: BSD-2-Clause-Patent
> +##
> +
> +import inspect
> +import pathlib
> +import sys
> +import unittest
> +
> +# Import the build plugin
> +test_file = pathlib.Path(__file__)
> +sys.path.append(str(test_file.parent.parent))
> +
> +# flake8 (E402): Ignore flake8 module level import not at top of file
> +import DebugMacroCheck # noqa: E402
> +
> +from os import linesep # noqa: E402
> +from tests import DebugMacroDataSet # noqa: E402
> +from tests import MacroTest # noqa: E402
> +from typing import Callable, Tuple # noqa: E402
> +
> +
> +#
> +# This metaclass is provided to dynamically produce test case container
> +# classes. The main purpose of this approach is to:
> +# 1. Allow categories of test cases to be defined (test container
> classes)
> +# 2. Allow test cases to automatically (dynamically) be assigned to
> their
> +# corresponding test container class when new test data is defined.
> +#
> +# The idea being that infrastructure and test data are separated.
> Adding
> +# / removing / modifying test data does not require an
> infrastructure
> +# change (unless new categories are defined).
> +# 3. To work with the unittest discovery algorithm and VS Code Test
> Explorer.
> +#
> +# Notes:
> +# - (1) can roughly be achieved with unittest test suites. In another
> +# implementation approach, this solution was tested with relatively
> minor
> +# modifications to use test suites. However, this became a bit overly
> +# complicated with the dynamic test case method generation and did
> not
> +# work as well with VS Code Test Explorer.
> +# - For (2) and (3), particularly for VS Code Test Explorer to work,
> the
> +# dynamic population of the container class namespace needed to
> happen prior
> +# to class object creation. That is why the metaclass assigns test
> methods
> +# to the new classes based upon the test category specified in the
> +# corresponding data class.
> +# - This could have been simplified a bit by either using one test case
> +# container class and/or testing data in a single, monolithic test
> function
> +# that iterates over the data set. However, the dynamic hierarchy
> greatly
> +# helps organize test results and reporting. The infrastructure
> though
> +# inheriting some complexity to support it, should not need to change
> (much)
> +# as the data set expands.
> +# - Test case categories (container classes) are derived from the
> overall
> +# type of macro conditions under test.
> +#
> +# - This implementation assumes unittest will discover test cases
> +# (classes derived from unittest.TestCase) with the name pattern
> "Test_*"
> +# and test functions with the name pattern "test_x". Individual tests
> are
> +# dynamically numbered monotonically within a category.
> +# - The final test case description is also able to return fairly clean
> +# context information.
> +#
> +class Meta_TestDebugMacroCheck(type):
> + """
> + Metaclass for debug macro test case class factory.
> + """
> + @classmethod
> + def __prepare__(mcls, name, bases, **kwargs):
> + """Returns the test case namespace for this class."""
> + candidate_macros, cls_ns, cnt = [], {}, 0
> +
> + if "category" in kwargs.keys():
> + candidate_macros = [m for m in
> DebugMacroDataSet.DEBUG_MACROS if
> + m.category == kwargs["category"]]
> + else:
> + candidate_macros = DebugMacroDataSet.DEBUG_MACROS
> +
> + for cnt, macro_test in enumerate(candidate_macros):
> + f_name = f'test_{macro_test.category}_{cnt}'
> + t_desc = f'{macro_test!s}'
> + cls_ns[f_name] = mcls.build_macro_test(macro_test, t_desc)
> + return cls_ns
> +
> + def __new__(mcls, name, bases, ns, **kwargs):
> + """Defined to prevent variable args from bubbling to the base
> class."""
> + return super().__new__(mcls, name, bases, ns)
> +
> + def __init__(mcls, name, bases, ns, **kwargs):
> + """Defined to prevent variable args from bubbling to the base
> class."""
> + return super().__init__(name, bases, ns)
> +
> + @classmethod
> + def build_macro_test(cls, macro_test: MacroTest.MacroTest,
> + test_desc: str) -> Callable[[None], None]:
> + """Returns a test function for this macro test data."
> +
> + Args:
> + macro_test (MacroTest.MacroTest): The macro test class.
> +
> + test_desc (str): A test description string.
> +
> + Returns:
> + Callable[[None], None]: A test case function.
> + """
> + def test_func(self):
> + act_result = cls.check_regex(macro_test.macro)
> + self.assertCountEqual(
> + act_result,
> + macro_test.result,
> + test_desc + f'{linesep}'.join(
> + ["", f"Actual Result: {act_result}", "=" * 80,
> ""]))
> +
> + return test_func
> +
> + @classmethod
> + def check_regex(cls, source_str: str) -> Tuple[int, int, int]:
> + """Returns the plugin result for the given macro string.
> +
> + Args:
> + source_str (str): A string containing debug macros.
> +
> + Returns:
> + Tuple[int, int, int]: A tuple of the number of formatting
> errors,
> + number of print specifiers, and number of arguments for the
> macros
> + given.
> + """
> + return DebugMacroCheck.check_debug_macros(
> + DebugMacroCheck.get_debug_macros(source_str),
> + cls._get_function_name())
> +
> + @classmethod
> + def _get_function_name(cls) -> str:
> + """Returns the function name from one level of call depth.
> +
> + Returns:
> + str: The caller function name.
> + """
> + return "function: " +
> inspect.currentframe().f_back.f_code.co_name
> +
> +
> +# Test container classes for dynamically generated macro test cases.
> +# A class can be removed below to skip / remove it from testing.
> +# Test case functions will be added to the appropriate class as they are
> +# created.
> +class Test_NoSpecifierNoArgument(
> + unittest.TestCase,
> + metaclass=Meta_TestDebugMacroCheck,
> + category="no_specifier_no_argument_macro_test"):
> + pass
> +
> +
> +class Test_EqualSpecifierEqualArgument(
> + unittest.TestCase,
> + metaclass=Meta_TestDebugMacroCheck,
> + category="equal_specifier_equal_argument_macro_test"):
> + pass
> +
> +
> +class Test_MoreSpecifiersThanArguments(
> + unittest.TestCase,
> + metaclass=Meta_TestDebugMacroCheck,
> + category="more_specifiers_than_arguments_macro_test"):
> + pass
> +
> +
> +class Test_LessSpecifiersThanArguments(
> + unittest.TestCase,
> + metaclass=Meta_TestDebugMacroCheck,
> + category="less_specifiers_than_arguments_macro_test"):
> + pass
> +
> +
> +class Test_IgnoredSpecifiers(
> + unittest.TestCase,
> + metaclass=Meta_TestDebugMacroCheck,
> + category="ignored_specifiers_macro_test"):
> + pass
> +
> +
> +class Test_SpecialParsingMacroTest(
> + unittest.TestCase,
> + metaclass=Meta_TestDebugMacroCheck,
> + category="special_parsing_macro_test"):
> + pass
> +
> +
> +class Test_CodeSnippetMacroTest(
> + unittest.TestCase,
> + metaclass=Meta_TestDebugMacroCheck,
> + category="code_snippet_macro_test"):
> + pass
> +
> +
> +if __name__ == '__main__':
> + unittest.main()
> --
> 2.41.0.windows.3
-=-=-=-=-=-=-=-=-=-=-=-
Groups.io Links: You receive all messages sent to this group.
View/Reply Online (#108349): https://edk2.groups.io/g/devel/message/108349
Mute This Topic: https://groups.io/mt/100745711/7686176
Group Owner: devel+owner@edk2.groups.io
Unsubscribe: https://edk2.groups.io/g/devel/leave/12367111/7686176/1913456212/xyzzy [rebecca@openfw.io]
-=-=-=-=-=-=-=-=-=-=-=-
next prev parent reply other threads:[~2023-09-07 1:36 UTC|newest]
Thread overview: 19+ messages / expand[flat|nested] mbox.gz Atom feed top
2023-08-14 20:48 [edk2-devel] [PATCH v1 0/7] Add DebugMacroCheck Michael Kubacki
2023-08-14 20:48 ` [edk2-devel] [PATCH v1 1/7] RedfishPkg/PlatformHostInterfaceBmcUsbNicLib: Fix DEBUG macro args Michael Kubacki
2023-08-14 20:48 ` [edk2-devel] [PATCH v1 2/7] pip-requirements.txt: Add regex Michael Kubacki
2023-09-07 1:26 ` Michael D Kinney
2023-08-14 20:48 ` [edk2-devel] [PATCH v1 3/7] SecurityPkg.ci.yaml: Add debug macro exception Michael Kubacki
2023-09-07 1:42 ` Yao, Jiewen
2023-08-14 20:48 ` [edk2-devel] [PATCH v1 4/7] ArmVirtPkg.ci.yaml: " Michael Kubacki
2023-08-14 20:48 ` [edk2-devel] [PATCH v1 5/7] DynamicTablesPkg.ci.yaml: " Michael Kubacki
2023-08-14 20:48 ` [edk2-devel] [PATCH v1 6/7] OvmfPkg/PlatformCI: Disable DebugMacroCheck Michael Kubacki
2023-09-07 1:40 ` Yao, Jiewen
2023-08-14 20:48 ` [edk2-devel] [PATCH v1 7/7] .pytool/Plugin: Add DebugMacroCheck Michael Kubacki
2023-09-07 1:35 ` Michael D Kinney [this message]
2023-09-07 21:43 ` Michael Kubacki
2023-09-07 21:59 ` Michael D Kinney
2023-08-14 22:51 ` [edk2-devel] [PATCH v1 0/7] " Pedro Falcato
2023-08-15 0:23 ` Andrew Fish via groups.io
2023-08-15 0:26 ` Michael Kubacki
2023-08-15 1:12 ` Andrew Fish via groups.io
2023-08-15 0:57 ` Pedro Falcato
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-list from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=CO1PR11MB492916CC4E6F908777C29A10D2EEA@CO1PR11MB4929.namprd11.prod.outlook.com \
--to=devel@edk2.groups.io \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox