From nobody Thu Nov 14 07:08:18 2024 Delivered-To: importer@patchew.org Received-SPF: pass (zohomail.com: domain of groups.io designates 66.175.222.108 as permitted sender) client-ip=66.175.222.108; envelope-from=bounce+27952+107742+1787277+3901457@groups.io; helo=mail02.groups.io; Authentication-Results: mx.zohomail.com; dkim=pass; spf=pass (zohomail.com: domain of groups.io designates 66.175.222.108 as permitted sender) smtp.mailfrom=bounce+27952+107742+1787277+3901457@groups.io; dmarc=fail(p=none dis=none) header.from=linux.microsoft.com ARC-Seal: i=1; a=rsa-sha256; t=1692046204; cv=none; d=zohomail.com; s=zohoarc; b=IIXvMFtWFukIm1Msf3Z2vG5/hav8U/zweqGU6JR3dHq07Uf7CWWx/3uTO4zK93IOFjF4xgow13i46kqGfHkU6qZ0t9dqZtgYZ9YSqST6TyBLxjQmvO6zCeTzU6rcq0sRXtiCtejkndrzlgnWleEqPz/sdNJARril5xXQQvoe6z0= ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=zohomail.com; s=zohoarc; t=1692046204; h=Content-Transfer-Encoding:Cc:Date:From:In-Reply-To:List-Subscribe:List-Id:List-Help:List-Unsubscribe:MIME-Version:Message-ID:Reply-To:References:Sender:Subject:To; bh=Mge4XQdpJ+bctfv8anWTULjg/nb3+GrhermBqE7RcHY=; b=XHrHYllqdPYkuDNXCPIMPYvAIxXAY/UdMDDBfJXjqpNnyHud+kKktcC06b8KvYl8I2bSlrAfFgITqjn6xNRQkoI5nK2XtcNJaA0o6w+phgpYerJlj6Tw7tJGxq9ZZJ622QjRYl8DorywrJ5ZCHDB0VI6Y9fM7ggumjHPTzEOfN0= ARC-Authentication-Results: i=1; mx.zohomail.com; dkim=pass; spf=pass (zohomail.com: domain of groups.io designates 66.175.222.108 as permitted sender) smtp.mailfrom=bounce+27952+107742+1787277+3901457@groups.io; dmarc=fail header.from= (p=none dis=none) Received: from mail02.groups.io (mail02.groups.io [66.175.222.108]) by mx.zohomail.com with SMTPS id 169204620477550.834117980577275; Mon, 14 Aug 2023 13:50:04 -0700 (PDT) Return-Path: DKIM-Signature: a=rsa-sha256; bh=5ShLaRUiyCk0LcV+fbrhDXQY7slwPwDZ+73e/mwKOgw=; c=relaxed/simple; d=groups.io; h=DKIM-Filter:From:To:Cc:Subject:Date:Message-ID:In-Reply-To:References:MIME-Version:Precedence:List-Subscribe:List-Help:Sender:List-Id:Mailing-List:Delivered-To:Reply-To:List-Unsubscribe-Post:List-Unsubscribe:Content-Transfer-Encoding; s=20140610; t=1692046204; v=1; b=pFC5HnwZ2WGJt8AV6KV1y6VUPACMtbDu8RSvAyG4C9a//PXPO/QAtZhFvrWp2magxw/+uwXx BizjDEbMM4e+fc5pM9d6H/hrokaQWN7yScm8HzKlFaMLGQbh8szkvosFFMzDNAPt1eEduXeUoFW BJhCiFred2k5kA03szkAJrxo= X-Received: by 127.0.0.2 with SMTP id rtWhYY1788612xMmGe0z518n; Mon, 14 Aug 2023 13:50:04 -0700 X-Received: from linux.microsoft.com (linux.microsoft.com [13.77.154.182]) by mx.groups.io with SMTP id smtpd.web11.119111.1692046203820018245 for ; Mon, 14 Aug 2023 13:50:03 -0700 X-Received: from localhost.localdomain (unknown [47.201.241.95]) by linux.microsoft.com (Postfix) with ESMTPSA id A098F2109420; Mon, 14 Aug 2023 13:50:02 -0700 (PDT) DKIM-Filter: OpenDKIM Filter v2.11.0 linux.microsoft.com A098F2109420 From: "Michael Kubacki" To: devel@edk2.groups.io Cc: Sean Brogan , Michael D Kinney , Liming Gao Subject: [edk2-devel] [PATCH v1 7/7] .pytool/Plugin: Add DebugMacroCheck Date: Mon, 14 Aug 2023 16:48:58 -0400 Message-ID: <20230814204859.257-8-mikuback@linux.microsoft.com> In-Reply-To: <20230814204859.257-1-mikuback@linux.microsoft.com> References: <20230814204859.257-1-mikuback@linux.microsoft.com> MIME-Version: 1.0 Precedence: Bulk List-Subscribe: List-Help: Sender: devel@edk2.groups.io List-Id: Mailing-List: list devel@edk2.groups.io; contact devel+owner@edk2.groups.io Reply-To: devel@edk2.groups.io,mikuback@linux.microsoft.com List-Unsubscribe-Post: List-Unsubscribe=One-Click List-Unsubscribe: X-Gm-Message-State: Q97yubwNV1jciWMkk0Ayg6BMx1787277AA= Content-Transfer-Encoding: quoted-printable X-ZohoMail-DKIM: pass (identity @groups.io) X-ZM-MESSAGEID: 1692046205681100001 Content-Type: text/plain; charset="utf-8" From: Michael Kubacki 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 Cc: Michael D Kinney Cc: Liming Gao Signed-off-by: Michael Kubacki --- .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/DebugMacroCheckBuil= dPlugin.py b/.pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheckBuil= dPlugin.py new file mode 100644 index 000000000000..b1544666025e --- /dev/null +++ b/.pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheckBuildPlugin= .py @@ -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 =3D 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 independen= tly + 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 =3D builder.env.GetValue("DISABLE_DEBUG_MACRO_CHECK") + if env_disable: + return 0 + + # Only run on targets with compilation + build_target =3D builder.env.GetValue("TARGET").lower() + if "no-target" in build_target: + return 0 + + pp =3D builder.pp.split(os.pathsep) + edk2 =3D Edk2Path(builder.ws, pp) + package =3D edk2.GetContainingPackage( + builder.mws.join(builder.ws, + builder.env.GetValue( + "ACTIVE_PLATFORM"))) + package_path =3D Path( + edk2.GetAbsolutePathOnThisSystemFromEdk2Relative= Path( + 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 =3D [] + 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 =3D {} + + # 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 =3D 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 =3D 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 |=3D package_config_file_data["DebugMacroChec= k"]["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 p= lugin + # getting called such as pre-existing build script. + sub_file =3D 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 |=3D yaml.safe_load(sf) + + try: + error_count =3D DebugMacroCheck.check_macros_in_directory( + package_path, + ignore_git_submodules=3DFalse, + show_progress_bar=3DFalse, + **sub_data) + finally: + for h, l in handler_level_context: + h.setLevel(l) + + return error_count diff --git a/.pytool/Plugin/DebugMacroCheck/BuildPlugin/DebugMacroCheck_plu= g_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.ya= ml @@ -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/Pl= ugin/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 =3D "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 em= pty + 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 =3D StringIO() + exit_code =3D RunCmd("git", "ls-files --other", + workingdir=3Dstr(directory_path), + outstream=3Dout_stream_buffer, + logging_level=3Dlogging.NOTSET) + if exit_code !=3D 0: + return [] + + rel_paths =3D out_stream_buffer.getvalue().strip().splitlines() + abs_paths =3D [] + 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 =3D StringIO() + exit_code =3D RunCmd( + "git", "config --file .gitmodules --get-regexp path", + workingdir=3Dstr(directory_path), + outstream=3Dout_stream_buffer, + logging_level=3Dlogging.NOTSET) + if exit_code !=3D 0: + return [] + + submodule_paths =3D [] + 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 =3D False): + """Class constructor method. + + Args: + quiet (bool, optional): Indicates if messages are currently be= ing + printed (False) or not (True). Defaults to False. + """ + + self._quiet =3D quiet + + def filter(self, record: logging.LogRecord) -> bool: + """Quiet filter method. + + Args: + record (logging.LogRecord): A log record object that the filte= r 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 filte= r is + applied to. + + Returns: + bool: True if the message is not a 'Progress' message. Otherwi= se, + False. + """ + return not record.getMessage().startswith("\rProgress") + + +class CacheDuringProgressFilter(logging.Filter): + """A logging filter that suppresses messages during progress operation= s.""" + + _message_cache =3D [] + + @property + def message_cache(self) -> List[logging.LogRecord]: + """Contains a cache of messages accumulated during time of operati= on. + + 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 dis= play + 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 =3D {k.lower(): v for k, v in macro_subs.items()} + + arg_cnt, failure_cnt, print_spec_cnt =3D 0, 0, 0 + for macro in macros: + # Special Specifier Handling + processed_dbg_str =3D 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 =3D 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 =3D ['%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 =3D 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 =3D ['%%', '\r', '\n'] + for s in specifier_other_replacements: + if s in processed_dbg_str: + processed_dbg_str =3D processed_dbg_str.replace(s, '') + + processed_dbg_str =3D 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 =3D 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 =3D "" + else: + processed_arg_str =3D macro['dbg_args'].strip() + + argument_other_replacements =3D ['\r', '\n'] + for r in argument_other_replacements: + if s in processed_arg_str: + processed_arg_str =3D processed_arg_str.replace(s, '') + processed_arg_str =3D 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 =3D re.sub( + r'([\"\'])(?:|\\.|[^\\])*?(\1)', + '', + processed_arg_str) + + arg_matches =3D regex.findall( + r'(?:\((?:[^)(]+|(?R))*+\))|(,)', + processed_arg_str, + regex.MULTILINE) + + arg_cnt =3D 0 + if processed_arg_str !=3D '': + arg_cnt =3D arg_matches.count(',') + + if print_spec_cnt !=3D arg_cnt: + logging.error(f"File: {file_dbg_path}") + logging.error(f" Message =3D {macro['dbg_str']}") + logging.error(f" Arguments =3D \"{processed_arg_str}\"") + logging.error(f" Specifier Count =3D {print_spec_cnt}") + logging.error(f" Argument Count =3D {arg_cnt}") + + failure_cnt +=3D 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 identify= ing + # DEBUG macros within source files and grouping the macro message stri= ng + # and macro arguments strings so they can be further processed. + r =3D regex.compile( + r'(?>(?PDEBUG\s*\(\s*\((?:.*?,))(?:\s*))(?P.*?(= ?:\"' + r'(?:[^\"\\]|\\.)*\".*?)*)(?:(?(?=3D,)(?.*?(?=3D(?:\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 dis= play + 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 =3D 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 dis= play + in debug messages. + + show_utf8_decode_warning (bool, optional): Indicates whether to sh= ow + 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=3D'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] =3D ('.c',), + ignore_git_ignore_files: Optional[bool] =3D = True, + ignore_git_submodules: Optional[bool] =3D Tr= ue, + show_progress_bar: Optional[bool] =3D True, + show_utf8_decode_warning: bool =3D False, + **macro_subs: str + ) -> int: + """Checks files with the given extension in the given directory for de= bug + 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 whet= her + 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 sh= ow + 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=3D"\r") + + start_time =3D timeit.default_timer() + previous_indicator_time =3D start_time + + files =3D [] + 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 =3D timeit.default_timer() + current_start_delta =3D current_time - start_time + + if current_time - previous_indicator_time >=3D 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 =3D 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 =3D timeit.default_timer() + file_list =3D set(_get_file_list(directory, file_extensions)) + end_time =3D 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 =3D timeit.default_timer() + ignored_file_paths =3D GitHelpers.get_git_ignored_paths(directory) + end_time =3D 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 =3D timeit.default_timer() + file_list =3D file_list.difference(ignored_file_paths) + end_time =3D 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 =3D 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 =3D timeit.default_timer() + file_list =3D [f for f in file_list + if not f.is_relative_to(*submodule_paths)] + end_time =3D 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 aft= er " + 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 =3D CacheDuringProgressFilter() + handler =3D next((h for h in logging.getLogger().handlers if h.get_nam= e() =3D=3D + 'stdout_logger_handler'), None) + + if handler is not None: + handler.addFilter(cache_progress_filter) + + start_time =3D timeit.default_timer() + + failure_cnt, file_cnt =3D 0, 0 + for file_cnt, file in enumerate(file_list): + file_rel_path =3D str(file.relative_to(directory)) + failure_cnt +=3D 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 els= e "") + + if show_progress_bar: + _show_progress(len(file_list), len(file_list), + f" {failure_cnt} errors" if failure_cnt > 0 else "") + print("\n", flush=3DTrue) + + end_time =3D 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 =3D '') -> 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 =3D=3D 0: + _progress_start_time =3D timeit.default_timer() + + terminal_col =3D shutil.get_terminal_size().columns + var_consume_len =3D (len("Progress|\u2588| 000.0% Complete 000s") + + len(suffix)) + avail_len =3D terminal_col - var_consume_len + + percent =3D f"{100 * (step / float(total)):3.1f}" + filled =3D int(avail_len * step // total) + bar =3D '\u2588' * filled + '-' * (avail_len - filled) + step_time =3D timeit.default_timer() - _progress_start_time + + print(f'\rProgress|{bar}| {percent}% Complete {step_time:-3.0f}s' + f'{suffix}', end=3D'\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 director= y. + + Returns: + bool: True if the path is a directory else False. + """ + abs_dir_path =3D 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 =3D 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 mess= ages. + """ + pass + + root_logger =3D logging.getLogger() + root_logger.setLevel(logging.DEBUG) + + stdout_logger_handler =3D 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 =3D argparse.ArgumentParser( + prog=3DPROGRAM_NAME, + description=3D( + "Checks for debug macro formatting " + "errors within files recursively located withi= n " + "a given directory."), + formatter_class=3DRawTextHelpFormatter) + + io_req_group =3D parser.add_mutually_exclusive_group(required=3DTrue) + io_opt_group =3D parser.add_argument_group( + "Optional input and output") + git_group =3D parser.add_argument_group("Optional git control") + + io_req_group.add_argument('-w', '--workspace-directory', + type=3D_check_dir_path, + help=3D"Directory of source files to check.\= n\n") + + io_req_group.add_argument('-i', '--input-file', nargs=3D'?', + type=3D_check_file_path, + help=3D"File path for an input file to check= .\n\n" + "Note that some other options do not ap= ply " + "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=3D'?', + default=3DNone, + const=3D'debug_macro_check.log', + help=3D"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 u= sed " + "in the current directory)\n\n") + + io_opt_group.add_argument('-s', '--substitution-file', + type=3D_check_file_path, + help=3D"A substitution YAML file specifies s= tring " + "substitutions to perform within the de= bug " + "macro.\n\nThis is intended to be a sim= ple " + "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 u= sed " + "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=3D'count', + default=3D0, + help=3D"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 enabl= ed)" + "\n\n") + + io_opt_group.add_argument('-n', '--no-progress-bar', action=3D'store_t= rue', + help=3D"Disables progress bars.\n" + "(default: progress bars are used in so= me" + "places to show progress)\n\n") + + io_opt_group.add_argument('-q', '--quiet', action=3D'store_true', + help=3D"Disables console output.\n" + "(default: console output is enabled)\n= \n") + + io_opt_group.add_argument('-u', '--utf8w', action=3D'store_true', + help=3D"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=3D'store_true', + help=3D"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=3D'store_true', + help=3D"Do not ignore files in git submodules.\= n" + "(default: files in git submodules are " + "ignored)\n\n") + + parser.add_argument('-e', '--extensions', nargs=3D'*', default=3D['.c'= ], + help=3D"List of file extensions to include.\n" + "(default: %(default)s)") + + args =3D parser.parse_args() + + if args.quiet: + # Don't print in the few places that directly print + builtins.print =3D _quiet_print + stdout_logger_handler.addFilter(QuietFilter(args.quiet)) + + if args.log_file: + file_logger_handler =3D logging.FileHandler(filename=3Dargs.log_fi= le, + mode=3D'w', encoding=3D'= 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 =3D=3D 0: + file_logger_handler.setLevel(logging.INFO) + file_logger_formatter =3D logging.Formatter( + '%(levelname)-8s %(message)s') + elif args.verbose_log_file =3D=3D 1: + file_logger_handler.setLevel(logging.DEBUG) + file_logger_formatter =3D logging.Formatter( + '%(levelname)-8s %(message)s') + elif args.verbose_log_file =3D=3D 2: + file_logger_handler.setLevel(logging.DEBUG) + file_logger_formatter =3D logging.Formatter( + '[%(filename)s - %(funcName)20s() ] %(levelname)-8s ' + '%(message)s') + elif args.verbose_log_file =3D=3D 3: + file_logger_handler.setLevel(logging.DEBUG) + file_logger_formatter =3D logging.Formatter( + '[%(filename)s:%(lineno)s - %(funcName)20s() ] ' + '%(levelname)-8s %(message)s') + elif args.verbose_log_file =3D=3D 4: + file_logger_handler.setLevel(logging.DEBUG) + file_logger_formatter =3D logging.Formatter( + '%(asctime)s [%(filename)s:%(lineno)s - %(funcName)20s() ]' + ' %(levelname)-8s %(message)s') + else: + file_logger_handler.setLevel(logging.DEBUG) + file_logger_formatter =3D 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 =3D {} + if args.substitution_file: + logging.info(f"Loading substitution file {args.substitution_file}") + with open(args.substitution_file, 'r') as sf: + substitution_data =3D 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 =3D Path(__file__).parent + input_file =3D Path(args.input_file) + + rel_path =3D str(input_file) + if input_file.is_relative_to(curr_dir): + rel_path =3D str(input_file.relative_to(curr_dir)) + + logging.info(f"Checking Debug Macros in File: " + f"{input_file.resolve()}\n") + + start_time =3D timeit.default_timer() + failure_cnt =3D check_macros_in_file( + input_file, + rel_path, + args.utf8w, + **substitution_data)[0] + end_time =3D 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__ =3D=3D '__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/Debu= gMacroCheck/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 proc= ess to catch errors right away. + +As a build plugin, it is capable of finding these errors early in the deve= lopment process after code is initially +written to ensure that all code tested is free of debug macro formatting e= rrors. These errors often creep into debug +prints in error conditions that are not frequently executed making debug e= ven more difficult and confusing when they +are encountered. In other cases, debug macros with these errors in the mai= n code path can lead to unexpected behavior +when executed. As a standalone script, it can be easily run manually or in= tegrated into other CI processes. + +The plugin is part of a set of debug macro check scripts meant to be relat= ively 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-Describi= ng Environment (SDE) due to the accompanying +file `DebugMacroCheck_plugin_in.yaml`. + +Since macro errors are considered a coding bug that should be found and fi= xed during the build phase of the developer +process (before debug and testing), this plugin is run in pre-build. It wi= ll run within the scope of the package +being compiled. For a platform build, this means it will run against the p= ackage 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-TA= RGET"`). + + 3. Runs as a pre-build step. This means it gives results right away to e= nsure 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, a= ll code submissions have been checked. + + 4. Reports any errors in the build log and fails the build upon error ma= king 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` wi= th the name of a substitution YAML file to + use. + + **Example:** + + ```python + shell_environment.GetBuildVars().SetValue( + "DEBUG_MACRO_CHECK_SUB_FILE", + os.path.join(self.GetWorkspace= Root(), "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 wit= h one argument + # Replace ternary operator in debug string with single spe= cifier + 'Index =3D=3D COLUME_SIZE/2 ? " | %02x" : " %02x"': "%d" + + # DynamicTablesPkg/Library/Common/TableHelperLib/ConfigurationMana= gerObjectParser.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 c= alled `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 varia= ble are not inspected at this time. + +## 2. DebugMacroCheck.py + +This is the main Python module containing the implementation logic. The bu= ild 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 dependen= cy 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-li= brary/) +- GitHub repo: [tianocore/edk2-pytool-library](https://github.com/tianocor= e/edk2-pytool-library) + +If you strongly prefer not including this additional dependency, the funct= ionality imported here is relatively +simple to substitute with the Python [`subprocess`](https://docs.python.or= g/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 "fi= le_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 sin= gle 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 t= hen a file called + debug_macro_check.log is created and used in the c= urrent directory) + + -s SUBSTITUTION_FILE, --substitution-file SUBSTITUTION_FILE + A substitution YAML file specifies string substitu= tions to perform within the debug macro. + + This is intended to be a simple mechanism to expan= d the rare cases of pre-processor + macros without directly involving the pre-processo= r. 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 result= s 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. Thi= s has the advantage that it is very portable +and can run early in the build process, but it also means pre-processor ma= cro expansion does not happen when it is +invoked. + +In practice, it has been very rare that this is an issue for how most debu= g 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 hum= ans to keep debug macro specifiers and +arguments balanced as it is for `DebugMacroCheck` pre-processor macro subs= titution is used. By separating the string +from the actual arguments provided, it is more likely for developers to ma= ke 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 i= n 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 optio= n and will upgrade your environment to a +newer, safer, and better Python experience. **(2)** is the simplest approa= ch 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 upd= ates 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/.p= ytool/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 =3D [ + ##################################################################### + # 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=3D0x%x)\n", T= his->Media->MediaId));', + (0, 1, 1) + ), + EqualSpecifierEqualArgumentMacroTest( + r'DEBUG ((DEBUG_INFO, " Retuning TimerCnt %dseconds\n", 2 * (Cap= ability->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", PartitionEntryB= uffer[Index].StartingLBA));', + (0, 1, 1) + ), + EqualSpecifierEqualArgumentMacroTest( + r'DEBUG ((DEBUG_ERROR, "Failed to locate gEdkiiBootLogo2ProtocolGu= id Status =3D %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, Unicod= e, 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, Gu= id, Ascii, Status, Unicode, Hex, Pointer, Character, Guid, Ascii, Status, U= nicode, 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=3D0x%x, = Lba=3D%ld, BufferSize=3D0x%x bytes (%d kB), BufferPtr @ 0x%08x)\n", MediaId= , Lba, BufferSizeInBytes, Buffer));', + (1, 5, 4) + ), + MoreSpecifiersThanArgumentsMacroTest( + r'DEBUG ((DEBUG_INFO, "%a: Request=3D%s\n", __func__));', + (1, 2, 1) + ), + MoreSpecifiersThanArgumentsMacroTest( + r'DEBUG ((DEBUG_ERROR, "%a: Invalid request format %d for %d\n", C= ertFormat, CertRequest));', + (1, 3, 2) + ), + + ##################################################################### + # Section: Less Print Specifiers Than Arguments + ##################################################################### + LessSpecifiersThanArgumentsMacroTest( + r'DEBUG ((DEBUG_INFO, "Find GPT Partition [0x%lx", PartitionEntryB= uffer[Index].StartingLBA, BlockDevPtr->LastBlock));', + (1, 1, 2) + ), + LessSpecifiersThanArgumentsMacroTest( + r'DEBUG ((DEBUG_INFO, " Retuning TimerCnt Disabled\n", 2 * (Capa= bility->TimerCount - 1)));', + (1, 0, 1) + ), + LessSpecifiersThanArgumentsMacroTest( + r'DEBUG ((DEBUG_ERROR, "Failed to locate gEdkiiBootLogo2ProtocolGu= id. 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 PPR= Q/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 b= lob with return status %r\n", __func__, gPolicyBlobFieldName[MFCI_POLICY_TA= RGET_NONCE], Status));', + (1, 2, 3) + ), + + ##################################################################### + # Section: Macros with Ignored Specifiers + ##################################################################### + IgnoredSpecifiersMacroTest( + r'DEBUG ((DEBUG_INIT, "%HEmuOpenBlock: opened %a%N\n", Private->Fi= lename));', + (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", Str= ing1, 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->Tun= ingSDR50 ? "TRUE" : "FALSE"));', + (0, 1, 1), + "Ternary Operator Present" + ), + SpecialParsingMacroTest( + r'DEBUG ((DEBUG_INFO, " SDR50 Tuning %a\n", Capability->Tun= ingSDR50 ? "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=3D%Lu LoadFile=3D\"%s\" FilePath=3D\"%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 =3D %d. " \ + "Maximum supported Processor Node size exceeded. " \ + "Token =3D %p. Status =3D %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 =3D=3D 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 Argument= s" + ), + SpecialParsingMacroTest( + r''' + DEBUG (( + DEBUG_ERROR, + "%a: Label=3D\"%s\" OldParentNodeId=3D%Lu OldName=3D\"%a\" " + "NewParentNodeId=3D%Lu NewName=3D\"%a\" Errno=3D%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\", Sta= tus =3D %r\n", Status)); + ''', + (0, 1, 1), + "Escaped Parentheses in Debug Message" + ), + SpecialParsingMacroTest( + r''' + DEBUG((DEBUG_INFO, "%0d %s", XbB_ddr4[1][bankBit][xorBit], xorBit = =3D=3D (XaB_NUM_OF_BITS-1) ? "]": ", ")); + ''', + (0, 2, 2), + "Parentheses in Ternary Operator Expression" + ), + SpecialParsingMacroTest( + r'DEBUG ((DEBUG_INFO | DEBUG_EVENT | DEBUG_WARN, " %u\n", &Struc= ture->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 A= fter Function Call" + ), + SpecialParsingMacroTest( + r'DEBUG ((DEBUG_WARN, " %s-%a\n", ReturnString(&Param1), ReturnS= tring2(&ParamN)));', + (0, 2, 2), + "Multiple Function Call Arguments" + ), + SpecialParsingMacroTest( + r'DEBUG ((DEBUG_WARN, " %s\n", ReturnString(&Param1), ReturnStri= ng2(&ParamN)));', + (1, 1, 2), + "Multiple Function Call Arguments with Imbalance" + ), + SpecialParsingMacroTest( + r'DEBUG ((DEBUG_WARN, " %s%s\n", (ReturnString(&Param1)), (Retur= nString2(&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, Ret= urnString(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.Some= Size, 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.So= meSize, CommaDecimalValue));', + (1, 9, 8), + "Multiple Complex Print Specifiers Imbalance 1" + ), + SpecialParsingMacroTest( + r''' + DEBUG (( + DEBUG_ERROR, + ("%a: Label=3D\"%s\" CanonicalPathname=3D\"%a\" FileName=3D\"%s\= " " + "OpenMode=3D0x%Lx Attributes=3D0x%Lx: nonsensical request to po= ssibly " + "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 C= oncat" + ), + 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) + LocalBbsT= able[Index].MfgStringOffset), + (UINTN)((LocalBbsTable[Index].DescStringSegment << 4) + LocalBbs= Table[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%-1= 6x (%-,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-D= epth Function Calls" + ), + SpecialParsingMacroTest( + r''' + DEBUG ( + (DEBUG_NET, + "TcpFastRecover: enter fast retransmission for TCB %p, recover p= oint 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\"", __fu= nc__, "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_PROTOC= OL 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 =3D=3D COLUMN_SIZE/2 ? "0" : " %02x", (U= INTN)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, "=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D= =3D=3D=3D=3D=3D\n")); + for (Index =3D 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) + Local= BbsTable[Index].MfgStringOffset), + (UINTN)((LocalBbsTable[Index].DescStringSegment << 4) + Loca= lBbsTable[Index].DescStringOffset)) + ); + } + + DEBUG ((DEBUG_INFO, "\n")); + ''', + (1, 0, 0), + "Code Section with An Imbalanced Macro" + ), + CodeSnippetMacroTest( + r''' + if (*Buffer =3D=3D AML_ROOT_CHAR) { + // + // RootChar + // + Buffer++; + DEBUG ((DEBUG_ERROR, "\\")); + } else if (*Buffer =3D=3D AML_PARENT_PREFIX_CHAR) { + // + // ParentPrefixChar + // + do { + Buffer++; + DEBUG ((DEBUG_ERROR, "^")); + } while (*Buffer =3D=3D AML_PARENT_PREFIX_CHAR); + } + DEBUG ((DEBUG_WARN, "Failed to retrieve Variable:\"MebxData\", Sta= tus =3D %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 =3D 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/Pl= ugin/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=3DTrue) +class MacroTest(abc.ABC): + """Abstract base class for an individual macro test case.""" + + macro: str + result: Tuple[int, int, int] + description: str =3D field(default=3D'') + + @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 argume= nts.' + + 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 =3D [ + f"{linesep}", + "=3D" * 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=3DTrue) +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=3DTrue) +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=3DTrue) +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=3DTrue) +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=3DTrue) +class IgnoredSpecifiersMacroTest(MacroTest): + """Test case to test ignored print specifiers.""" + + @property + def category(self) -> str: + return "ignored_specifiers_macro_test" + + +@dataclass(frozen=3DTrue) +class SpecialParsingMacroTest(MacroTest): + """Test case with special (complicated) parsing scenarios.""" + + @property + def category(self) -> str: + return "special_parsing_macro_test" + + +@dataclass(frozen=3DTrue) +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/Plu= gin/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 =3D 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 classe= s) +# 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. Add= ing +# / 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 Expl= orer. +# +# Notes: +# - (1) can roughly be achieved with unittest test suites. In another +# implementation approach, this solution was tested with relatively min= or +# 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 meth= ods +# 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 func= tion +# that iterates over the data set. However, the dynamic hierarchy great= ly +# 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 a= re +# 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 =3D [], {}, 0 + + if "category" in kwargs.keys(): + candidate_macros =3D [m for m in DebugMacroDataSet.DEBUG_MACRO= S if + m.category =3D=3D kwargs["category"]] + else: + candidate_macros =3D DebugMacroDataSet.DEBUG_MACROS + + for cnt, macro_test in enumerate(candidate_macros): + f_name =3D f'test_{macro_test.category}_{cnt}' + t_desc =3D f'{macro_test!s}' + cls_ns[f_name] =3D 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 clas= s.""" + return super().__new__(mcls, name, bases, ns) + + def __init__(mcls, name, bases, ns, **kwargs): + """Defined to prevent variable args from bubbling to the base clas= s.""" + 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 =3D cls.check_regex(macro_test.macro) + self.assertCountEqual( + act_result, + macro_test.result, + test_desc + f'{linesep}'.join( + ["", f"Actual Result: {act_result}", "=3D" * 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 erro= rs, + number of print specifiers, and number of arguments for the ma= cros + 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=3DMeta_TestDebugMacroCheck, + category=3D"no_specifier_no_argument_macro_test"): + pass + + +class Test_EqualSpecifierEqualArgument( + unittest.TestCase, + metaclass=3DMeta_TestDebugMacroCheck, + category=3D"equal_specifier_equal_argument_macro_test"): + pass + + +class Test_MoreSpecifiersThanArguments( + unittest.TestCase, + metaclass=3DMeta_TestDebugMacroCheck, + category=3D"more_specifiers_than_arguments_macro_test"): + pass + + +class Test_LessSpecifiersThanArguments( + unittest.TestCase, + metaclass=3DMeta_TestDebugMacroCheck, + category=3D"less_specifiers_than_arguments_macro_test"): + pass + + +class Test_IgnoredSpecifiers( + unittest.TestCase, + metaclass=3DMeta_TestDebugMacroCheck, + category=3D"ignored_specifiers_macro_test"): + pass + + +class Test_SpecialParsingMacroTest( + unittest.TestCase, + metaclass=3DMeta_TestDebugMacroCheck, + category=3D"special_parsing_macro_test"): + pass + + +class Test_CodeSnippetMacroTest( + unittest.TestCase, + metaclass=3DMeta_TestDebugMacroCheck, + category=3D"code_snippet_macro_test"): + pass + + +if __name__ =3D=3D '__main__': + unittest.main() --=20 2.41.0.windows.3 -=3D-=3D-=3D-=3D-=3D-=3D-=3D-=3D-=3D-=3D-=3D- Groups.io Links: You receive all messages sent to this group. View/Reply Online (#107742): https://edk2.groups.io/g/devel/message/107742 Mute This Topic: https://groups.io/mt/100745711/1787277 Group Owner: devel+owner@edk2.groups.io Unsubscribe: https://edk2.groups.io/g/devel/unsub [importer@patchew.org] -=3D-=3D-=3D-=3D-=3D-=3D-=3D-=3D-=3D-=3D-=3D-