From 2626bf135960c7bf1f4958dedd1d6fbe9efbb04b Mon Sep 17 00:00:00 2001 From: Jennifer Power Date: Mon, 28 Aug 2023 17:21:17 -0400 Subject: [PATCH 1/2] refactor: updates logging to import log logic from trestle Signed-off-by: Jennifer Power --- trestlebot/bot.py | 2 +- trestlebot/cli.py | 6 +- trestlebot/log.py | 134 ------------------------------- trestlebot/tasks/authored/ssp.py | 2 +- 4 files changed, 6 insertions(+), 138 deletions(-) delete mode 100644 trestlebot/log.py diff --git a/trestlebot/bot.py b/trestlebot/bot.py index 8ff79f28..c7ef6d28 100644 --- a/trestlebot/bot.py +++ b/trestlebot/bot.py @@ -27,7 +27,7 @@ from trestlebot.tasks.base_task import TaskBase, TaskException -logger = logging.getLogger("trestle") +logger = logging.getLogger(__name__) class RepoException(Exception): diff --git a/trestlebot/cli.py b/trestlebot/cli.py index 399632f5..1a2aa565 100644 --- a/trestlebot/cli.py +++ b/trestlebot/cli.py @@ -22,7 +22,9 @@ import sys from typing import List, Optional -from trestlebot import bot, const, log +import trestle.common.log as log + +from trestlebot import bot, const from trestlebot.github import GitHub, is_github_actions from trestlebot.gitlab import GitLab, get_gitlab_root_url, is_gitlab_ci from trestlebot.provider import GitProvider @@ -32,7 +34,7 @@ from trestlebot.tasks.regenerate_task import RegenerateTask -logger = logging.getLogger("trestle") +logger = logging.getLogger(__name__) def _parse_cli_arguments() -> argparse.Namespace: diff --git a/trestlebot/log.py b/trestlebot/log.py deleted file mode 100644 index 80207bdb..00000000 --- a/trestlebot/log.py +++ /dev/null @@ -1,134 +0,0 @@ -# -*- 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 'trestle' or __name__ -_logger = logging.getLogger("trestle") - - -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/ssp.py b/trestlebot/tasks/authored/ssp.py index 0ed00fcd..e1a44340 100644 --- a/trestlebot/tasks/authored/ssp.py +++ b/trestlebot/tasks/authored/ssp.py @@ -34,7 +34,7 @@ ) -logger = logging.getLogger("trestle") +logger = logging.getLogger(__name__) class SSPIndex: From e31926304d66d9c32f40d6befd96beca8348cb77 Mon Sep 17 00:00:00 2001 From: Jennifer Power Date: Mon, 28 Aug 2023 17:36:30 -0400 Subject: [PATCH 2/2] test: update cli unit tests to read error from log Signed-off-by: Jennifer Power --- tests/trestlebot/test_cli.py | 44 ++++++++++++++++++++---------------- 1 file changed, 24 insertions(+), 20 deletions(-) diff --git a/tests/trestlebot/test_cli.py b/tests/trestlebot/test_cli.py index be6f1776..4d3a5a35 100644 --- a/tests/trestlebot/test_cli.py +++ b/tests/trestlebot/test_cli.py @@ -16,6 +16,7 @@ """Test for CLI""" +import logging import sys from typing import List from unittest.mock import patch @@ -47,7 +48,7 @@ def args_dict_to_list(args_dict: dict) -> List[str]: return args -def test_invalid_oscal_model(monkeypatch, valid_args_dict, capsys): +def test_invalid_oscal_model(monkeypatch, valid_args_dict, caplog): """Test invalid oscal model""" args_dict = valid_args_dict args_dict["oscal-model"] = "fake" @@ -56,14 +57,15 @@ def test_invalid_oscal_model(monkeypatch, valid_args_dict, capsys): with pytest.raises(SystemExit): cli_main() - captured = capsys.readouterr() - assert ( - "Invalid value fake for oscal model. Please use catalog, profile, compdef, or ssp." - in captured.err + assert any( + record.levelno == logging.ERROR + and record.message + == "Invalid value fake for oscal model. Please use catalog, profile, compdef, or ssp." + for record in caplog.records ) -def test_no_ssp_index(monkeypatch, valid_args_dict, capsys): +def test_no_ssp_index(monkeypatch, valid_args_dict, caplog): """Test missing index file for ssp""" args_dict = valid_args_dict args_dict["oscal-model"] = "ssp" @@ -73,12 +75,14 @@ def test_no_ssp_index(monkeypatch, valid_args_dict, capsys): with pytest.raises(SystemExit): cli_main() - captured = capsys.readouterr() - - assert "Must set ssp_index_path when using SSP as oscal model." in captured.err + assert any( + record.levelno == logging.ERROR + and record.message == "Must set ssp_index_path when using SSP as oscal model." + for record in caplog.records + ) -def test_no_markdown_path(monkeypatch, valid_args_dict, capsys): +def test_no_markdown_path(monkeypatch, valid_args_dict, caplog): """Test without a markdown file passed as a flag""" args_dict = valid_args_dict args_dict["markdown-path"] = "" @@ -87,12 +91,14 @@ def test_no_markdown_path(monkeypatch, valid_args_dict, capsys): with pytest.raises(SystemExit): cli_main() - captured = capsys.readouterr() - - assert "Must set markdown path with oscal model." in captured.err + assert any( + record.levelno == logging.ERROR + and record.message == "Must set markdown path with oscal model." + for record in caplog.records + ) -def test_with_target_branch(monkeypatch, valid_args_dict, capsys): +def test_with_target_branch(monkeypatch, valid_args_dict, caplog): """Test with target branch set an an unsupported Git provider""" args_dict = valid_args_dict args_dict["target-branch"] = "main" @@ -106,13 +112,11 @@ def test_with_target_branch(monkeypatch, valid_args_dict, capsys): with pytest.raises(SystemExit): cli_main() - captured = capsys.readouterr() - - expected_string = ( - "target-branch flag is set with an unset git provider. " + assert any( + record.levelno == logging.ERROR + and record.message == "target-branch flag is set with an unset git provider. " "To test locally, set the GITHUB_ACTIONS or GITLAB_CI environment variable." + for record in caplog.records ) - assert expected_string in captured.err - mock_check.assert_called_once()