diff --git a/AUTHORS b/AUTHORS index 96c434d6a6d..65b7d78c522 100644 --- a/AUTHORS +++ b/AUTHORS @@ -12,6 +12,7 @@ Adam Uhlir Ahn Ki-Wook Akiomi Kamakura Alan Velasco +Alex Lambson Alexander Johnson Alexander King Alexei Kozlenok diff --git a/changelog/8711.improvement.rst b/changelog/8711.improvement.rst new file mode 100644 index 00000000000..20805e9f94d --- /dev/null +++ b/changelog/8711.improvement.rst @@ -0,0 +1,3 @@ +:func:`_pytest.logging.LogCaptureFixture.set_level` and :func:`_pytest.logging.LogCaptureFixture.at_level` +will temporarily enable the requested ``level`` if ``level`` was disabled globally via +``logging.disable(LEVEL)``. diff --git a/src/_pytest/logging.py b/src/_pytest/logging.py index 7f73b8a4685..098a4961f71 100644 --- a/src/_pytest/logging.py +++ b/src/_pytest/logging.py @@ -368,11 +368,12 @@ def __init__(self, item: nodes.Node, *, _ispytest: bool = False) -> None: self._initial_handler_level: Optional[int] = None # Dict of log name -> log level. self._initial_logger_levels: Dict[Optional[str], int] = {} + self._initial_disabled_logging_level: Optional[int] = None def _finalize(self) -> None: """Finalize the fixture. - This restores the log levels changed by :meth:`set_level`. + This restores the log levels and the disabled logging levels changed by :meth:`set_level`. """ # Restore log levels. if self._initial_handler_level is not None: @@ -380,6 +381,10 @@ def _finalize(self) -> None: for logger_name, level in self._initial_logger_levels.items(): logger = logging.getLogger(logger_name) logger.setLevel(level) + # Disable logging at the original disabled logging level. + if self._initial_disabled_logging_level is not None: + logging.disable(self._initial_disabled_logging_level) + self._initial_disabled_logging_level = None @property def handler(self) -> LogCaptureHandler: @@ -446,6 +451,39 @@ def clear(self) -> None: """Reset the list of log records and the captured log text.""" self.handler.reset() + def force_enable_logging( + self, level: Union[int, str], logger_obj: logging.Logger + ) -> int: + """Enable the desired logging level if the level was disabled. + + Only enables logging levels equal too and higher than the requested ``level``. + + Does nothing if the desired ``level`` wasn't disabled. + + :param Union[int, str] level: + The logger level caplog should capture. + All logging is enabled if a non-standard logging level string is supplied. + Valid level strings are in :data:`logging._nameToLevel`. + :param Logger logger_obj: The logger object to check. + + :return int: The original disabled logging level. + """ + original_disable_level: int = logger_obj.manager.disable # type: ignore[attr-defined] + + if isinstance(level, str): + level = logging.getLevelName(level) + + if not isinstance(level, int): + logging.disable(logging.NOTSET) + return original_disable_level + if logger_obj.isEnabledFor(level): + return original_disable_level + + disable_level = max(level - 10, logging.NOTSET) + logging.disable(disable_level) + + return original_disable_level + def set_level(self, level: Union[int, str], logger: Optional[str] = None) -> None: """Set the level of a logger for the duration of a test. @@ -453,6 +491,8 @@ def set_level(self, level: Union[int, str], logger: Optional[str] = None) -> Non The levels of the loggers changed by this function will be restored to their initial values at the end of the test. + Will enable the requesed logging level if it was disabled via :meth:`logging.disable`. + :param int level: The level. :param str logger: The logger to update. If not given, the root logger. """ @@ -463,6 +503,9 @@ def set_level(self, level: Union[int, str], logger: Optional[str] = None) -> Non if self._initial_handler_level is None: self._initial_handler_level = self.handler.level self.handler.setLevel(level) + initial_disabled_logging_level = self.force_enable_logging(level, logger_obj) + if self._initial_disabled_logging_level is None: + self._initial_disabled_logging_level = initial_disabled_logging_level @contextmanager def at_level( @@ -472,6 +515,8 @@ def at_level( the end of the 'with' statement the level is restored to its original value. + Will enable the requesed logging level if it was disabled via :meth:`logging.disable`. + :param int level: The level. :param str logger: The logger to update. If not given, the root logger. """ @@ -480,11 +525,13 @@ def at_level( logger_obj.setLevel(level) handler_orig_level = self.handler.level self.handler.setLevel(level) + original_disable_level = self.force_enable_logging(level, logger_obj) try: yield finally: logger_obj.setLevel(orig_level) self.handler.setLevel(handler_orig_level) + logging.disable(original_disable_level) @fixture diff --git a/testing/logging/test_fixture.py b/testing/logging/test_fixture.py index bcb20de5805..e188507508a 100644 --- a/testing/logging/test_fixture.py +++ b/testing/logging/test_fixture.py @@ -1,3 +1,4 @@ +# type: ignore[attr-defined] import logging import pytest @@ -28,10 +29,30 @@ def test_change_level(caplog): assert "CRITICAL" in caplog.text +def test_change_level_logging_disabled(caplog): + logging.disable(logging.CRITICAL) + assert logging.root.manager.disable == logging.CRITICAL + caplog.set_level(logging.WARNING) + logger.info("handler INFO level") + logger.warning("handler WARNING level") + + caplog.set_level(logging.CRITICAL, logger=sublogger.name) + sublogger.warning("logger SUB_WARNING level") + sublogger.critical("logger SUB_CRITICAL level") + + assert "INFO" not in caplog.text + assert "WARNING" in caplog.text + assert "SUB_WARNING" not in caplog.text + assert "SUB_CRITICAL" in caplog.text + + # logging.disable needs to be reset because it's global and causes future tests will break. + logging.disable(logging.NOTSET) + + def test_change_level_undo(pytester: Pytester) -> None: """Ensure that 'set_level' is undone after the end of the test. - Tests the logging output themselves (affacted both by logger and handler levels). + Tests the logging output themselves (affected both by logger and handler levels). """ pytester.makepyfile( """ @@ -54,6 +75,38 @@ def test2(caplog): result.stdout.no_fnmatch_line("*log from test2*") +def test_change_disabled_level_undo(pytester: Pytester) -> None: + """Ensure that 'force_enable_logging' in 'set_level' is undone after the end of the test. + + Tests the logging output themselves (affected by disabled logging level). + """ + pytester.makepyfile( + """ + import logging + + def test1(caplog): + logging.disable(logging.CRITICAL) + caplog.set_level(logging.INFO) + # using + operator here so fnmatch_lines doesn't match the code in the traceback + logging.info('log from ' + 'test1') + assert 0 + + def test2(caplog): + # using + operator here so fnmatch_lines doesn't match the code in the traceback + # use logging.warning because we need a level that will show up if logging.disabled + # isn't reset to ``CRITICAL`` after test1. + logging.warning('log from ' + 'test2') + assert 0 + """ + ) + result = pytester.runpytest() + result.stdout.fnmatch_lines(["*log from test1*", "*2 failed in *"]) + result.stdout.no_fnmatch_line("*log from test2*") + + # logging.disable needs to be reset because it's global and causes future tests will break. + logging.disable(logging.NOTSET) + + def test_change_level_undos_handler_level(pytester: Pytester) -> None: """Ensure that 'set_level' is undone after the end of the test (handler). @@ -97,6 +150,35 @@ def test_with_statement(caplog): assert "CRITICAL" in caplog.text +def test_with_statement_logging_disabled(caplog): + logging.disable(logging.CRITICAL) + assert logging.root.manager.disable == logging.CRITICAL + with caplog.at_level(logging.WARNING): + logger.debug("handler DEBUG level") + logger.info("handler INFO level") + logger.warning("handler WARNING level") + logger.error("handler ERROR level") + logger.critical("handler CRITICAL level") + + assert logging.root.manager.disable == logging.INFO + + with caplog.at_level(logging.CRITICAL, logger=sublogger.name): + sublogger.warning("logger SUB_WARNING level") + sublogger.critical("logger SUB_CRITICAL level") + + assert "DEBUG" not in caplog.text + assert "INFO" not in caplog.text + assert "WARNING" in caplog.text + assert "ERROR" in caplog.text + assert " CRITICAL" in caplog.text + assert "SUB_WARNING" not in caplog.text + assert "SUB_CRITICAL" in caplog.text + assert logging.root.manager.disable == logging.CRITICAL + + # logging.disable needs to be reset because it's global and causes future tests will break. + logging.disable(logging.NOTSET) + + def test_log_access(caplog): caplog.set_level(logging.INFO) logger.info("boo %s", "arg")