From 8eafbd05ca2d980b36541fbc9d547e52b6016a9a Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 11:25:17 +0200 Subject: [PATCH] Merge the pytest-catchlog plugin --- _pytest/config.py | 2 +- _pytest/logging.py | 459 +++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 460 insertions(+), 1 deletion(-) create mode 100644 _pytest/logging.py diff --git a/_pytest/config.py b/_pytest/config.py index 690f98587..0d77cfbbf 100644 --- a/_pytest/config.py +++ b/_pytest/config.py @@ -105,7 +105,7 @@ default_plugins = ( "mark main terminal runner python fixtures debugging unittest capture skipping " "tmpdir monkeypatch recwarn pastebin helpconfig nose assertion " "junitxml resultlog doctest cacheprovider freeze_support " - "setuponly setupplan warnings").split() + "setuponly setupplan warnings logging").split() builtin_plugins = set(default_plugins) diff --git a/_pytest/logging.py b/_pytest/logging.py new file mode 100644 index 000000000..53e704b0d --- /dev/null +++ b/_pytest/logging.py @@ -0,0 +1,459 @@ +from __future__ import absolute_import, division, print_function + +import logging +from contextlib import closing, contextmanager +import functools +import sys + +import pytest +import py + + +DEFAULT_LOG_FORMAT = '%(filename)-25s %(lineno)4d %(levelname)-8s %(message)s' +DEFAULT_LOG_DATE_FORMAT = '%H:%M:%S' + + +def add_option_ini(parser, option, dest, default=None, **kwargs): + parser.addini(dest, default=default, + help='default value for ' + option) + parser.getgroup('catchlog').addoption(option, dest=dest, **kwargs) + + +def get_option_ini(config, name): + ret = config.getoption(name) # 'default' arg won't work as expected + if ret is None: + ret = config.getini(name) + return ret + + +def pytest_addoption(parser): + """Add options to control log capturing.""" + + group = parser.getgroup('catchlog', 'Log catching') + add_option_ini(parser, + '--no-print-logs', + dest='log_print', action='store_const', const=False, default=True, + help='disable printing caught logs on failed tests.' + ) + add_option_ini( + parser, + '--log-level', + dest='log_level', default=None, + help='logging level used by the logging module' + ) + add_option_ini(parser, + '--log-format', + dest='log_format', default=DEFAULT_LOG_FORMAT, + help='log format as used by the logging module.' + ) + add_option_ini(parser, + '--log-date-format', + dest='log_date_format', default=DEFAULT_LOG_DATE_FORMAT, + help='log date format as used by the logging module.' + ) + add_option_ini( + parser, + '--log-cli-level', + dest='log_cli_level', default=None, + help='cli logging level.' + ) + add_option_ini( + parser, + '--log-cli-format', + dest='log_cli_format', default=None, + help='log format as used by the logging module.' + ) + add_option_ini( + parser, + '--log-cli-date-format', + dest='log_cli_date_format', default=None, + help='log date format as used by the logging module.' + ) + add_option_ini( + parser, + '--log-file', + dest='log_file', default=None, + help='path to a file when logging will be written to.' + ) + add_option_ini( + parser, + '--log-file-level', + dest='log_file_level', default=None, + help='log file logging level.' + ) + add_option_ini( + parser, + '--log-file-format', + dest='log_file_format', default=DEFAULT_LOG_FORMAT, + help='log format as used by the logging module.' + ) + add_option_ini( + parser, + '--log-file-date-format', + dest='log_file_date_format', default=DEFAULT_LOG_DATE_FORMAT, + help='log date format as used by the logging module.' + ) + + +def get_logger_obj(logger=None): + """Get a logger object that can be specified by its name, or passed as is. + + Defaults to the root logger. + """ + if logger is None or isinstance(logger, py.builtin._basestring): + logger = logging.getLogger(logger) + return logger + + +@contextmanager +def logging_at_level(level, logger=None): + """Context manager that sets the level for capturing of logs.""" + logger = get_logger_obj(logger) + + orig_level = logger.level + logger.setLevel(level) + try: + yield + finally: + logger.setLevel(orig_level) + + +@contextmanager +def logging_using_handler(handler, logger=None): + """Context manager that safely registers a given handler.""" + logger = get_logger_obj(logger) + + if handler in logger.handlers: # reentrancy + # Adding the same handler twice would confuse logging system. + # Just don't do that. + yield + else: + logger.addHandler(handler) + try: + yield + finally: + logger.removeHandler(handler) + + +@contextmanager +def catching_logs(handler, filter=None, formatter=None, + level=logging.NOTSET, logger=None): + """Context manager that prepares the whole logging machinery properly.""" + logger = get_logger_obj(logger) + + if filter is not None: + handler.addFilter(filter) + if formatter is not None: + handler.setFormatter(formatter) + handler.setLevel(level) + + with closing(handler): + with logging_using_handler(handler, logger): + with logging_at_level(min(handler.level, logger.level), logger): + + yield handler + + +class LogCaptureFixture(object): + """Provides access and control of log capturing.""" + + def __init__(self, item): + """Creates a new funcarg.""" + self._item = item + + @property + def handler(self): + return self._item.catch_log_handler + + @property + def text(self): + """Returns the log text.""" + return self.handler.stream.getvalue() + + @property + def records(self): + """Returns the list of log records.""" + return self.handler.records + + @property + def record_tuples(self): + """Returns a list of a striped down version of log records intended + for use in assertion comparison. + + The format of the tuple is: + + (logger_name, log_level, message) + """ + return [(r.name, r.levelno, r.getMessage()) for r in self.records] + + def clear(self): + """Reset the list of log records.""" + self.handler.records = [] + + def set_level(self, level, logger=None): + """Sets the level for capturing of logs. + + By default, the level is set on the handler used to capture + logs. Specify a logger name to instead set the level of any + logger. + """ + + obj = logger and logging.getLogger(logger) or self.handler + obj.setLevel(level) + + def at_level(self, level, logger=None): + """Context manager that sets the level for capturing of logs. + + By default, the level is set on the handler used to capture + logs. Specify a logger name to instead set the level of any + logger. + """ + + obj = logger and logging.getLogger(logger) or self.handler + return logging_at_level(level, obj) + + +class CallablePropertyMixin(object): + """Backward compatibility for functions that became properties.""" + + @classmethod + def compat_property(cls, func): + if isinstance(func, property): + make_property = func.getter + func = func.fget + else: + make_property = property + + @functools.wraps(func) + def getter(self): + naked_value = func(self) + ret = cls(naked_value) + ret._naked_value = naked_value + ret._warn_compat = self._warn_compat + ret._prop_name = func.__name__ + return ret + + return make_property(getter) + + def __call__(self): + new = "'caplog.{0}' property".format(self._prop_name) + if self._prop_name == 'records': + new += ' (or caplog.clear())' + self._warn_compat(old="'caplog.{0}()' syntax".format(self._prop_name), + new=new) + return self._naked_value # to let legacy clients modify the object + + +class CallableList(CallablePropertyMixin, list): + pass + + +class CallableStr(CallablePropertyMixin, py.builtin.text): + pass + + +class CompatLogCaptureFixture(LogCaptureFixture): + """Backward compatibility with pytest-capturelog.""" + + def _warn_compat(self, old, new): + self._item.warn(code='L1', + message=("{0} is deprecated, use {1} instead" + .format(old, new))) + + @CallableStr.compat_property + def text(self): + return super(CompatLogCaptureFixture, self).text + + @CallableList.compat_property + def records(self): + return super(CompatLogCaptureFixture, self).records + + @CallableList.compat_property + def record_tuples(self): + return super(CompatLogCaptureFixture, self).record_tuples + + def setLevel(self, level, logger=None): + self._warn_compat(old="'caplog.setLevel()'", + new="'caplog.set_level()'") + return self.set_level(level, logger) + + def atLevel(self, level, logger=None): + self._warn_compat(old="'caplog.atLevel()'", + new="'caplog.at_level()'") + return self.at_level(level, logger) + + +@pytest.fixture +def caplog(request): + """Access and control log capturing. + + Captured logs are available through the following methods:: + + * caplog.text() -> string containing formatted log output + * caplog.records() -> list of logging.LogRecord instances + * caplog.record_tuples() -> list of (logger_name, level, message) tuples + """ + return CompatLogCaptureFixture(request.node) + + +def get_actual_log_level(config, setting_name): + """Return the actual logging level.""" + log_level = get_option_ini(config, setting_name) + if not log_level: + return + if isinstance(log_level, py.builtin.text): + log_level = log_level.upper() + try: + return int(getattr(logging, log_level, log_level)) + except ValueError: + # Python logging does not recognise this as a logging level + raise pytest.UsageError( + "'{0}' is not recognized as a logging level name for " + "'{1}'. Please consider passing the " + "logging level num instead.".format( + log_level, + setting_name)) + + +def pytest_configure(config): + """Always register the log catcher plugin with py.test or tests can't + find the fixture function. + """ + log_cli_level = get_actual_log_level(config, 'log_cli_level') + if log_cli_level is None: + # No specific CLI logging level was provided, let's check + # log_level for a fallback + log_cli_level = get_actual_log_level(config, 'log_level') + if log_cli_level is None: + # No log_level was provided, default to WARNING + log_cli_level = logging.WARNING + config._catchlog_log_cli_level = log_cli_level + config._catchlog_log_file = get_option_ini(config, 'log_file') + if config._catchlog_log_file: + log_file_level = get_actual_log_level(config, 'log_file_level') + if log_file_level is None: + # No log_level was provided, default to WARNING + log_file_level = logging.WARNING + config._catchlog_log_file_level = log_file_level + config.pluginmanager.register(LoggingPlugin(config)) + + +class LoggingPlugin(object): + """Attaches to the logging module and captures log messages for each test. + """ + + def __init__(self, config): + """Creates a new plugin to capture log messages. + + The formatter can be safely shared across all handlers so + create a single one for the entire test session here. + """ + print_logs = get_option_ini(config, 'log_print') + if not isinstance(print_logs, bool): + if print_logs.lower() in ('true', 'yes', '1'): + print_logs = True + elif print_logs.lower() in ('false', 'no', '0'): + print_logs = False + self.print_logs = print_logs + self.formatter = logging.Formatter( + get_option_ini(config, 'log_format'), + get_option_ini(config, 'log_date_format')) + self.log_cli_handler = logging.StreamHandler(sys.stderr) + log_cli_format = get_option_ini(config, 'log_cli_format') + if not log_cli_format: + # No CLI specific format was provided, use log_format + log_cli_format = get_option_ini(config, 'log_format') + log_cli_date_format = get_option_ini(config, 'log_cli_date_format') + if not log_cli_date_format: + # No CLI specific date format was provided, use log_date_format + log_cli_date_format = get_option_ini(config, 'log_date_format') + log_cli_formatter = logging.Formatter( + log_cli_format, + datefmt=log_cli_date_format) + self.log_cli_handler.setFormatter(log_cli_formatter) + if config._catchlog_log_file: + log_file_format = get_option_ini(config, 'log_file_format') + if not log_file_format: + # No log file specific format was provided, use log_format + log_file_format = get_option_ini(config, 'log_format') + log_file_date_format = get_option_ini(config, 'log_file_date_format') + if not log_file_date_format: + # No log file specific date format was provided, use log_date_format + log_file_date_format = get_option_ini(config, 'log_date_format') + self.log_file_handler = logging.FileHandler( + config._catchlog_log_file, + # Each pytest runtests session will write to a clean logfile + mode='w', + ) + log_file_formatter = logging.Formatter( + log_file_format, + datefmt=log_file_date_format) + self.log_file_handler.setFormatter(log_file_formatter) + else: + self.log_file_handler = None + + @contextmanager + def _runtest_for(self, item, when): + """Implements the internals of pytest_runtest_xxx() hook.""" + with catching_logs(LogCaptureHandler(), + formatter=self.formatter) as log_handler: + item.catch_log_handler = log_handler + try: + yield # run test + finally: + del item.catch_log_handler + + if self.print_logs: + # Add a captured log section to the report. + log = log_handler.stream.getvalue().strip() + item.add_report_section(when, 'log', log) + + @pytest.mark.hookwrapper + def pytest_runtest_setup(self, item): + with self._runtest_for(item, 'setup'): + yield + + @pytest.mark.hookwrapper + def pytest_runtest_call(self, item): + with self._runtest_for(item, 'call'): + yield + + @pytest.mark.hookwrapper + def pytest_runtest_teardown(self, item): + with self._runtest_for(item, 'teardown'): + yield + + @pytest.mark.hookwrapper + def pytest_runtestloop(self, session): + """Runs all collected test items.""" + with catching_logs(self.log_cli_handler, + level=session.config._catchlog_log_cli_level): + if self.log_file_handler is not None: + with catching_logs(self.log_file_handler, + level=session.config._catchlog_log_file_level): + yield # run all the tests + else: + yield # run all the tests + + +class LogCaptureHandler(logging.StreamHandler): + """A logging handler that stores log records and the log text.""" + + def __init__(self): + """Creates a new log handler.""" + + logging.StreamHandler.__init__(self) + self.stream = py.io.TextIO() + self.records = [] + + def close(self): + """Close this log handler and its underlying stream.""" + + logging.StreamHandler.close(self) + self.stream.close() + + def emit(self, record): + """Keep the log records in a list in addition to the log text.""" + + self.records.append(record) + logging.StreamHandler.emit(self, record)