From cfea478b808b9d8d8dd32269398755885dd19227 Mon Sep 17 00:00:00 2001 From: Alex Flom Date: Thu, 6 Jul 2023 13:12:43 -0400 Subject: [PATCH] Adds logger Signed-off-by: Alex Flom --- trestlebot/bot.py | 15 ++-- trestlebot/cli.py | 17 ++-- trestlebot/log.py | 125 +++++++++++++++++++++++++++ trestlebot/tasks/authored/catalog.py | 8 -- trestlebot/tasks/authored/compdef.py | 8 -- trestlebot/tasks/authored/profile.py | 8 -- trestlebot/tasks/authored/ssp.py | 8 -- 7 files changed, 140 insertions(+), 49 deletions(-) create mode 100644 trestlebot/log.py diff --git a/trestlebot/bot.py b/trestlebot/bot.py index 269227bc..410bead0 100644 --- a/trestlebot/bot.py +++ b/trestlebot/bot.py @@ -17,7 +17,6 @@ """This module implements functions for the Trestle Bot.""" import logging -import sys from typing import List, Optional from git import GitCommandError @@ -27,9 +26,7 @@ from trestlebot.tasks.base_task import TaskBase, TaskException -logging.basicConfig( - format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO -) +logger = logging.getLogger(__name__) class RepoException(Exception): @@ -41,7 +38,7 @@ class RepoException(Exception): def _stage_files(gitwd: Repo, patterns: List[str]) -> None: """Stages files in git based on file patterns""" for pattern in patterns: - logging.info(f"Adding file for pattern {pattern}") + logger.info(f"Adding file for pattern {pattern}") gitwd.index.add(pattern) @@ -130,7 +127,7 @@ def run( ) if dry_run: - logging.info("Dry run mode is enabled. Do not push to remote.") + logger.info("Dry run mode is enabled. Do not push to remote.") return commit_sha try: @@ -140,14 +137,14 @@ def run( # Push changes to the remote repository remote.push(refspec=f"HEAD:{branch}") - logging.info(f"Changes pushed to {branch} successfully.") + logger.info(f"Changes pushed to {branch} successfully.") return commit_sha except GitCommandError as e: raise RepoException(f"Git push to {branch} failed: {e}") from e else: - logging.info("Nothing to commit") + logger.info("Nothing to commit") return commit_sha else: - logging.info("Nothing to commit") + logger.info("Nothing to commit") return commit_sha diff --git a/trestlebot/cli.py b/trestlebot/cli.py index 649ddc9f..98519b58 100644 --- a/trestlebot/cli.py +++ b/trestlebot/cli.py @@ -22,15 +22,14 @@ import sys from typing import List -from trestlebot import bot +from trestlebot import bot, log from trestlebot.tasks.assemble_task import AssembleTask from trestlebot.tasks.authored import types from trestlebot.tasks.base_task import TaskBase -logging.basicConfig( - format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO -) +logger = logging.getLogger('trestlebot') + def _parse_cli_arguments() -> argparse.Namespace: @@ -116,13 +115,15 @@ def handle_exception( exception: Exception, msg: str = "Exception occurred during execution" ) -> int: """Log the exception and return the exit code""" - logging.exception(msg + f": {exception}") + logger.error(msg + f": {exception}") return 1 def run() -> None: """Trestle Bot entry point function.""" + log.set_global_logging_levels() + args = _parse_cli_arguments() pre_tasks: List[TaskBase] = [] @@ -132,18 +133,18 @@ def run() -> None: try: assembled_type = types.check_authored_type(args.assemble_model) except ValueError: - logging.error( + logger.error( f"Invalid value {args.assemble_model} for assemble model. " f"Please use catalog, profile, compdef, or ssp." ) sys.exit(1) if not args.markdown_path: - logging.error("Must set markdown path with assemble model.") + logger.error("Must set markdown path with assemble model.") sys.exit(1) if args.assemble_model == "ssp" and args.ssp_index_path == "": - logging.error("Must set ssp_index_path when using SSP as assemble model.") + logger.error("Must set ssp_index_path when using SSP as assemble model.") sys.exit(1) assemble_task = AssembleTask( diff --git a/trestlebot/log.py b/trestlebot/log.py new file mode 100644 index 00000000..8849c6ee --- /dev/null +++ b/trestlebot/log.py @@ -0,0 +1,125 @@ +# -*- mode:python; coding:utf-8 -*- + +# Copyright (c) 2020 IBM Corp. All rights reserved. +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# https://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +"""Common logging utilities.""" +import argparse +import logging +import sys +from types import TracebackType +from typing import Optional, Type + +# Singleton logger instance +# All other CLI sub module will inherit settings of this logger as long as +# sub-module instantiates a logger with a prefix 'trestlebot' or __name__ +_logger = logging.getLogger('trestlebot') + + +class SpecificLevelFilter(logging.Filter): + """ + Filter for the same level as provided by setLevel for a log handler. + + Python by default logs all levels above to a given destination. This makes it easy to split levels where you might + log all levels to file and only errors to std.err, however, does not allow logging a specific level elsewhere. + """ + + def __init__(self, level: int) -> None: + """Initialize providing maximum level to be pushed through the filter.""" + self._level = level + + def filter(self, log_record: logging.LogRecord) -> bool: # noqa: A003 + """Filter log messages.""" + return log_record.levelno == self._level + + +def set_global_logging_levels(level: int = logging.INFO) -> None: + """Initialise logging. + + Should only be invoked by the CLI classes or similar. + """ + # This line stops default root loggers setup for a python context from logging extra messages. + # DO NOT USE THIS COMMAND directly from an SDK. Handle logs levels based on your own application + _logger.propagate = False + # Remove handlers + _logger.handlers.clear() + # set global level + _logger.setLevel(level) + # Create standard out + console_out_handler = logging.StreamHandler(sys.stdout) + console_out_handler.setLevel(logging.INFO) + console_out_handler.addFilter(SpecificLevelFilter(logging.INFO)) + + console_debug_handler = logging.StreamHandler(sys.stdout) + console_debug_handler.setLevel(logging.DEBUG) + console_debug_handler.addFilter(SpecificLevelFilter(logging.DEBUG)) + + console_error_handler = logging.StreamHandler(sys.stderr) + console_error_handler.setLevel(logging.WARNING) + # create formatters + error_formatter = logging.Formatter('%(name)s:%(lineno)d %(levelname)s: %(message)s') + debug_formatter = logging.Formatter('%(name)s:%(lineno)d %(levelname)s: %(message)s') + console_debug_handler.setFormatter(debug_formatter) + console_error_handler.setFormatter(error_formatter) + # add ch to logger + _logger.addHandler(console_out_handler) + _logger.addHandler(console_error_handler) + _logger.addHandler(console_debug_handler) + + +def _exception_handler( + exception_type: Type[BaseException], exception: BaseException, traceback: Optional[TracebackType] +) -> None: + """Empty exception handler to prevent stack traceback in quiet mode.""" + logging.warning(exception) + + +def _get_trace_level() -> int: + """Get special value used for trace - just below DEBUG.""" + return logging.DEBUG - 5 + + +def set_log_level_from_args(args: argparse.Namespace) -> None: + """Vanity function to automatically set log levels based on verbosity flags.""" + if args.verbose > 1: + # these msgs only output by trace calls + set_global_logging_levels(_get_trace_level()) + elif args.verbose == 1: + set_global_logging_levels(logging.DEBUG) + else: + set_global_logging_levels(logging.INFO) + sys.excepthook = _exception_handler + + +def get_current_verbosity_level(logger: logging.Logger) -> int: + """Get the current verbosity level based on logging level.""" + level = logger.getEffectiveLevel() + if level < logging.DEBUG: + return 2 + elif level == logging.DEBUG: + return 1 + return 0 + + +class Trace(): + """Class allowing low priority trace message when verbose > 1 and log level below DEBUG.""" + + def __init__(self, logger: logging.Logger) -> None: + """Store the main logger with its module name.""" + self._logger = logger + + def log(self, msg: str) -> None: + """Output the trace msg if log level is below DEBUG.""" + level = self._logger.getEffectiveLevel() + if level < logging.DEBUG: + self._logger.debug(msg) diff --git a/trestlebot/tasks/authored/catalog.py b/trestlebot/tasks/authored/catalog.py index 70311b88..1cba0806 100644 --- a/trestlebot/tasks/authored/catalog.py +++ b/trestlebot/tasks/authored/catalog.py @@ -16,10 +16,8 @@ """Trestle Bot functions for catalog authoring""" -import logging import os import pathlib -import sys from trestle.common.err import TrestleError from trestle.core.commands.author.catalog import CatalogAssemble @@ -30,12 +28,6 @@ AuthorObjectBase, ) - -logging.basicConfig( - format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO -) - - class AuthoredCatalog(AuthorObjectBase): """ Functions for authoring OSCAL catalogs in automation diff --git a/trestlebot/tasks/authored/compdef.py b/trestlebot/tasks/authored/compdef.py index 3284ba40..543bc914 100644 --- a/trestlebot/tasks/authored/compdef.py +++ b/trestlebot/tasks/authored/compdef.py @@ -16,10 +16,8 @@ """Trestle Bot functions for component definition authoring""" -import logging import os import pathlib -import sys from trestle.common.err import TrestleError from trestle.core.commands.author.component import ComponentAssemble @@ -30,12 +28,6 @@ AuthorObjectBase, ) - -logging.basicConfig( - format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO -) - - class AuthoredComponentsDefinition(AuthorObjectBase): """ Functions for authoring OSCAL Component Definitions in automation diff --git a/trestlebot/tasks/authored/profile.py b/trestlebot/tasks/authored/profile.py index fad96f74..76b9a80b 100644 --- a/trestlebot/tasks/authored/profile.py +++ b/trestlebot/tasks/authored/profile.py @@ -16,10 +16,8 @@ """Trestle Bot functions for profile authoring""" -import logging import os import pathlib -import sys from trestle.common.err import TrestleError from trestle.core.commands.author.profile import ProfileAssemble @@ -30,12 +28,6 @@ AuthorObjectBase, ) - -logging.basicConfig( - format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO -) - - class AuthoredProfile(AuthorObjectBase): """ Functions for authoring OSCAL Profiles in automation diff --git a/trestlebot/tasks/authored/ssp.py b/trestlebot/tasks/authored/ssp.py index 3406c145..8c1bbaaa 100644 --- a/trestlebot/tasks/authored/ssp.py +++ b/trestlebot/tasks/authored/ssp.py @@ -17,9 +17,7 @@ """Trestle Bot functions for SSP authoring""" import argparse -import logging import os -import sys from typing import Dict from trestle.common.err import TrestleError @@ -31,12 +29,6 @@ AuthorObjectBase, ) - -logging.basicConfig( - format="%(levelname)s - %(message)s", stream=sys.stdout, level=logging.INFO -) - - class AuthoredSSP(AuthorObjectBase): """ Functions for authoring OSCAL SSPs in automation