From f062889bef7bcceb824c96d4ef5bd989fe17beee Mon Sep 17 00:00:00 2001 From: shouzy <82171453+realshouzy@users.noreply.github.com> Date: Tue, 11 Jun 2024 00:33:19 +0200 Subject: [PATCH] Adjust tests for new logging --- tests/fixtures.py | 42 +++++++++++---- tests/logging_test.py | 108 +++++++++++++++++++++++++++------------ tests/pip_purge_test.py | 40 ++++++++++----- tests/pip_review_test.py | 37 ++++++++------ 4 files changed, 155 insertions(+), 72 deletions(-) diff --git a/tests/fixtures.py b/tests/fixtures.py index 8947c49d..a1ea999a 100644 --- a/tests/fixtures.py +++ b/tests/fixtures.py @@ -1,15 +1,44 @@ from __future__ import annotations +import logging +import logging.config +from functools import wraps from types import SimpleNamespace -from typing import TYPE_CHECKING +from typing import Callable, ParamSpec, TypeVar import pytest -from pip_manage._logging import setup_logging from pip_manage._pip_interface import _OutdatedPackage -if TYPE_CHECKING: - import logging +_P = ParamSpec("_P") +_R = TypeVar("_R") + + +# https://github.com/pytest-dev/pytest/discussions/11618 +def retain_pytest_handlers(f: Callable[_P, _R]) -> Callable[_P, _R]: + @wraps(f) + def wrapper(*args: _P.args, **kwargs: _P.kwargs) -> _R: + pytest_handlers: list[logging.Handler] = [ + handler + for handler in logging.root.handlers + if handler.__module__ == "_pytest.logging" + ] + ret: _R = f(*args, **kwargs) + for handler in pytest_handlers: + if handler not in logging.root.handlers: + logging.root.addHandler(handler) + return ret + + return wrapper + + +@pytest.fixture(autouse=True) +def _keep_pytest_handlers_during_dict_config(monkeypatch: pytest.MonkeyPatch) -> None: + monkeypatch.setattr( + logging.config, + "dictConfig", + retain_pytest_handlers(logging.config.dictConfig), + ) @pytest.fixture() @@ -29,11 +58,6 @@ def sample_subprocess_output() -> bytes: ) -@pytest.fixture(scope="session") -def logger() -> logging.Logger: - return setup_logging("test") - - @pytest.fixture() def dummy_dependencies() -> list[SimpleNamespace]: package_a: SimpleNamespace = SimpleNamespace( diff --git a/tests/logging_test.py b/tests/logging_test.py index 77c304e3..992d0301 100755 --- a/tests/logging_test.py +++ b/tests/logging_test.py @@ -5,16 +5,15 @@ import pytest -from pip_manage._logging import _StdOutFilter, set_logging_level -from tests.fixtures import logger # pylint: disable=W0611 +from pip_manage._logging import _ColoredFormatter, _NonErrorFilter, setup_logging def test_stdout_filter_is_subclass_of_logging_filter() -> None: - assert issubclass(_StdOutFilter, logging.Filter) + assert issubclass(_NonErrorFilter, logging.Filter) def test_stdout_filter_override() -> None: - assert _StdOutFilter().filter.__override__ + assert getattr(_NonErrorFilter().filter, "__override__", False) @pytest.mark.parametrize( @@ -28,7 +27,7 @@ def test_stdout_filter_override() -> None: 0, "test", None, - (None, None, None), + None, ), id="DEBUG", ), @@ -40,14 +39,14 @@ def test_stdout_filter_override() -> None: 0, "test", None, - (None, None, None), + None, ), id="INFO", ), ], ) def test_stdout_filter_passes(record: logging.LogRecord) -> None: - assert _StdOutFilter().filter(record) + assert _NonErrorFilter().filter(record) @pytest.mark.parametrize( @@ -61,7 +60,7 @@ def test_stdout_filter_passes(record: logging.LogRecord) -> None: 0, "test", None, - (None, None, None), + None, ), id="WARNING", ), @@ -73,7 +72,7 @@ def test_stdout_filter_passes(record: logging.LogRecord) -> None: 0, "test", None, - (None, None, None), + None, ), id="ERROR", ), @@ -85,50 +84,91 @@ def test_stdout_filter_passes(record: logging.LogRecord) -> None: 0, "test", None, - (None, None, None), + None, ), id="CRITICAL", ), ], ) def test_stdout_filter_no_passes(record: logging.LogRecord) -> None: - assert not _StdOutFilter().filter(record) + assert not _NonErrorFilter().filter(record) -def test_setup_logging(logger: logging.Logger) -> None: - assert logger.name == "test" - assert logger.level == logging.NOTSET - assert len(logger.handlers) == 2 +def test_colored_formatter_is_subclass_of_logging_formatter() -> None: + assert issubclass(_ColoredFormatter, logging.Formatter) - stderr_handler: logging.Handler = logger.handlers[0] - assert stderr_handler.name == "stderr" - assert stderr_handler.level == logging.WARNING - assert stderr_handler.formatter._fmt == "%(levelname)s: %(message)s" # type: ignore[union-attr] - stdout_handler: logging.Handler = logger.handlers[1] - assert stdout_handler.name == "stdout" - assert stdout_handler.level == logging.DEBUG - assert stdout_handler.formatter._fmt == "%(message)s" # type: ignore[union-attr] - assert len(stdout_handler.filters) == 1 - assert isinstance(stdout_handler.filters[0], _StdOutFilter) +def test_colored_formatter_override() -> None: + assert getattr(_ColoredFormatter().format, "__override__", False) + + +def test_colored_formatter_class_vars() -> None: + assert { + "DEBUG": "\x1b[0;37m", + "INFO": "\x1b[0;32m", + "WARNING": "\x1b[0;33m", + "ERROR": "\x1b[0;31m", + "CRITICAL": "\x1b[1;31m", + } == _ColoredFormatter.COLORS + assert _ColoredFormatter.RESET == "\x1b[0m" - logger.handlers.clear() + +@pytest.mark.parametrize( + ("level", "prefix"), + [ + (logging.DEBUG, "\x1b[0;37mDEBUG"), + (logging.INFO, "\x1b[0;32mINFO"), + (logging.WARNING, "\x1b[0;33mWARNING"), + (logging.ERROR, "\x1b[0;31mERROR"), + (logging.CRITICAL, "\x1b[1;31mCRITICAL"), + ], +) +def test_colored_formatter_format(level: int, prefix: str) -> None: + test_record: logging.LogRecord = logging.LogRecord( + "test", + level, + "test", + 0, + "test", + None, + None, + ) + assert _ColoredFormatter().format(test_record) == f"{prefix}: test\x1b[0m" @pytest.mark.parametrize( - ("verbose", "logger_level"), + ("verbose", "level"), [ pytest.param(True, logging.DEBUG, id="verbose"), pytest.param(False, logging.INFO, id="non_verbose"), ], ) -def test_set_logging_level( - logger: logging.Logger, - verbose: bool, # noqa: FBT001 - logger_level: int, -) -> None: - set_logging_level(logger, verbose=verbose) - assert logger.level == logger_level +def test_setup_logging(verbose: bool, level: int) -> None: # noqa: FBT001 + setup_logging("test", verbose=verbose) + root_logger: logging.Logger = logging.getLogger() + assert root_logger.level == logging.DEBUG + assert len(root_logger.handlers) == 2 + + stdout_handler: logging.Handler = root_logger.handlers[0] + assert stdout_handler.name == "stdout" + assert stdout_handler.level == logging.DEBUG + assert isinstance(stdout_handler.formatter, logging.Formatter) + assert stdout_handler.formatter._fmt == "%(message)s" + assert len(stdout_handler.filters) == 1 + assert isinstance(stdout_handler.filters[0], _NonErrorFilter) + + stderr_handler: logging.Handler = root_logger.handlers[1] + assert stderr_handler.name == "stderr" + assert stderr_handler.level == logging.WARNING + assert isinstance(stderr_handler.formatter, _ColoredFormatter) + assert stderr_handler.formatter._fmt == "%(message)s" + assert not stderr_handler.filters + + test_logger: logging.Logger = logging.getLogger("test") + assert test_logger.level == level + assert test_logger.propagate + assert not test_logger.handlers + assert not test_logger.filters if __name__ == "__main__": diff --git a/tests/pip_purge_test.py b/tests/pip_purge_test.py index e9b2d2ec..0a754c1c 100755 --- a/tests/pip_purge_test.py +++ b/tests/pip_purge_test.py @@ -13,7 +13,10 @@ from pip_manage import pip_purge from pip_manage._pip_interface import PIP_CMD -from tests.fixtures import dummy_dependencies # pylint: disable=W0611 +from tests.fixtures import ( # pylint: disable=W0611 + _keep_pytest_handlers_during_dict_config, + dummy_dependencies, +) def _raise_package_not_found_error_when_package_c(package: str) -> None: @@ -52,11 +55,6 @@ def test_constants( assert constant == expected -def test_default_settings_pip_purge_logger() -> None: - assert pip_purge._logger.name == "pip-purge" - assert len(pip_purge._logger.handlers) == 2 - - def test_parse_args_empty_args() -> None: assert pip_purge._parse_args([]) == ( argparse.Namespace( @@ -428,7 +426,7 @@ def test_main_verbose_flag_sets_logger_level_to_debug( "subprocess.call", ) as mock_subprocess_call: exit_code: int = pip_purge.main(["package_a", arg]) - assert pip_purge._logger.level == logging.DEBUG + assert logging.getLogger("pip-purge").level == logging.DEBUG mock_subprocess_call.assert_called_once_with( [*PIP_CMD, "uninstall", "package_a", "package_b", "package_e"], stdout=sys.stdout, @@ -453,7 +451,7 @@ def test_main_no_verbose_flag_sets_logger_level_to_info( "subprocess.call", ) as mock_subprocess_call: exit_code: int = pip_purge.main(["package_a"]) - assert pip_purge._logger.level == logging.INFO + assert logging.getLogger("pip-purge").level == logging.INFO mock_subprocess_call.assert_called_once_with( [*PIP_CMD, "uninstall", "package_a", "package_b", "package_e"], stdout=sys.stdout, @@ -473,7 +471,14 @@ def test_main_error_exit_when_no_packages_provided( "subprocess.call", ) as mock_subprocess_call: exit_code: int = pip_purge.main([]) - assert caplog.record_tuples == [("pip-purge", 40, "No packages provided")] + assert caplog.record_tuples == [ + ( + "pip-purge", + 40, + "\x1b[0;31mERROR: You must give at least one requirement to " + "uninstall\x1b[0m", + ), + ] mock_subprocess_call.assert_not_called() assert exit_code == 1 @@ -492,9 +497,14 @@ def test_main_warn_about_unrecognized_args_before_error_exit_when_no_packages_pr assert ( "pip-purge", 30, - "Unrecognized arguments: '-a', '-b'", + "\x1b[0;33mWARNING: Unrecognized arguments: '-a', '-b'\x1b[0m", + ) in caplog.record_tuples + assert ( + "pip-purge", + 40, + "\x1b[0;31mERROR: You must give at least one requirement to " + "uninstall\x1b[0m", ) in caplog.record_tuples - assert ("pip-purge", 40, "No packages provided") in caplog.record_tuples mock_subprocess_call.assert_not_called() assert exit_code == 1 @@ -519,7 +529,7 @@ def test_main_warn_about_unrecognized_args( assert ( "pip-purge", 30, - "Unrecognized arguments: '-a', '-b'", + "\x1b[0;33mWARNING: Unrecognized arguments: '-a', '-b'\x1b[0m", ) in caplog.record_tuples mock_subprocess_call.assert_called_once_with( [*PIP_CMD, "uninstall", "-y", "package_a", "package_b", "package_e"], @@ -547,7 +557,11 @@ def test_main_warn_about_not_installed_packages( ): exit_code: int = pip_purge.main(["package_a", "package_x"]) assert caplog.record_tuples == [ - ("pip-purge", 30, "package_x is not installed"), + ( + "pip-purge", + 30, + "\x1b[0;33mWARNING: Skipping package_x as it is not installed\x1b[0m", + ), ( "pip-purge", 20, diff --git a/tests/pip_review_test.py b/tests/pip_review_test.py index 092da129..d2e3e8bd 100755 --- a/tests/pip_review_test.py +++ b/tests/pip_review_test.py @@ -11,7 +11,11 @@ from pip_manage import pip_review from pip_manage._pip_interface import PIP_CMD, _OutdatedPackage -from tests.fixtures import sample_packages, sample_subprocess_output +from tests.fixtures import ( # pylint: disable=W0611 + _keep_pytest_handlers_during_dict_config, + sample_packages, + sample_subprocess_output, +) # pylint: disable=W0212, E1101, W0621, C0302, R0913, C0301 @@ -56,11 +60,6 @@ def test_constants( assert constant == expected -def test_default_settings_pip_review_logger() -> None: - assert pip_review._logger.name == "pip-review" - assert len(pip_review._logger.handlers) == 2 - - def test_parse_args_empty_args() -> None: assert pip_review._parse_args([]) == ( argparse.Namespace( @@ -431,7 +430,7 @@ def test_main_verbose_flag_sets_logger_level_to_debug( "subprocess.call", ) as mock_subprocess_call: exit_code: int = pip_review.main([arg]) - assert pip_review._logger.level == logging.DEBUG + assert logging.getLogger("pip-review").level == logging.DEBUG mock_subprocess_call.assert_not_called() assert exit_code == 0 @@ -452,7 +451,7 @@ def test_main_no_verbose_flag_sets_logger_level_to_info( "subprocess.call", ) as mock_subprocess_call: exit_code: int = pip_review.main([]) - assert pip_review._logger.level == logging.INFO + assert logging.getLogger("pip-review").level == logging.INFO mock_subprocess_call.assert_not_called() assert exit_code == 0 @@ -460,14 +459,17 @@ def test_main_no_verbose_flag_sets_logger_level_to_info( @pytest.mark.parametrize( ("args", "err_msg"), [ - (["--raw", "--auto"], "'--raw' and '--auto' cannot be used together"), + ( + ["--raw", "--auto"], + "\x1b[0;31mERROR: '--raw' and '--auto' cannot be used together\x1b[0m", + ), ( ["--raw", "--interactive"], - "'--raw' and '--interactive' cannot be used together", + "\x1b[0;31mERROR: '--raw' and '--interactive' cannot be used together\x1b[0m", ), ( ["--auto", "--interactive"], - "'--auto' and '--interactive' cannot be used together", + "\x1b[0;31mERROR: '--auto' and '--interactive' cannot be used together\x1b[0m", ), ], ) @@ -502,7 +504,7 @@ def test_main_warn_about_unrecognized_args( assert ( "pip-review", 30, - "Unrecognized arguments: '-x'", + "\x1b[0;33mWARNING: Unrecognized arguments: '-x'\x1b[0m", ) in caplog.record_tuples expected_cmd: list[str] = [ *PIP_CMD, @@ -522,14 +524,17 @@ def test_main_warn_about_unrecognized_args( @pytest.mark.parametrize( ("args", "err_msg"), [ - (["--raw", "--auto"], "'--raw' and '--auto' cannot be used together"), + ( + ["--raw", "--auto"], + "\x1b[0;31mERROR: '--raw' and '--auto' cannot be used together\x1b[0m", + ), ( ["--raw", "--interactive"], - "'--raw' and '--interactive' cannot be used together", + "\x1b[0;31mERROR: '--raw' and '--interactive' cannot be used together\x1b[0m", ), ( ["--auto", "--interactive"], - "'--auto' and '--interactive' cannot be used together", + "\x1b[0;31mERROR: '--auto' and '--interactive' cannot be used together\x1b[0m", ), ], ) @@ -543,7 +548,7 @@ def test_main_mutually_warn_about_unrecognized_args_before_exclusive_args_error( ( "pip-review", 30, - "Unrecognized arguments: '-x'", + "\x1b[0;33mWARNING: Unrecognized arguments: '-x'\x1b[0m", ), ("pip-review", 40, err_msg), ]