From d2d11a8bdcd382b0ac1e75af0a36cf826bcc3fa0 Mon Sep 17 00:00:00 2001 From: Ran Benita Date: Wed, 13 May 2020 01:29:25 +0300 Subject: [PATCH] logging: reuse LoggingCaptureHandler instance since it's expensive to create Previously, a LoggingCaptureHandler was instantiated for each test's setup/call/teardown which turns out to be expensive. Instead, only keep one instance and reset it between runs. --- src/_pytest/logging.py | 22 +++++++++------------- testing/logging/test_fixture.py | 4 ++-- 2 files changed, 11 insertions(+), 15 deletions(-) diff --git a/src/_pytest/logging.py b/src/_pytest/logging.py index f69bcba89..e2f691a31 100644 --- a/src/_pytest/logging.py +++ b/src/_pytest/logging.py @@ -27,7 +27,7 @@ DEFAULT_LOG_FORMAT = "%(levelname)-8s %(name)s:%(filename)s:%(lineno)d %(message 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 @@ class LogCaptureFixture: .. 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 @@ class LoggingPlugin: 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 @@ class LoggingPlugin: 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 @@ class LoggingPlugin: 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 @@ class LoggingPlugin: 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 diff --git a/testing/logging/test_fixture.py b/testing/logging/test_fixture.py index a33b0e80e..657ffb4dd 100644 --- a/testing/logging/test_fixture.py +++ b/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"}