logging: simplify log-file handling

- Instead of making it optional, always set up a handler, but possibly
  going to /dev/null. This simplifies the code by removing a lot of
  conditionals. It also can replace the NullHandler() we already add.

- Change `set_log_path` to just change the stream, instead of recreating
  one. Besides plugging a resource leak, it enables the next item.

- Remove the capturing_logs from _runtest_for, since it sufficiently
  covered by the one in pytest_runtestloop now, which wraps all other
  _runtest_for calls.

The first item alone would have had an adverse performance impact, but
the last item removes it.
This commit is contained in:
Ran Benita 2020-05-17 14:58:04 +03:00
parent e48ac692de
commit 075903dafa
1 changed files with 39 additions and 55 deletions

View File

@ -1,6 +1,8 @@
""" Access and control log capturing. """ """ Access and control log capturing. """
import logging import logging
import os
import re import re
import sys
from contextlib import contextmanager from contextlib import contextmanager
from io import StringIO from io import StringIO
from typing import AbstractSet from typing import AbstractSet
@ -503,6 +505,7 @@ class LoggingPlugin:
_issue_warning_captured(NO_PRINT_LOGS, self._config.hook, stacklevel=2) _issue_warning_captured(NO_PRINT_LOGS, self._config.hook, stacklevel=2)
# Report logging.
self.formatter = self._create_formatter( self.formatter = self._create_formatter(
get_option_ini(config, "log_format"), get_option_ini(config, "log_format"),
get_option_ini(config, "log_date_format"), get_option_ini(config, "log_date_format"),
@ -510,24 +513,22 @@ class LoggingPlugin:
) )
self.log_level = get_log_level_for_setting(config, "log_level") self.log_level = get_log_level_for_setting(config, "log_level")
# File logging.
self.log_file_level = get_log_level_for_setting(config, "log_file_level") self.log_file_level = get_log_level_for_setting(config, "log_file_level")
self.log_file_format = get_option_ini(config, "log_file_format", "log_format") log_file = get_option_ini(config, "log_file") or os.devnull
self.log_file_date_format = get_option_ini(
config, "log_file_date_format", "log_date_format"
)
self.log_file_formatter = logging.Formatter(
self.log_file_format, datefmt=self.log_file_date_format
)
log_file = get_option_ini(config, "log_file")
if log_file:
self.log_file_handler = logging.FileHandler( self.log_file_handler = logging.FileHandler(
log_file, mode="w", encoding="UTF-8" log_file, mode="w", encoding="UTF-8"
) # type: Optional[logging.FileHandler] )
self.log_file_handler.setFormatter(self.log_file_formatter) log_file_format = get_option_ini(config, "log_file_format", "log_format")
else: log_file_date_format = get_option_ini(
self.log_file_handler = None config, "log_file_date_format", "log_date_format"
)
log_file_formatter = logging.Formatter(
log_file_format, datefmt=log_file_date_format
)
self.log_file_handler.setFormatter(log_file_formatter)
# CLI/live logging.
if self._log_cli_enabled(): if self._log_cli_enabled():
self._setup_cli_logging() self._setup_cli_logging()
else: else:
@ -592,10 +593,19 @@ class LoggingPlugin:
if not fname.parent.exists(): if not fname.parent.exists():
fname.parent.mkdir(exist_ok=True, parents=True) fname.parent.mkdir(exist_ok=True, parents=True)
self.log_file_handler = logging.FileHandler( stream = fname.open(mode="w", encoding="UTF-8")
str(fname), mode="w", encoding="UTF-8" if sys.version_info >= (3, 7):
) old_stream = self.log_file_handler.setStream(stream)
self.log_file_handler.setFormatter(self.log_file_formatter) else:
old_stream = self.log_file_handler.stream
self.log_file_handler.acquire()
try:
self.log_file_handler.flush()
self.log_file_handler.stream = stream
finally:
self.log_file_handler.release()
if old_stream:
old_stream.close()
def _log_cli_enabled(self): def _log_cli_enabled(self):
"""Return True if log_cli should be considered enabled, either explicitly """Return True if log_cli should be considered enabled, either explicitly
@ -611,17 +621,8 @@ class LoggingPlugin:
if self.log_cli_handler: if self.log_cli_handler:
self.log_cli_handler.set_when("collection") self.log_cli_handler.set_when("collection")
if self.log_file_handler is not None:
with catching_logs(self.log_file_handler, level=self.log_file_level): with catching_logs(self.log_file_handler, level=self.log_file_level):
yield yield
else:
# Add a dummy handler to ensure logging.root.handlers is not empty.
# If it were empty, then a `logging.warning()` call (and similar) during collection
# would trigger a `logging.basicConfig()` call, which would add a `StreamHandler`
# handler, which would cause all subsequent logs which reach the root to be also
# printed to stdout, which we don't want (issue #6240).
with catching_logs(logging.NullHandler()):
yield
def _runtest_for( def _runtest_for(
self, item: Optional[nodes.Item], when: str self, item: Optional[nodes.Item], when: str
@ -640,12 +641,6 @@ class LoggingPlugin:
] = log_handler ] = log_handler
item._store[catch_log_handler_key] = log_handler item._store[catch_log_handler_key] = log_handler
try: try:
if self.log_file_handler is not None:
with catching_logs(
self.log_file_handler, level=self.log_file_level
):
yield
else:
yield yield
finally: finally:
if item is not None and when == "teardown": if item is not None and when == "teardown":
@ -688,29 +683,21 @@ class LoggingPlugin:
with self.live_logs_context(): with self.live_logs_context():
if self.log_cli_handler: if self.log_cli_handler:
self.log_cli_handler.set_when("sessionfinish") self.log_cli_handler.set_when("sessionfinish")
if self.log_file_handler is not None:
try: try:
with catching_logs( with catching_logs(self.log_file_handler, level=self.log_file_level):
self.log_file_handler, level=self.log_file_level
):
yield yield
finally: finally:
# Close the FileHandler explicitly. # Close the FileHandler explicitly.
# (logging.shutdown might have lost the weakref?!) # (logging.shutdown might have lost the weakref?!)
self.log_file_handler.close() self.log_file_handler.close()
else:
yield
@pytest.hookimpl(hookwrapper=True, tryfirst=True) @pytest.hookimpl(hookwrapper=True, tryfirst=True)
def pytest_sessionstart(self): def pytest_sessionstart(self):
with self.live_logs_context(): with self.live_logs_context():
if self.log_cli_handler: if self.log_cli_handler:
self.log_cli_handler.set_when("sessionstart") self.log_cli_handler.set_when("sessionstart")
if self.log_file_handler is not None:
with catching_logs(self.log_file_handler, level=self.log_file_level): with catching_logs(self.log_file_handler, level=self.log_file_level):
yield yield
else:
yield
@pytest.hookimpl(hookwrapper=True) @pytest.hookimpl(hookwrapper=True)
def pytest_runtestloop(self, session): def pytest_runtestloop(self, session):
@ -725,11 +712,8 @@ class LoggingPlugin:
self._config.option.verbose = 1 self._config.option.verbose = 1
with self.live_logs_context(): with self.live_logs_context():
if self.log_file_handler is not None:
with catching_logs(self.log_file_handler, level=self.log_file_level): with catching_logs(self.log_file_handler, level=self.log_file_level):
yield # run all the tests yield # run all the tests
else:
yield # run all the tests
class _LiveLoggingStreamHandler(logging.StreamHandler): class _LiveLoggingStreamHandler(logging.StreamHandler):