Merge pull request #7227 from bluetech/logging-reuse-handler

logging: reuse LoggingCaptureHandler instance since it's expensive to create

Author: bluetech

src/_pytest/logging.py

@@ -27,7 +27,7 @@
 DEFAULT_LOG_DATE_FORMAT = "%H:%M:%S"
 _ANSI_ESCAPE_SEQ = re.compile(r"\x1b\[[\d;]+m")
 catch_log_handler_key = StoreKey["LogCaptureHandler"]()
-catch_log_handlers_key = StoreKey[Dict[str, "LogCaptureHandler"]]()
+catch_log_records_key = StoreKey[Dict[str, List[logging.LogRecord]]]()
 
 
 def _remove_ansi_escape_sequences(text):
@@ -351,11 +351,7 @@ def get_records(self, when: str) -> List[logging.LogRecord]:
 
         .. versionadded:: 3.4
         """
-        handler = self._item._store[catch_log_handlers_key].get(when)
-        if handler:
-            return handler.records
-        else:
-            return []
+        return self._item._store[catch_log_records_key].get(when, [])
 
     @property
     def text(self):
@@ -497,6 +493,8 @@ def __init__(self, config: Config) -> None:
             get_option_ini(config, "log_auto_indent"),
         )
         self.log_level = get_log_level_for_setting(config, "log_level")
+        self.log_handler = LogCaptureHandler()
+        self.log_handler.setFormatter(self.formatter)
 
         # File logging.
         self.log_file_level = get_log_level_for_setting(config, "log_file_level")
@@ -639,10 +637,9 @@ def pytest_runtest_logreport(self):
 
     def _runtest_for(self, item: nodes.Item, when: str) -> Generator[None, None, None]:
         """Implements the internals of pytest_runtest_xxx() hook."""
-        log_handler = LogCaptureHandler()
-        log_handler.setFormatter(self.formatter)
-        with catching_logs(log_handler, level=self.log_level):
-            item._store[catch_log_handlers_key][when] = log_handler
+        with catching_logs(self.log_handler, level=self.log_level) as log_handler:
+            log_handler.reset()
+            item._store[catch_log_records_key][when] = log_handler.records
             item._store[catch_log_handler_key] = log_handler
 
             yield
@@ -654,8 +651,7 @@ def _runtest_for(self, item: nodes.Item, when: str) -> Generator[None, None, Non
     def pytest_runtest_setup(self, item):
         self.log_cli_handler.set_when("setup")
 
-        empty = {}  # type: Dict[str, LogCaptureHandler]
-        item._store[catch_log_handlers_key] = empty
+        item._store[catch_log_records_key] = {}
         yield from self._runtest_for(item, "setup")
 
     @pytest.hookimpl(hookwrapper=True)
@@ -669,7 +665,7 @@ def pytest_runtest_teardown(self, item):
         self.log_cli_handler.set_when("teardown")
 
         yield from self._runtest_for(item, "teardown")
-        del item._store[catch_log_handlers_key]
+        del item._store[catch_log_records_key]
         del item._store[catch_log_handler_key]
 
     @pytest.hookimpl

testing/logging/test_fixture.py

@@ -1,7 +1,7 @@
 import logging
 
 import pytest
-from _pytest.logging import catch_log_handlers_key
+from _pytest.logging import catch_log_records_key
 
 logger = logging.getLogger(__name__)
 sublogger = logging.getLogger(__name__ + ".baz")
@@ -137,4 +137,4 @@ def test_caplog_captures_for_all_stages(caplog, logging_during_setup_and_teardow
     assert [x.message for x in caplog.get_records("setup")] == ["a_setup_log"]
 
     # This reaches into private API, don't use this type of thing in real tests!
-    assert set(caplog._item._store[catch_log_handlers_key]) == {"setup", "call"}
+    assert set(caplog._item._store[catch_log_records_key]) == {"setup", "call"}