From 8eafbd05ca2d980b36541fbc9d547e52b6016a9a Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 11:25:17 +0200 Subject: [PATCH 01/33] 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) From 6607478b23316653335de85e4a6eb2ec6d7e90c3 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 13:12:07 +0200 Subject: [PATCH 02/33] Add unittests for LoggingPlugin (excluding perf tests) --- _pytest/logging.py | 2 +- testing/logging/conftest.py | 33 +++ testing/logging/test_compat.py | 80 ++++++ testing/logging/test_fixture.py | 99 ++++++++ testing/logging/test_reporting.py | 398 ++++++++++++++++++++++++++++++ 5 files changed, 611 insertions(+), 1 deletion(-) create mode 100644 testing/logging/conftest.py create mode 100644 testing/logging/test_compat.py create mode 100644 testing/logging/test_fixture.py create mode 100644 testing/logging/test_reporting.py diff --git a/_pytest/logging.py b/_pytest/logging.py index 53e704b0d..aa0c46948 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -335,7 +335,7 @@ def pytest_configure(config): # 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)) + config.pluginmanager.register(LoggingPlugin(config), 'loggingp') class LoggingPlugin(object): diff --git a/testing/logging/conftest.py b/testing/logging/conftest.py new file mode 100644 index 000000000..9b559d7eb --- /dev/null +++ b/testing/logging/conftest.py @@ -0,0 +1,33 @@ +# -*- coding: utf-8 -*- +from __future__ import absolute_import, division, print_function + +import pytest + + +pytest_plugins = 'pytester' + + +def pytest_addoption(parser): + parser.addoption('--run-perf', + action='store', dest='run_perf', + choices=['yes', 'no', 'only', 'check'], + nargs='?', default='check', const='yes', + help='Run performance tests (can be slow)', + ) + + parser.addoption('--perf-graph', + action='store', dest='perf_graph_name', + nargs='?', default=None, const='graph.svg', + help='Plot a graph using data found in --benchmark-storage', + ) + parser.addoption('--perf-expr', + action='store', dest='perf_expr_primary', + default='log_emit', + help='Benchmark (or expression combining benchmarks) to plot', + ) + parser.addoption('--perf-expr-secondary', + action='store', dest='perf_expr_secondary', + default='caplog - stub', + help=('Benchmark (or expression combining benchmarks) to plot ' + 'as a secondary line'), + ) diff --git a/testing/logging/test_compat.py b/testing/logging/test_compat.py new file mode 100644 index 000000000..0c527b587 --- /dev/null +++ b/testing/logging/test_compat.py @@ -0,0 +1,80 @@ +# -*- coding: utf-8 -*- +import pytest + + +def test_camel_case_aliases(testdir): + testdir.makepyfile(''' + import logging + + logger = logging.getLogger(__name__) + + def test_foo(caplog): + caplog.setLevel(logging.INFO) + logger.debug('boo!') + + with caplog.atLevel(logging.WARNING): + logger.info('catch me if you can') + ''') + result = testdir.runpytest() + assert result.ret == 0 + + with pytest.raises(pytest.fail.Exception): + result.stdout.fnmatch_lines(['*- Captured *log call -*']) + + result = testdir.runpytest('-rw') + assert result.ret == 0 + result.stdout.fnmatch_lines(''' + =*warning* summary*= + *caplog.setLevel()*deprecated* + *caplog.atLevel()*deprecated* + ''') + + +def test_property_call(testdir): + testdir.makepyfile(''' + import logging + + logger = logging.getLogger(__name__) + + def test_foo(caplog): + logger.info('boo %s', 'arg') + + assert caplog.text == caplog.text() == str(caplog.text) + assert caplog.records == caplog.records() == list(caplog.records) + assert (caplog.record_tuples == + caplog.record_tuples() == list(caplog.record_tuples)) + ''') + result = testdir.runpytest() + assert result.ret == 0 + + result = testdir.runpytest('-rw') + assert result.ret == 0 + result.stdout.fnmatch_lines(''' + =*warning* summary*= + *caplog.text()*deprecated* + *caplog.records()*deprecated* + *caplog.record_tuples()*deprecated* + ''') + + +def test_records_modification(testdir): + testdir.makepyfile(''' + import logging + + logger = logging.getLogger(__name__) + + def test_foo(caplog): + logger.info('boo %s', 'arg') + assert caplog.records + assert caplog.records() + + del caplog.records()[:] # legacy syntax + assert not caplog.records + assert not caplog.records() + + logger.info('foo %s', 'arg') + assert caplog.records + assert caplog.records() + ''') + result = testdir.runpytest() + assert result.ret == 0 diff --git a/testing/logging/test_fixture.py b/testing/logging/test_fixture.py new file mode 100644 index 000000000..bdfa67ecc --- /dev/null +++ b/testing/logging/test_fixture.py @@ -0,0 +1,99 @@ +# -*- coding: utf-8 -*- +import sys +import logging + + +logger = logging.getLogger(__name__) +sublogger = logging.getLogger(__name__+'.baz') + +u = (lambda x: x.decode('utf-8')) if sys.version_info < (3,) else (lambda x: x) + + +def test_fixture_help(testdir): + result = testdir.runpytest('--fixtures') + result.stdout.fnmatch_lines(['*caplog*']) + + +def test_change_level(caplog): + caplog.set_level(logging.INFO) + logger.debug('handler DEBUG level') + logger.info('handler INFO level') + + caplog.set_level(logging.CRITICAL, logger=sublogger.name) + sublogger.warning('logger WARNING level') + sublogger.critical('logger CRITICAL level') + + assert 'DEBUG' not in caplog.text + assert 'INFO' in caplog.text + assert 'WARNING' not in caplog.text + assert 'CRITICAL' in caplog.text + + +def test_with_statement(caplog): + with caplog.at_level(logging.INFO): + logger.debug('handler DEBUG level') + logger.info('handler INFO level') + + with caplog.at_level(logging.CRITICAL, logger=sublogger.name): + sublogger.warning('logger WARNING level') + sublogger.critical('logger CRITICAL level') + + assert 'DEBUG' not in caplog.text + assert 'INFO' in caplog.text + assert 'WARNING' not in caplog.text + assert 'CRITICAL' in caplog.text + + +def test_log_access(caplog): + logger.info('boo %s', 'arg') + assert caplog.records[0].levelname == 'INFO' + assert caplog.records[0].msg == 'boo %s' + assert 'boo arg' in caplog.text + + +def test_record_tuples(caplog): + logger.info('boo %s', 'arg') + + assert caplog.record_tuples == [ + (__name__, logging.INFO, 'boo arg'), + ] + + +def test_unicode(caplog): + logger.info(u('bū')) + assert caplog.records[0].levelname == 'INFO' + assert caplog.records[0].msg == u('bū') + assert u('bū') in caplog.text + + +def test_clear(caplog): + logger.info(u('bū')) + assert len(caplog.records) + caplog.clear() + assert not len(caplog.records) + + +def test_special_warning_with_del_records_warning(testdir): + p1 = testdir.makepyfile(""" + def test_del_records_inline(caplog): + del caplog.records()[:] + """) + result = testdir.runpytest_subprocess(p1) + result.stdout.fnmatch_lines([ + "*'caplog.records()' syntax is deprecated," + " use 'caplog.records' property (or caplog.clear()) instead", + "*1 *warnings*", + ]) + + +def test_warning_with_setLevel(testdir): + p1 = testdir.makepyfile(""" + def test_inline(caplog): + caplog.setLevel(0) + """) + result = testdir.runpytest_subprocess(p1) + result.stdout.fnmatch_lines([ + "*'caplog.setLevel()' is deprecated," + " use 'caplog.set_level()' instead", + "*1 *warnings*", + ]) diff --git a/testing/logging/test_reporting.py b/testing/logging/test_reporting.py new file mode 100644 index 000000000..af75eb632 --- /dev/null +++ b/testing/logging/test_reporting.py @@ -0,0 +1,398 @@ +# -*- coding: utf-8 -*- +import os +import pytest + + +def test_nothing_logged(testdir): + testdir.makepyfile(''' + import sys + + def test_foo(): + sys.stdout.write('text going to stdout') + sys.stderr.write('text going to stderr') + assert False + ''') + result = testdir.runpytest() + assert result.ret == 1 + result.stdout.fnmatch_lines(['*- Captured stdout call -*', + 'text going to stdout']) + result.stdout.fnmatch_lines(['*- Captured stderr call -*', + 'text going to stderr']) + with pytest.raises(pytest.fail.Exception): + result.stdout.fnmatch_lines(['*- Captured *log call -*']) + + +def test_messages_logged(testdir): + testdir.makepyfile(''' + import sys + import logging + + logger = logging.getLogger(__name__) + + def test_foo(): + sys.stdout.write('text going to stdout') + sys.stderr.write('text going to stderr') + logger.info('text going to logger') + assert False + ''') + result = testdir.runpytest() + assert result.ret == 1 + result.stdout.fnmatch_lines(['*- Captured *log call -*', + '*text going to logger*']) + result.stdout.fnmatch_lines(['*- Captured stdout call -*', + 'text going to stdout']) + result.stdout.fnmatch_lines(['*- Captured stderr call -*', + 'text going to stderr']) + + +def test_setup_logging(testdir): + testdir.makepyfile(''' + import logging + + logger = logging.getLogger(__name__) + + def setup_function(function): + logger.info('text going to logger from setup') + + def test_foo(): + logger.info('text going to logger from call') + assert False + ''') + result = testdir.runpytest() + assert result.ret == 1 + result.stdout.fnmatch_lines(['*- Captured *log setup -*', + '*text going to logger from setup*', + '*- Captured *log call -*', + '*text going to logger from call*']) + + +def test_teardown_logging(testdir): + testdir.makepyfile(''' + import logging + + logger = logging.getLogger(__name__) + + def test_foo(): + logger.info('text going to logger from call') + + def teardown_function(function): + logger.info('text going to logger from teardown') + assert False + ''') + result = testdir.runpytest() + assert result.ret == 1 + result.stdout.fnmatch_lines(['*- Captured *log call -*', + '*text going to logger from call*', + '*- Captured *log teardown -*', + '*text going to logger from teardown*']) + + +def test_disable_log_capturing(testdir): + testdir.makepyfile(''' + import sys + import logging + + logger = logging.getLogger(__name__) + + def test_foo(): + sys.stdout.write('text going to stdout') + logger.warning('catch me if you can!') + sys.stderr.write('text going to stderr') + assert False + ''') + result = testdir.runpytest('--no-print-logs') + print(result.stdout) + assert result.ret == 1 + result.stdout.fnmatch_lines(['*- Captured stdout call -*', + 'text going to stdout']) + result.stdout.fnmatch_lines(['*- Captured stderr call -*', + 'text going to stderr']) + with pytest.raises(pytest.fail.Exception): + result.stdout.fnmatch_lines(['*- Captured *log call -*']) + + +def test_disable_log_capturing_ini(testdir): + testdir.makeini( + ''' + [pytest] + log_print=False + ''' + ) + testdir.makepyfile(''' + import sys + import logging + + logger = logging.getLogger(__name__) + + def test_foo(): + sys.stdout.write('text going to stdout') + logger.warning('catch me if you can!') + sys.stderr.write('text going to stderr') + assert False + ''') + result = testdir.runpytest() + print(result.stdout) + assert result.ret == 1 + result.stdout.fnmatch_lines(['*- Captured stdout call -*', + 'text going to stdout']) + result.stdout.fnmatch_lines(['*- Captured stderr call -*', + 'text going to stderr']) + with pytest.raises(pytest.fail.Exception): + result.stdout.fnmatch_lines(['*- Captured *log call -*']) + + +def test_log_cli_default_level(testdir): + # Default log file level + testdir.makepyfile(''' + import pytest + import logging + def test_log_cli(request): + plugin = request.config.pluginmanager.getplugin('loggingp') + assert plugin.log_cli_handler.level == logging.WARNING + logging.getLogger('catchlog').info("This log message won't be shown") + logging.getLogger('catchlog').warning("This log message will be shown") + print('PASSED') + ''') + + result = testdir.runpytest('-s') + + # fnmatch_lines does an assertion internally + result.stdout.fnmatch_lines([ + 'test_log_cli_default_level.py PASSED', + ]) + result.stderr.fnmatch_lines([ + "* This log message will be shown" + ]) + for line in result.errlines: + try: + assert "This log message won't be shown" in line + pytest.fail("A log message was shown and it shouldn't have been") + except AssertionError: + continue + + # make sure that that we get a '0' exit code for the testsuite + assert result.ret == 0 + + +def test_log_cli_level(testdir): + # Default log file level + testdir.makepyfile(''' + import pytest + import logging + def test_log_cli(request): + plugin = request.config.pluginmanager.getplugin('loggingp') + assert plugin.log_cli_handler.level == logging.INFO + logging.getLogger('catchlog').debug("This log message won't be shown") + logging.getLogger('catchlog').info("This log message will be shown") + print('PASSED') + ''') + + result = testdir.runpytest('-s', '--log-cli-level=INFO') + + # fnmatch_lines does an assertion internally + result.stdout.fnmatch_lines([ + 'test_log_cli_level.py PASSED', + ]) + result.stderr.fnmatch_lines([ + "* This log message will be shown" + ]) + for line in result.errlines: + try: + assert "This log message won't be shown" in line + pytest.fail("A log message was shown and it shouldn't have been") + except AssertionError: + continue + + # make sure that that we get a '0' exit code for the testsuite + assert result.ret == 0 + + result = testdir.runpytest('-s', '--log-level=INFO') + + # fnmatch_lines does an assertion internally + result.stdout.fnmatch_lines([ + 'test_log_cli_level.py PASSED', + ]) + result.stderr.fnmatch_lines([ + "* This log message will be shown" + ]) + for line in result.errlines: + try: + assert "This log message won't be shown" in line + pytest.fail("A log message was shown and it shouldn't have been") + except AssertionError: + continue + + # make sure that that we get a '0' exit code for the testsuite + assert result.ret == 0 + + +def test_log_cli_ini_level(testdir): + testdir.makeini( + """ + [pytest] + log_cli_level = INFO + """) + testdir.makepyfile(''' + import pytest + import logging + def test_log_cli(request): + plugin = request.config.pluginmanager.getplugin('loggingp') + assert plugin.log_cli_handler.level == logging.INFO + logging.getLogger('catchlog').debug("This log message won't be shown") + logging.getLogger('catchlog').info("This log message will be shown") + print('PASSED') + ''') + + result = testdir.runpytest('-s') + + # fnmatch_lines does an assertion internally + result.stdout.fnmatch_lines([ + 'test_log_cli_ini_level.py PASSED', + ]) + result.stderr.fnmatch_lines([ + "* This log message will be shown" + ]) + for line in result.errlines: + try: + assert "This log message won't be shown" in line + pytest.fail("A log message was shown and it shouldn't have been") + except AssertionError: + continue + + # make sure that that we get a '0' exit code for the testsuite + assert result.ret == 0 + + +def test_log_file_cli(testdir): + # Default log file level + testdir.makepyfile(''' + import pytest + import logging + def test_log_file(request): + plugin = request.config.pluginmanager.getplugin('loggingp') + assert plugin.log_file_handler.level == logging.WARNING + logging.getLogger('catchlog').info("This log message won't be shown") + logging.getLogger('catchlog').warning("This log message will be shown") + print('PASSED') + ''') + + log_file = testdir.tmpdir.join('pytest.log').strpath + + result = testdir.runpytest('-s', '--log-file={0}'.format(log_file)) + + # fnmatch_lines does an assertion internally + result.stdout.fnmatch_lines([ + 'test_log_file_cli.py PASSED', + ]) + + # make sure that that we get a '0' exit code for the testsuite + assert result.ret == 0 + assert os.path.isfile(log_file) + with open(log_file) as rfh: + contents = rfh.read() + assert "This log message will be shown" in contents + assert "This log message won't be shown" not in contents + + +def test_log_file_cli_level(testdir): + # Default log file level + testdir.makepyfile(''' + import pytest + import logging + def test_log_file(request): + plugin = request.config.pluginmanager.getplugin('loggingp') + assert plugin.log_file_handler.level == logging.INFO + logging.getLogger('catchlog').debug("This log message won't be shown") + logging.getLogger('catchlog').info("This log message will be shown") + print('PASSED') + ''') + + log_file = testdir.tmpdir.join('pytest.log').strpath + + result = testdir.runpytest('-s', + '--log-file={0}'.format(log_file), + '--log-file-level=INFO') + + # fnmatch_lines does an assertion internally + result.stdout.fnmatch_lines([ + 'test_log_file_cli_level.py PASSED', + ]) + + # make sure that that we get a '0' exit code for the testsuite + assert result.ret == 0 + assert os.path.isfile(log_file) + with open(log_file) as rfh: + contents = rfh.read() + assert "This log message will be shown" in contents + assert "This log message won't be shown" not in contents + + +def test_log_file_ini(testdir): + log_file = testdir.tmpdir.join('pytest.log').strpath + + testdir.makeini( + """ + [pytest] + log_file={0} + """.format(log_file)) + testdir.makepyfile(''' + import pytest + import logging + def test_log_file(request): + plugin = request.config.pluginmanager.getplugin('loggingp') + assert plugin.log_file_handler.level == logging.WARNING + logging.getLogger('catchlog').info("This log message won't be shown") + logging.getLogger('catchlog').warning("This log message will be shown") + print('PASSED') + ''') + + result = testdir.runpytest('-s') + + # fnmatch_lines does an assertion internally + result.stdout.fnmatch_lines([ + 'test_log_file_ini.py PASSED', + ]) + + # make sure that that we get a '0' exit code for the testsuite + assert result.ret == 0 + assert os.path.isfile(log_file) + with open(log_file) as rfh: + contents = rfh.read() + assert "This log message will be shown" in contents + assert "This log message won't be shown" not in contents + + +def test_log_file_ini_level(testdir): + log_file = testdir.tmpdir.join('pytest.log').strpath + + testdir.makeini( + """ + [pytest] + log_file={0} + log_file_level = INFO + """.format(log_file)) + testdir.makepyfile(''' + import pytest + import logging + def test_log_file(request): + plugin = request.config.pluginmanager.getplugin('loggingp') + assert plugin.log_file_handler.level == logging.INFO + logging.getLogger('catchlog').debug("This log message won't be shown") + logging.getLogger('catchlog').info("This log message will be shown") + print('PASSED') + ''') + + result = testdir.runpytest('-s') + + # fnmatch_lines does an assertion internally + result.stdout.fnmatch_lines([ + 'test_log_file_ini_level.py PASSED', + ]) + + # make sure that that we get a '0' exit code for the testsuite + assert result.ret == 0 + assert os.path.isfile(log_file) + with open(log_file) as rfh: + contents = rfh.read() + assert "This log message will be shown" in contents + assert "This log message won't be shown" not in contents From 5130f5707f2652262ca3fb2d2c9611824611c5eb Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 13:23:29 +0200 Subject: [PATCH 03/33] Fix name clash --- testing/logging/{test_compat.py => test_capturelog_compat.py} | 0 1 file changed, 0 insertions(+), 0 deletions(-) rename testing/logging/{test_compat.py => test_capturelog_compat.py} (100%) diff --git a/testing/logging/test_compat.py b/testing/logging/test_capturelog_compat.py similarity index 100% rename from testing/logging/test_compat.py rename to testing/logging/test_capturelog_compat.py From ca46f4fe2a870d858ec5678116ea5d3b865489fe Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 13:47:48 +0200 Subject: [PATCH 04/33] Remove conftest --- testing/logging/conftest.py | 33 --------------------------------- 1 file changed, 33 deletions(-) delete mode 100644 testing/logging/conftest.py diff --git a/testing/logging/conftest.py b/testing/logging/conftest.py deleted file mode 100644 index 9b559d7eb..000000000 --- a/testing/logging/conftest.py +++ /dev/null @@ -1,33 +0,0 @@ -# -*- coding: utf-8 -*- -from __future__ import absolute_import, division, print_function - -import pytest - - -pytest_plugins = 'pytester' - - -def pytest_addoption(parser): - parser.addoption('--run-perf', - action='store', dest='run_perf', - choices=['yes', 'no', 'only', 'check'], - nargs='?', default='check', const='yes', - help='Run performance tests (can be slow)', - ) - - parser.addoption('--perf-graph', - action='store', dest='perf_graph_name', - nargs='?', default=None, const='graph.svg', - help='Plot a graph using data found in --benchmark-storage', - ) - parser.addoption('--perf-expr', - action='store', dest='perf_expr_primary', - default='log_emit', - help='Benchmark (or expression combining benchmarks) to plot', - ) - parser.addoption('--perf-expr-secondary', - action='store', dest='perf_expr_secondary', - default='caplog - stub', - help=('Benchmark (or expression combining benchmarks) to plot ' - 'as a secondary line'), - ) From a8e3effb6c25129bc828df02fa9234b1f7aea1e4 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 15:04:26 +0200 Subject: [PATCH 05/33] Upgrade py --- setup.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/setup.py b/setup.py index 4d74e6bca..27d066fba 100644 --- a/setup.py +++ b/setup.py @@ -43,7 +43,7 @@ def has_environment_marker_support(): def main(): - install_requires = ['py>=1.4.33', 'six>=1.10.0', 'setuptools'] + install_requires = ['py>=1.4.34', 'six>=1.10.0', 'setuptools'] # if _PYTEST_SETUP_SKIP_PLUGGY_DEP is set, skip installing pluggy; # used by tox.ini to test with pluggy master if '_PYTEST_SETUP_SKIP_PLUGGY_DEP' not in os.environ: From 1ba219e0da9a62a82dc6ad3c154c4df948a5bf32 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 15:08:31 +0200 Subject: [PATCH 06/33] Adapt (logging) unittest --- testing/test_capture.py | 2 -- 1 file changed, 2 deletions(-) diff --git a/testing/test_capture.py b/testing/test_capture.py index eb10f3c07..841cdb0a3 100644 --- a/testing/test_capture.py +++ b/testing/test_capture.py @@ -346,8 +346,6 @@ class TestLoggingInteraction(object): p = testdir.makepyfile(""" import sys def test_something(): - # pytest does not import logging - assert 'logging' not in sys.modules import logging logging.basicConfig() logging.warn("hello432") From 1bea7e698553662ce52111f3b2f68f3c625b2df2 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 15:32:23 +0200 Subject: [PATCH 07/33] Cleanup pytest_addoption --- _pytest/logging.py | 61 ++++++++++++++++------------------------------ 1 file changed, 21 insertions(+), 40 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index aa0c46948..5d5a8522a 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -13,12 +13,6 @@ 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: @@ -29,70 +23,57 @@ def get_option_ini(config, name): def pytest_addoption(parser): """Add options to control log capturing.""" - group = parser.getgroup('catchlog', 'Log catching') - add_option_ini(parser, + group = parser.getgroup('logging') + + def add_option_ini(option, dest, default=None, **kwargs): + parser.addini(dest, default=default, + help='default value for ' + option) + group.addoption(option, dest=dest, **kwargs) + + add_option_ini( '--no-print-logs', dest='log_print', action='store_const', const=False, default=True, - help='disable printing caught logs on failed tests.' - ) + 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, + help='logging level used by the logging module') + add_option_ini( '--log-format', dest='log_format', default=DEFAULT_LOG_FORMAT, - help='log format as used by the logging module.' - ) - add_option_ini(parser, + help='log format as used by the logging module.') + add_option_ini( '--log-date-format', dest='log_date_format', default=DEFAULT_LOG_DATE_FORMAT, - help='log date format as used by the logging module.' - ) + 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.' - ) + 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.' - ) + 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.' - ) + 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.' - ) + 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.' - ) + 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.' - ) + 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.' - ) + help='log date format as used by the logging module.') def get_logger_obj(logger=None): From 98209e92ee3ac1dec888eb123141488f265d9082 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 18:01:58 +0200 Subject: [PATCH 08/33] Remove superfluous whitespace in docstring --- _pytest/logging.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 5d5a8522a..36ce3e3b8 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -297,8 +297,8 @@ def get_actual_log_level(config, setting_name): def pytest_configure(config): - """Always register the log catcher plugin with py.test or tests can't - find the fixture function. + """Always register the logging 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: From 3e71a50403b6eeaee9d309f9a67bac98b67a5629 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 18:02:28 +0200 Subject: [PATCH 09/33] Remove unneeded sys import from unittest --- testing/test_capture.py | 1 - 1 file changed, 1 deletion(-) diff --git a/testing/test_capture.py b/testing/test_capture.py index 841cdb0a3..79e34a40f 100644 --- a/testing/test_capture.py +++ b/testing/test_capture.py @@ -344,7 +344,6 @@ class TestLoggingInteraction(object): def test_logging_initialized_in_test(self, testdir): p = testdir.makepyfile(""" - import sys def test_something(): import logging logging.basicConfig() From 36cceeb10eaed8310b4cc1b6761879d47ce07d72 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 18:09:27 +0200 Subject: [PATCH 10/33] Set type of log_print ini-variable to 'bool' --- _pytest/logging.py | 13 ++++--------- 1 file changed, 4 insertions(+), 9 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 36ce3e3b8..6e4a9e724 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -25,14 +25,15 @@ def pytest_addoption(parser): group = parser.getgroup('logging') - def add_option_ini(option, dest, default=None, **kwargs): - parser.addini(dest, default=default, + def add_option_ini(option, dest, default=None, type=None, **kwargs): + parser.addini(dest, default=default, type=type, help='default value for ' + option) group.addoption(option, dest=dest, **kwargs) add_option_ini( '--no-print-logs', dest='log_print', action='store_const', const=False, default=True, + type='bool', help='disable printing caught logs on failed tests.') add_option_ini( '--log-level', @@ -329,13 +330,7 @@ class LoggingPlugin(object): 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.print_logs = get_option_ini(config, 'log_print') self.formatter = logging.Formatter( get_option_ini(config, 'log_format'), get_option_ini(config, 'log_date_format')) From a1bd54e4eae50d39a7650e93cd39fc09ce8c3cac Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 13 Sep 2017 23:56:35 +0200 Subject: [PATCH 11/33] Clean-up LogCaptureHandler --- _pytest/logging.py | 39 ++++++++++++++++----------------------- 1 file changed, 16 insertions(+), 23 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 6e4a9e724..1043cffda 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -136,6 +136,22 @@ def catching_logs(handler, filter=None, formatter=None, yield handler +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, py.io.TextIO()) + self.records = [] + + 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) + + class LogCaptureFixture(object): """Provides access and control of log capturing.""" @@ -410,26 +426,3 @@ class LoggingPlugin(object): 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) From fc965c1dc569556323fc196bd026f877e42a5d6a Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Thu, 14 Sep 2017 00:17:51 +0200 Subject: [PATCH 12/33] Remove outdated docstring --- _pytest/logging.py | 3 --- 1 file changed, 3 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 1043cffda..c4a63db2d 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -314,9 +314,6 @@ def get_actual_log_level(config, setting_name): def pytest_configure(config): - """Always register the logging 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 From 87b8dc5afbb1a80670b510fbf40b9018f04a43d1 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Fri, 15 Sep 2017 03:04:23 +0200 Subject: [PATCH 13/33] Move 'config' handling from pytest_configure to __init__ --- _pytest/logging.py | 38 ++++++++++++++++++++------------------ 1 file changed, 20 insertions(+), 18 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index c4a63db2d..fd5effb20 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -314,22 +314,6 @@ def get_actual_log_level(config, setting_name): def pytest_configure(config): - 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), 'loggingp') @@ -343,6 +327,16 @@ class LoggingPlugin(object): The formatter can be safely shared across all handlers so create a single one for the entire test session here. """ + 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 + self.print_logs = get_option_ini(config, 'log_print') self.formatter = logging.Formatter( get_option_ini(config, 'log_format'), @@ -360,7 +354,15 @@ class LoggingPlugin(object): log_cli_format, datefmt=log_cli_date_format) self.log_cli_handler.setFormatter(log_cli_formatter) - if config._catchlog_log_file: + + log_file = get_option_ini(config, 'log_file') + if 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 + 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 @@ -370,7 +372,7 @@ class LoggingPlugin(object): # 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, + log_file, # Each pytest runtests session will write to a clean logfile mode='w', ) From f1f6109255e5d2ef021f07d2b42d5f8c5f189f52 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Fri, 15 Sep 2017 03:11:56 +0200 Subject: [PATCH 14/33] Remove _catchlog_ prefix --- _pytest/logging.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index fd5effb20..8fce433f5 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -335,7 +335,7 @@ class LoggingPlugin(object): 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.log_cli_level = log_cli_level self.print_logs = get_option_ini(config, 'log_print') self.formatter = logging.Formatter( @@ -361,7 +361,7 @@ class LoggingPlugin(object): 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.log_file_level = log_file_level log_file_format = get_option_ini(config, 'log_file_format') if not log_file_format: @@ -418,10 +418,10 @@ class LoggingPlugin(object): def pytest_runtestloop(self, session): """Runs all collected test items.""" with catching_logs(self.log_cli_handler, - level=session.config._catchlog_log_cli_level): + level=session.config.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): + level=session.config.log_file_level): yield # run all the tests else: yield # run all the tests From d13e17cf51abf424f0bd26a3f8607c8f8339b390 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Fri, 15 Sep 2017 03:15:07 +0200 Subject: [PATCH 15/33] Don't modify the 'config' object in __init__ --- _pytest/logging.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 8fce433f5..aa8cc7b8d 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -335,7 +335,7 @@ class LoggingPlugin(object): if log_cli_level is None: # No log_level was provided, default to WARNING log_cli_level = logging.WARNING - config.log_cli_level = log_cli_level + self.log_cli_level = log_cli_level self.print_logs = get_option_ini(config, 'log_print') self.formatter = logging.Formatter( @@ -361,7 +361,7 @@ class LoggingPlugin(object): if log_file_level is None: # No log_level was provided, default to WARNING log_file_level = logging.WARNING - config.log_file_level = log_file_level + self.log_file_level = log_file_level log_file_format = get_option_ini(config, 'log_file_format') if not log_file_format: @@ -418,10 +418,10 @@ class LoggingPlugin(object): def pytest_runtestloop(self, session): """Runs all collected test items.""" with catching_logs(self.log_cli_handler, - level=session.config.log_cli_level): + level=self.log_cli_level): if self.log_file_handler is not None: with catching_logs(self.log_file_handler, - level=session.config.log_file_level): + level=self.log_file_level): yield # run all the tests else: yield # run all the tests From 08f6b5f4ea72add0fd07e4f6f559765a7bd8accf Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Fri, 15 Sep 2017 04:43:51 +0200 Subject: [PATCH 16/33] Use pytest.hookimpl instead of pytest.mark.hookwrapper pytest.mark.hookwrapper seems to be used nowhere in the _pytest package. --- _pytest/logging.py | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index aa8cc7b8d..2f541245c 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -399,22 +399,22 @@ class LoggingPlugin(object): log = log_handler.stream.getvalue().strip() item.add_report_section(when, 'log', log) - @pytest.mark.hookwrapper + @pytest.hookimpl(hookwrapper=True) def pytest_runtest_setup(self, item): with self._runtest_for(item, 'setup'): yield - @pytest.mark.hookwrapper + @pytest.hookimpl(hookwrapper=True) def pytest_runtest_call(self, item): with self._runtest_for(item, 'call'): yield - @pytest.mark.hookwrapper + @pytest.hookimpl(hookwrapper=True) def pytest_runtest_teardown(self, item): with self._runtest_for(item, 'teardown'): yield - @pytest.mark.hookwrapper + @pytest.hookimpl(hookwrapper=True) def pytest_runtestloop(self, session): """Runs all collected test items.""" with catching_logs(self.log_cli_handler, From e41fd52e8c6b6bc853511244c9a5459b218041c0 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Fri, 15 Sep 2017 12:45:25 +0200 Subject: [PATCH 17/33] Introduce live_logs context manager --- _pytest/logging.py | 11 +++++++---- 1 file changed, 7 insertions(+), 4 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 2f541245c..909a566dc 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -341,7 +341,8 @@ class LoggingPlugin(object): 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_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 @@ -353,7 +354,10 @@ class LoggingPlugin(object): log_cli_formatter = logging.Formatter( log_cli_format, datefmt=log_cli_date_format) - self.log_cli_handler.setFormatter(log_cli_formatter) + log_cli_handler.setFormatter(log_cli_formatter) + self.log_cli_handler = log_cli_handler # needed for a single unittest + self.live_logs = catching_logs(log_cli_handler, + level=self.log_cli_level) log_file = get_option_ini(config, 'log_file') if log_file: @@ -417,8 +421,7 @@ class LoggingPlugin(object): @pytest.hookimpl(hookwrapper=True) def pytest_runtestloop(self, session): """Runs all collected test items.""" - with catching_logs(self.log_cli_handler, - level=self.log_cli_level): + with self.live_logs: if self.log_file_handler is not None: with catching_logs(self.log_file_handler, level=self.log_file_level): From 57f66a455aa51fb0a38578664156923c5a8a5adf Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Fri, 15 Sep 2017 13:33:54 +0200 Subject: [PATCH 18/33] catching_logs: Remove unused 'filter' kwarg --- _pytest/logging.py | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 909a566dc..77ae04424 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -118,13 +118,11 @@ def logging_using_handler(handler, logger=None): @contextmanager -def catching_logs(handler, filter=None, formatter=None, +def catching_logs(handler, 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) From 3a4011585f67981595d6a2eb8ca3de78bbe2f251 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Fri, 15 Sep 2017 13:38:49 +0200 Subject: [PATCH 19/33] catching_logs: Remove usage of 'closing' ctx manager The 'closing' context manager is only needed for the log_file_handler. --- _pytest/logging.py | 15 +++++++-------- 1 file changed, 7 insertions(+), 8 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 77ae04424..e9b143369 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -127,11 +127,9 @@ def catching_logs(handler, formatter=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 + with logging_using_handler(handler, logger): + with logging_at_level(min(handler.level, logger.level), logger): + yield handler class LogCaptureHandler(logging.StreamHandler): @@ -421,8 +419,9 @@ class LoggingPlugin(object): """Runs all collected test items.""" with self.live_logs: if self.log_file_handler is not None: - with catching_logs(self.log_file_handler, - level=self.log_file_level): - yield # run all the tests + with closing(self.log_file_handler): + with catching_logs(self.log_file_handler, + level=self.log_file_level): + yield # run all the tests else: yield # run all the tests From 207f153ec13e41e13697da672fe59a64e320f00a Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Sun, 17 Sep 2017 14:11:35 +0200 Subject: [PATCH 20/33] Remove logging_at_level ctx manager --- _pytest/logging.py | 32 ++++++++++++++++---------------- 1 file changed, 16 insertions(+), 16 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index e9b143369..cec37b641 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -87,19 +87,6 @@ def get_logger_obj(logger=None): 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.""" @@ -128,8 +115,12 @@ def catching_logs(handler, formatter=None, handler.setLevel(level) with logging_using_handler(handler, logger): - with logging_at_level(min(handler.level, logger.level), logger): + orig_level = logger.level + logger.setLevel(min(orig_level, level)) + try: yield handler + finally: + logger.setLevel(orig_level) class LogCaptureHandler(logging.StreamHandler): @@ -195,6 +186,7 @@ class LogCaptureFixture(object): obj = logger and logging.getLogger(logger) or self.handler obj.setLevel(level) + @contextmanager def at_level(self, level, logger=None): """Context manager that sets the level for capturing of logs. @@ -202,9 +194,17 @@ class LogCaptureFixture(object): logs. Specify a logger name to instead set the level of any logger. """ + if logger is None: + logger = self.handler + else: + logger = logging.getLogger(logger) - obj = logger and logging.getLogger(logger) or self.handler - return logging_at_level(level, obj) + orig_level = logger.level + logger.setLevel(level) + try: + yield + finally: + logger.setLevel(orig_level) class CallablePropertyMixin(object): From 2559ec8bdbaa71f5bc127e2f3fe50b79b98a2ad4 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Sun, 17 Sep 2017 14:14:13 +0200 Subject: [PATCH 21/33] use 'formatter' kwarg of catching_logs --- _pytest/logging.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index cec37b641..57ed4035b 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -350,9 +350,9 @@ class LoggingPlugin(object): log_cli_formatter = logging.Formatter( log_cli_format, datefmt=log_cli_date_format) - log_cli_handler.setFormatter(log_cli_formatter) self.log_cli_handler = log_cli_handler # needed for a single unittest self.live_logs = catching_logs(log_cli_handler, + formatter=log_cli_formatter, level=self.log_cli_level) log_file = get_option_ini(config, 'log_file') From ad21d5cac4a65d3b2d167453d1f92f053b86f5fb Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Sun, 17 Sep 2017 14:28:18 +0200 Subject: [PATCH 22/33] Remove pytest-capturelog backward compat code --- _pytest/logging.py | 81 ++--------------------- testing/logging/test_capturelog_compat.py | 80 ---------------------- testing/logging/test_fixture.py | 26 -------- 3 files changed, 6 insertions(+), 181 deletions(-) delete mode 100644 testing/logging/test_capturelog_compat.py diff --git a/_pytest/logging.py b/_pytest/logging.py index 57ed4035b..b8533da2f 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -2,7 +2,6 @@ from __future__ import absolute_import, division, print_function import logging from contextlib import closing, contextmanager -import functools import sys import pytest @@ -182,9 +181,11 @@ class LogCaptureFixture(object): 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) + if logger is None: + logger = self.handler + else: + logger = logging.getLogger(logger) + logger.setLevel(level) @contextmanager def at_level(self, level, logger=None): @@ -207,76 +208,6 @@ class LogCaptureFixture(object): logger.setLevel(orig_level) -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. @@ -287,7 +218,7 @@ def caplog(request): * caplog.records() -> list of logging.LogRecord instances * caplog.record_tuples() -> list of (logger_name, level, message) tuples """ - return CompatLogCaptureFixture(request.node) + return LogCaptureFixture(request.node) def get_actual_log_level(config, setting_name): diff --git a/testing/logging/test_capturelog_compat.py b/testing/logging/test_capturelog_compat.py deleted file mode 100644 index 0c527b587..000000000 --- a/testing/logging/test_capturelog_compat.py +++ /dev/null @@ -1,80 +0,0 @@ -# -*- coding: utf-8 -*- -import pytest - - -def test_camel_case_aliases(testdir): - testdir.makepyfile(''' - import logging - - logger = logging.getLogger(__name__) - - def test_foo(caplog): - caplog.setLevel(logging.INFO) - logger.debug('boo!') - - with caplog.atLevel(logging.WARNING): - logger.info('catch me if you can') - ''') - result = testdir.runpytest() - assert result.ret == 0 - - with pytest.raises(pytest.fail.Exception): - result.stdout.fnmatch_lines(['*- Captured *log call -*']) - - result = testdir.runpytest('-rw') - assert result.ret == 0 - result.stdout.fnmatch_lines(''' - =*warning* summary*= - *caplog.setLevel()*deprecated* - *caplog.atLevel()*deprecated* - ''') - - -def test_property_call(testdir): - testdir.makepyfile(''' - import logging - - logger = logging.getLogger(__name__) - - def test_foo(caplog): - logger.info('boo %s', 'arg') - - assert caplog.text == caplog.text() == str(caplog.text) - assert caplog.records == caplog.records() == list(caplog.records) - assert (caplog.record_tuples == - caplog.record_tuples() == list(caplog.record_tuples)) - ''') - result = testdir.runpytest() - assert result.ret == 0 - - result = testdir.runpytest('-rw') - assert result.ret == 0 - result.stdout.fnmatch_lines(''' - =*warning* summary*= - *caplog.text()*deprecated* - *caplog.records()*deprecated* - *caplog.record_tuples()*deprecated* - ''') - - -def test_records_modification(testdir): - testdir.makepyfile(''' - import logging - - logger = logging.getLogger(__name__) - - def test_foo(caplog): - logger.info('boo %s', 'arg') - assert caplog.records - assert caplog.records() - - del caplog.records()[:] # legacy syntax - assert not caplog.records - assert not caplog.records() - - logger.info('foo %s', 'arg') - assert caplog.records - assert caplog.records() - ''') - result = testdir.runpytest() - assert result.ret == 0 diff --git a/testing/logging/test_fixture.py b/testing/logging/test_fixture.py index bdfa67ecc..4072234d8 100644 --- a/testing/logging/test_fixture.py +++ b/testing/logging/test_fixture.py @@ -71,29 +71,3 @@ def test_clear(caplog): assert len(caplog.records) caplog.clear() assert not len(caplog.records) - - -def test_special_warning_with_del_records_warning(testdir): - p1 = testdir.makepyfile(""" - def test_del_records_inline(caplog): - del caplog.records()[:] - """) - result = testdir.runpytest_subprocess(p1) - result.stdout.fnmatch_lines([ - "*'caplog.records()' syntax is deprecated," - " use 'caplog.records' property (or caplog.clear()) instead", - "*1 *warnings*", - ]) - - -def test_warning_with_setLevel(testdir): - p1 = testdir.makepyfile(""" - def test_inline(caplog): - caplog.setLevel(0) - """) - result = testdir.runpytest_subprocess(p1) - result.stdout.fnmatch_lines([ - "*'caplog.setLevel()' is deprecated," - " use 'caplog.set_level()' instead", - "*1 *warnings*", - ]) From 296ac5c476256cef50bc9a5cc448c34f7d2a389c Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Fri, 22 Sep 2017 22:31:29 +0200 Subject: [PATCH 23/33] Add thisch to AUTHORS --- AUTHORS | 1 + 1 file changed, 1 insertion(+) diff --git a/AUTHORS b/AUTHORS index cf31e0389..2fd2ab15e 100644 --- a/AUTHORS +++ b/AUTHORS @@ -166,6 +166,7 @@ Tarcisio Fischer Tareq Alayan Ted Xiao Thomas Grainger +Thomas Hisch Tom Viner Trevor Bekolay Tyler Goodlet From 69f3bd83360d7fb13df7e3e46eb16f029b86517d Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Fri, 22 Sep 2017 22:34:32 +0200 Subject: [PATCH 24/33] Add changelog entry for catchlog plugin --- changelog/2794.feature | 3 +++ 1 file changed, 3 insertions(+) create mode 100644 changelog/2794.feature diff --git a/changelog/2794.feature b/changelog/2794.feature new file mode 100644 index 000000000..9cff1c4bb --- /dev/null +++ b/changelog/2794.feature @@ -0,0 +1,3 @@ +Pytest now captures and displays output from the standard `logging` module. The user can control the logging level to be captured by specifying options in ``pytest.ini``, the command line and also during individual tests using markers. Also, a ``caplog`` fixture is available that enables users to test the captured log during specific tests (similar to ``capsys`` for example). For more information, please see the `docs `_. + +This feature was introduced by merging the popular `pytest-catchlog `_ plugin, thanks to `Thomas Hisch `_. Be advised that during the merging the backward compatibility interface with the defunct ``pytest-capturelog`` has been dropped. \ No newline at end of file From 0ec72d07450635cef2c0082fc3f82f1e842a92d5 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Tue, 26 Sep 2017 22:58:26 +0200 Subject: [PATCH 25/33] Improve get_option_ini and get_actual_log_level --- _pytest/logging.py | 71 ++++++++++++++++++++-------------------------- 1 file changed, 31 insertions(+), 40 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index b8533da2f..950b0f512 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -3,6 +3,7 @@ from __future__ import absolute_import, division, print_function import logging from contextlib import closing, contextmanager import sys +import six import pytest import py @@ -12,12 +13,13 @@ DEFAULT_LOG_FORMAT = '%(filename)-25s %(lineno)4d %(levelname)-8s %(message)s' DEFAULT_LOG_DATE_FORMAT = '%H:%M:%S' -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 get_option_ini(config, *names): + for name in names: + ret = config.getoption(name) # 'default' arg won't work as expected + if ret is None: + ret = config.getini(name) + if ret: + return ret def pytest_addoption(parser): """Add options to control log capturing.""" @@ -221,12 +223,19 @@ def caplog(request): return LogCaptureFixture(request.node) -def get_actual_log_level(config, setting_name): +def get_actual_log_level(config, *setting_names): """Return the actual logging level.""" - log_level = get_option_ini(config, setting_name) - if not log_level: + + for setting_name in setting_names: + log_level = config.getoption(setting_name) + if log_level is None: + log_level = config.getini(setting_name) + if log_level: + break + else: return - if isinstance(log_level, py.builtin.text): + + if isinstance(log_level, six.string_types): log_level = log_level.upper() try: return int(getattr(logging, log_level, log_level)) @@ -254,15 +263,8 @@ class LoggingPlugin(object): The formatter can be safely shared across all handlers so create a single one for the entire test session here. """ - 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 - self.log_cli_level = log_cli_level + self.log_cli_level = get_actual_log_level( + config, 'log_cli_level', 'log_level') or logging.WARNING self.print_logs = get_option_ini(config, 'log_print') self.formatter = logging.Formatter( @@ -270,14 +272,10 @@ class LoggingPlugin(object): get_option_ini(config, 'log_date_format')) 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_format = get_option_ini( + config, 'log_cli_format', 'log_format') + log_cli_date_format = get_option_ini( + config, 'log_cli_date_format', 'log_date_format') log_cli_formatter = logging.Formatter( log_cli_format, datefmt=log_cli_date_format) @@ -288,20 +286,13 @@ class LoggingPlugin(object): log_file = get_option_ini(config, 'log_file') if 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 - self.log_file_level = log_file_level + self.log_file_level = get_actual_log_level( + config, 'log_file_level') or logging.WARNING - 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') + log_file_format = get_option_ini( + config, 'log_file_format', 'log_format') + log_file_date_format = get_option_ini( + config, 'log_file_date_format', 'log_date_format') self.log_file_handler = logging.FileHandler( log_file, # Each pytest runtests session will write to a clean logfile From 1f3ab118fae69ddd60677289173b9726f7b5c068 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Tue, 26 Sep 2017 23:05:42 +0200 Subject: [PATCH 26/33] Remove usage of get_logger_obj --- _pytest/logging.py | 14 ++------------ 1 file changed, 2 insertions(+), 12 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 950b0f512..76d5be34b 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -78,20 +78,10 @@ def pytest_addoption(parser): 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_using_handler(handler, logger=None): """Context manager that safely registers a given handler.""" - logger = get_logger_obj(logger) + logger = logger or logging.getLogger(logger) if handler in logger.handlers: # reentrancy # Adding the same handler twice would confuse logging system. @@ -109,7 +99,7 @@ def logging_using_handler(handler, logger=None): def catching_logs(handler, formatter=None, level=logging.NOTSET, logger=None): """Context manager that prepares the whole logging machinery properly.""" - logger = get_logger_obj(logger) + logger = logger or logging.getLogger(logger) if formatter is not None: handler.setFormatter(formatter) From 815dd19fb4b265e9a29ed98bf612953858fb3bbd Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Tue, 26 Sep 2017 23:27:38 +0200 Subject: [PATCH 27/33] Remove unicode literal compat code --- testing/logging/test_fixture.py | 11 ++++------- 1 file changed, 4 insertions(+), 7 deletions(-) diff --git a/testing/logging/test_fixture.py b/testing/logging/test_fixture.py index 4072234d8..b5bee4233 100644 --- a/testing/logging/test_fixture.py +++ b/testing/logging/test_fixture.py @@ -1,13 +1,10 @@ # -*- coding: utf-8 -*- -import sys import logging logger = logging.getLogger(__name__) sublogger = logging.getLogger(__name__+'.baz') -u = (lambda x: x.decode('utf-8')) if sys.version_info < (3,) else (lambda x: x) - def test_fixture_help(testdir): result = testdir.runpytest('--fixtures') @@ -60,14 +57,14 @@ def test_record_tuples(caplog): def test_unicode(caplog): - logger.info(u('bū')) + logger.info(u'bū') assert caplog.records[0].levelname == 'INFO' - assert caplog.records[0].msg == u('bū') - assert u('bū') in caplog.text + assert caplog.records[0].msg == u'bū' + assert u'bū' in caplog.text def test_clear(caplog): - logger.info(u('bū')) + logger.info(u'bū') assert len(caplog.records) caplog.clear() assert not len(caplog.records) From 0e83511d6d6fa0f6619df8a17b7c04de8e21acba Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Tue, 26 Sep 2017 23:34:54 +0200 Subject: [PATCH 28/33] Rename name of registered logging plugin --- _pytest/logging.py | 3 ++- testing/logging/test_reporting.py | 14 +++++++------- 2 files changed, 9 insertions(+), 8 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 76d5be34b..1b71a544e 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -240,7 +240,8 @@ def get_actual_log_level(config, *setting_names): def pytest_configure(config): - config.pluginmanager.register(LoggingPlugin(config), 'loggingp') + config.pluginmanager.register(LoggingPlugin(config), + 'logging-plugin') class LoggingPlugin(object): diff --git a/testing/logging/test_reporting.py b/testing/logging/test_reporting.py index af75eb632..c02ee2172 100644 --- a/testing/logging/test_reporting.py +++ b/testing/logging/test_reporting.py @@ -147,7 +147,7 @@ def test_log_cli_default_level(testdir): import pytest import logging def test_log_cli(request): - plugin = request.config.pluginmanager.getplugin('loggingp') + plugin = request.config.pluginmanager.getplugin('logging-plugin') assert plugin.log_cli_handler.level == logging.WARNING logging.getLogger('catchlog').info("This log message won't be shown") logging.getLogger('catchlog').warning("This log message will be shown") @@ -180,7 +180,7 @@ def test_log_cli_level(testdir): import pytest import logging def test_log_cli(request): - plugin = request.config.pluginmanager.getplugin('loggingp') + plugin = request.config.pluginmanager.getplugin('logging-plugin') assert plugin.log_cli_handler.level == logging.INFO logging.getLogger('catchlog').debug("This log message won't be shown") logging.getLogger('catchlog').info("This log message will be shown") @@ -236,7 +236,7 @@ def test_log_cli_ini_level(testdir): import pytest import logging def test_log_cli(request): - plugin = request.config.pluginmanager.getplugin('loggingp') + plugin = request.config.pluginmanager.getplugin('logging-plugin') assert plugin.log_cli_handler.level == logging.INFO logging.getLogger('catchlog').debug("This log message won't be shown") logging.getLogger('catchlog').info("This log message will be shown") @@ -269,7 +269,7 @@ def test_log_file_cli(testdir): import pytest import logging def test_log_file(request): - plugin = request.config.pluginmanager.getplugin('loggingp') + plugin = request.config.pluginmanager.getplugin('logging-plugin') assert plugin.log_file_handler.level == logging.WARNING logging.getLogger('catchlog').info("This log message won't be shown") logging.getLogger('catchlog').warning("This log message will be shown") @@ -300,7 +300,7 @@ def test_log_file_cli_level(testdir): import pytest import logging def test_log_file(request): - plugin = request.config.pluginmanager.getplugin('loggingp') + plugin = request.config.pluginmanager.getplugin('logging-plugin') assert plugin.log_file_handler.level == logging.INFO logging.getLogger('catchlog').debug("This log message won't be shown") logging.getLogger('catchlog').info("This log message will be shown") @@ -339,7 +339,7 @@ def test_log_file_ini(testdir): import pytest import logging def test_log_file(request): - plugin = request.config.pluginmanager.getplugin('loggingp') + plugin = request.config.pluginmanager.getplugin('logging-plugin') assert plugin.log_file_handler.level == logging.WARNING logging.getLogger('catchlog').info("This log message won't be shown") logging.getLogger('catchlog').warning("This log message will be shown") @@ -375,7 +375,7 @@ def test_log_file_ini_level(testdir): import pytest import logging def test_log_file(request): - plugin = request.config.pluginmanager.getplugin('loggingp') + plugin = request.config.pluginmanager.getplugin('logging-plugin') assert plugin.log_file_handler.level == logging.INFO logging.getLogger('catchlog').debug("This log message won't be shown") logging.getLogger('catchlog').info("This log message will be shown") From 502652ff02fb6566cd88df865fe6ec857742e172 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Tue, 26 Sep 2017 23:54:28 +0200 Subject: [PATCH 29/33] Add preliminary documentation for logging-plugin --- doc/en/usage.rst | 181 +++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 181 insertions(+) diff --git a/doc/en/usage.rst b/doc/en/usage.rst index a8c6d40a0..842604d4b 100644 --- a/doc/en/usage.rst +++ b/doc/en/usage.rst @@ -189,6 +189,187 @@ in your code and pytest automatically disables its output capture for that test: for test output occurring after you exit the interactive PDB_ tracing session and continue with the regular test run. +.. _logging: + +Logging +------- + +.. versionadded 3.3.0 + +Log messages are captured by default and for each failed test will be shown in +the same manner as captured stdout and stderr. + +Running without options:: + + pytest + +Shows failed tests like so:: + + ----------------------- Captured stdlog call ---------------------- + test_reporting.py 26 INFO text going to logger + ----------------------- Captured stdout call ---------------------- + text going to stdout + ----------------------- Captured stderr call ---------------------- + text going to stderr + ==================== 2 failed in 0.02 seconds ===================== + +By default each captured log message shows the module, line number, log level +and message. Showing the exact module and line number is useful for testing and +debugging. If desired the log format and date format can be specified to +anything that the logging module supports. + +Running pytest specifying formatting options:: + + pytest --log-format="%(asctime)s %(levelname)s %(message)s" \ + --log-date-format="%Y-%m-%d %H:%M:%S" + +Shows failed tests like so:: + + ----------------------- Captured stdlog call ---------------------- + 2010-04-10 14:48:44 INFO text going to logger + ----------------------- Captured stdout call ---------------------- + text going to stdout + ----------------------- Captured stderr call ---------------------- + text going to stderr + ==================== 2 failed in 0.02 seconds ===================== + +These options can also be customized through a configuration file:: + + [pytest] + log_format = %(asctime)s %(levelname)s %(message)s + log_date_format = %Y-%m-%d %H:%M:%S + +Although the same effect could be achieved through the ``addopts`` setting, +using dedicated options should be preferred since the latter doesn't force other +developers to have ``pytest-catchlog`` installed (while at the same time, +``addopts`` approach would fail with 'unrecognized arguments' error). Command +line arguments take precedence. + +Further it is possible to disable reporting logs on failed tests completely +with:: + + pytest --no-print-logs + +Or in you ``pytest.ini``:: + + [pytest] + log_print=False + + +Shows failed tests in the normal manner as no logs were captured:: + + ----------------------- Captured stdout call ---------------------- + text going to stdout + ----------------------- Captured stderr call ---------------------- + text going to stderr + ==================== 2 failed in 0.02 seconds ===================== + +Inside tests it is possible to change the log level for the captured log +messages. This is supported by the ``caplog`` fixture:: + + def test_foo(caplog): + caplog.set_level(logging.INFO) + pass + +By default the level is set on the handler used to catch the log messages, +however as a convenience it is also possible to set the log level of any +logger:: + + def test_foo(caplog): + caplog.set_level(logging.CRITICAL, logger='root.baz') + pass + +It is also possible to use a context manager to temporarily change the log +level:: + + def test_bar(caplog): + with caplog.at_level(logging.INFO): + pass + +Again, by default the level of the handler is affected but the level of any +logger can be changed instead with:: + + def test_bar(caplog): + with caplog.at_level(logging.CRITICAL, logger='root.baz'): + pass + +Lastly all the logs sent to the logger during the test run are made available on +the fixture in the form of both the LogRecord instances and the final log text. +This is useful for when you want to assert on the contents of a message:: + + def test_baz(caplog): + func_under_test() + for record in caplog.records: + assert record.levelname != 'CRITICAL' + assert 'wally' not in caplog.text + +For all the available attributes of the log records see the +``logging.LogRecord`` class. + +You can also resort to ``record_tuples`` if all you want to do is to ensure, +that certain messages have been logged under a given logger name with a given +severity and message:: + + def test_foo(caplog): + logging.getLogger().info('boo %s', 'arg') + + assert caplog.record_tuples == [ + ('root', logging.INFO, 'boo arg'), + ] + +You can call ``caplog.clear()`` to reset the captured log records in a test:: + + def test_something_with_clearing_records(caplog): + some_method_that_creates_log_records() + caplog.clear() + your_test_method() + assert ['Foo'] == [rec.message for rec in caplog.records] + +Live Logs +^^^^^^^^^ + +By default, catchlog will output any logging records with a level higher or +equal to WARNING. In order to actually see these logs in the console you have to +disable pytest output capture by passing ``-s``. + +You can specify the logging level for which log records with equal or higher +level are printed to the console by passing ``--log-cli-level``. This setting +accepts the logging level names as seen in python's documentation or an integer +as the logging level num. + +Additionally, you can also specify ``--log-cli-format`` and +``--log-cli-date-format`` which mirror and default to ``--log-format`` and +``--log-date-format`` if not provided, but are applied only to the console +logging handler. + +All of the CLI log options can also be set in the configuration INI file. The +option names are: + +* ``log_cli_level`` +* ``log_cli_format`` +* ``log_cli_date_format`` + +If you need to record the whole test suite logging calls to a file, you can pass +``--log-file=/path/to/log/file``. This log file is opened in write mode which +means that it will be overwritten at each run tests session. + +You can also specify the logging level for the log file by passing +``--log-file-level``. This setting accepts the logging level names as seen in +python's documentation(ie, uppercased level names) or an integer as the logging +level num. + +Additionally, you can also specify ``--log-file-format`` and +``--log-file-date-format`` which are equal to ``--log-format`` and +``--log-date-format`` but are applied to the log file logging handler. + +All of the log file options can also be set in the configuration INI file. The +option names are: + +* ``log_file`` +* ``log_file_level`` +* ``log_file_format`` +* ``log_file_date_format`` + .. _durations: From 775f4a6f2fe031e0ab01e8579cefbd528d68770d Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 27 Sep 2017 20:22:44 +0200 Subject: [PATCH 30/33] Fix flake8 issue --- _pytest/logging.py | 1 + 1 file changed, 1 insertion(+) diff --git a/_pytest/logging.py b/_pytest/logging.py index 1b71a544e..2d33f98ea 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -21,6 +21,7 @@ def get_option_ini(config, *names): if ret: return ret + def pytest_addoption(parser): """Add options to control log capturing.""" From f3261d94184280a2bc9ce9a1336c9f08cbd7a3c6 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Wed, 27 Sep 2017 00:39:41 +0200 Subject: [PATCH 31/33] Move logging docu into own rst file Remove reference of pytest-catchlog plugin in plugins.rst --- doc/en/contents.rst | 1 + doc/en/logging.rst | 192 ++++++++++++++++++++++++++++++++++++++++++++ doc/en/plugins.rst | 3 - doc/en/usage.rst | 182 ----------------------------------------- 4 files changed, 193 insertions(+), 185 deletions(-) create mode 100644 doc/en/logging.rst diff --git a/doc/en/contents.rst b/doc/en/contents.rst index 028414eb6..12dbce2ee 100644 --- a/doc/en/contents.rst +++ b/doc/en/contents.rst @@ -30,6 +30,7 @@ Full pytest documentation xunit_setup plugins writing_plugins + logging goodpractices pythonpath diff --git a/doc/en/logging.rst b/doc/en/logging.rst new file mode 100644 index 000000000..e3bf56038 --- /dev/null +++ b/doc/en/logging.rst @@ -0,0 +1,192 @@ +.. _logging: + +Logging +------- + +.. versionadded 3.3.0 + +.. note:: + + This feature is a drop-in replacement for the `pytest-catchlog + `_ plugin and they will conflict + with each other. The backward compatibility API with ``pytest-capturelog`` + has been dropped when this feature was introduced, so if for that reason you + still need ``pytest-catchlog`` you can disable the internal feature by + adding to your ``pytest.ini``: + + .. code-block:: ini + + [pytest] + addopts=-p no:logging + +Log messages are captured by default and for each failed test will be shown in +the same manner as captured stdout and stderr. + +Running without options:: + + pytest + +Shows failed tests like so:: + + ----------------------- Captured stdlog call ---------------------- + test_reporting.py 26 INFO text going to logger + ----------------------- Captured stdout call ---------------------- + text going to stdout + ----------------------- Captured stderr call ---------------------- + text going to stderr + ==================== 2 failed in 0.02 seconds ===================== + +By default each captured log message shows the module, line number, log level +and message. Showing the exact module and line number is useful for testing and +debugging. If desired the log format and date format can be specified to +anything that the logging module supports. + +Running pytest specifying formatting options:: + + pytest --log-format="%(asctime)s %(levelname)s %(message)s" \ + --log-date-format="%Y-%m-%d %H:%M:%S" + +Shows failed tests like so:: + + ----------------------- Captured stdlog call ---------------------- + 2010-04-10 14:48:44 INFO text going to logger + ----------------------- Captured stdout call ---------------------- + text going to stdout + ----------------------- Captured stderr call ---------------------- + text going to stderr + ==================== 2 failed in 0.02 seconds ===================== + +These options can also be customized through a configuration file: + +.. code-block:: ini + + [pytest] + log_format = %(asctime)s %(levelname)s %(message)s + log_date_format = %Y-%m-%d %H:%M:%S + +Further it is possible to disable reporting logs on failed tests completely +with:: + + pytest --no-print-logs + +Or in you ``pytest.ini``: + +.. code-block:: ini + + [pytest] + log_print = False + + +Shows failed tests in the normal manner as no logs were captured:: + + ----------------------- Captured stdout call ---------------------- + text going to stdout + ----------------------- Captured stderr call ---------------------- + text going to stderr + ==================== 2 failed in 0.02 seconds ===================== + +Inside tests it is possible to change the log level for the captured log +messages. This is supported by the ``caplog`` fixture:: + + def test_foo(caplog): + caplog.set_level(logging.INFO) + pass + +By default the level is set on the handler used to catch the log messages, +however as a convenience it is also possible to set the log level of any +logger:: + + def test_foo(caplog): + caplog.set_level(logging.CRITICAL, logger='root.baz') + pass + +It is also possible to use a context manager to temporarily change the log +level:: + + def test_bar(caplog): + with caplog.at_level(logging.INFO): + pass + +Again, by default the level of the handler is affected but the level of any +logger can be changed instead with:: + + def test_bar(caplog): + with caplog.at_level(logging.CRITICAL, logger='root.baz'): + pass + +Lastly all the logs sent to the logger during the test run are made available on +the fixture in the form of both the LogRecord instances and the final log text. +This is useful for when you want to assert on the contents of a message:: + + def test_baz(caplog): + func_under_test() + for record in caplog.records: + assert record.levelname != 'CRITICAL' + assert 'wally' not in caplog.text + +For all the available attributes of the log records see the +``logging.LogRecord`` class. + +You can also resort to ``record_tuples`` if all you want to do is to ensure, +that certain messages have been logged under a given logger name with a given +severity and message:: + + def test_foo(caplog): + logging.getLogger().info('boo %s', 'arg') + + assert caplog.record_tuples == [ + ('root', logging.INFO, 'boo arg'), + ] + +You can call ``caplog.clear()`` to reset the captured log records in a test:: + + def test_something_with_clearing_records(caplog): + some_method_that_creates_log_records() + caplog.clear() + your_test_method() + assert ['Foo'] == [rec.message for rec in caplog.records] + +Live Logs +^^^^^^^^^ + +By default, pytest will output any logging records with a level higher or +equal to WARNING. In order to actually see these logs in the console you have to +disable pytest output capture by passing ``-s``. + +You can specify the logging level for which log records with equal or higher +level are printed to the console by passing ``--log-cli-level``. This setting +accepts the logging level names as seen in python's documentation or an integer +as the logging level num. + +Additionally, you can also specify ``--log-cli-format`` and +``--log-cli-date-format`` which mirror and default to ``--log-format`` and +``--log-date-format`` if not provided, but are applied only to the console +logging handler. + +All of the CLI log options can also be set in the configuration INI file. The +option names are: + +* ``log_cli_level`` +* ``log_cli_format`` +* ``log_cli_date_format`` + +If you need to record the whole test suite logging calls to a file, you can pass +``--log-file=/path/to/log/file``. This log file is opened in write mode which +means that it will be overwritten at each run tests session. + +You can also specify the logging level for the log file by passing +``--log-file-level``. This setting accepts the logging level names as seen in +python's documentation(ie, uppercased level names) or an integer as the logging +level num. + +Additionally, you can also specify ``--log-file-format`` and +``--log-file-date-format`` which are equal to ``--log-format`` and +``--log-date-format`` but are applied to the log file logging handler. + +All of the log file options can also be set in the configuration INI file. The +option names are: + +* ``log_file`` +* ``log_file_level`` +* ``log_file_format`` +* ``log_file_date_format`` diff --git a/doc/en/plugins.rst b/doc/en/plugins.rst index ec031e9e0..bba7d3ecd 100644 --- a/doc/en/plugins.rst +++ b/doc/en/plugins.rst @@ -27,9 +27,6 @@ Here is a little annotated list for some popular plugins: for `twisted `_ apps, starting a reactor and processing deferreds from test functions. -* `pytest-catchlog `_: - to capture and assert about messages from the logging module - * `pytest-cov `_: coverage reporting, compatible with distributed testing diff --git a/doc/en/usage.rst b/doc/en/usage.rst index 842604d4b..1cb64ec87 100644 --- a/doc/en/usage.rst +++ b/doc/en/usage.rst @@ -189,188 +189,6 @@ in your code and pytest automatically disables its output capture for that test: for test output occurring after you exit the interactive PDB_ tracing session and continue with the regular test run. -.. _logging: - -Logging -------- - -.. versionadded 3.3.0 - -Log messages are captured by default and for each failed test will be shown in -the same manner as captured stdout and stderr. - -Running without options:: - - pytest - -Shows failed tests like so:: - - ----------------------- Captured stdlog call ---------------------- - test_reporting.py 26 INFO text going to logger - ----------------------- Captured stdout call ---------------------- - text going to stdout - ----------------------- Captured stderr call ---------------------- - text going to stderr - ==================== 2 failed in 0.02 seconds ===================== - -By default each captured log message shows the module, line number, log level -and message. Showing the exact module and line number is useful for testing and -debugging. If desired the log format and date format can be specified to -anything that the logging module supports. - -Running pytest specifying formatting options:: - - pytest --log-format="%(asctime)s %(levelname)s %(message)s" \ - --log-date-format="%Y-%m-%d %H:%M:%S" - -Shows failed tests like so:: - - ----------------------- Captured stdlog call ---------------------- - 2010-04-10 14:48:44 INFO text going to logger - ----------------------- Captured stdout call ---------------------- - text going to stdout - ----------------------- Captured stderr call ---------------------- - text going to stderr - ==================== 2 failed in 0.02 seconds ===================== - -These options can also be customized through a configuration file:: - - [pytest] - log_format = %(asctime)s %(levelname)s %(message)s - log_date_format = %Y-%m-%d %H:%M:%S - -Although the same effect could be achieved through the ``addopts`` setting, -using dedicated options should be preferred since the latter doesn't force other -developers to have ``pytest-catchlog`` installed (while at the same time, -``addopts`` approach would fail with 'unrecognized arguments' error). Command -line arguments take precedence. - -Further it is possible to disable reporting logs on failed tests completely -with:: - - pytest --no-print-logs - -Or in you ``pytest.ini``:: - - [pytest] - log_print=False - - -Shows failed tests in the normal manner as no logs were captured:: - - ----------------------- Captured stdout call ---------------------- - text going to stdout - ----------------------- Captured stderr call ---------------------- - text going to stderr - ==================== 2 failed in 0.02 seconds ===================== - -Inside tests it is possible to change the log level for the captured log -messages. This is supported by the ``caplog`` fixture:: - - def test_foo(caplog): - caplog.set_level(logging.INFO) - pass - -By default the level is set on the handler used to catch the log messages, -however as a convenience it is also possible to set the log level of any -logger:: - - def test_foo(caplog): - caplog.set_level(logging.CRITICAL, logger='root.baz') - pass - -It is also possible to use a context manager to temporarily change the log -level:: - - def test_bar(caplog): - with caplog.at_level(logging.INFO): - pass - -Again, by default the level of the handler is affected but the level of any -logger can be changed instead with:: - - def test_bar(caplog): - with caplog.at_level(logging.CRITICAL, logger='root.baz'): - pass - -Lastly all the logs sent to the logger during the test run are made available on -the fixture in the form of both the LogRecord instances and the final log text. -This is useful for when you want to assert on the contents of a message:: - - def test_baz(caplog): - func_under_test() - for record in caplog.records: - assert record.levelname != 'CRITICAL' - assert 'wally' not in caplog.text - -For all the available attributes of the log records see the -``logging.LogRecord`` class. - -You can also resort to ``record_tuples`` if all you want to do is to ensure, -that certain messages have been logged under a given logger name with a given -severity and message:: - - def test_foo(caplog): - logging.getLogger().info('boo %s', 'arg') - - assert caplog.record_tuples == [ - ('root', logging.INFO, 'boo arg'), - ] - -You can call ``caplog.clear()`` to reset the captured log records in a test:: - - def test_something_with_clearing_records(caplog): - some_method_that_creates_log_records() - caplog.clear() - your_test_method() - assert ['Foo'] == [rec.message for rec in caplog.records] - -Live Logs -^^^^^^^^^ - -By default, catchlog will output any logging records with a level higher or -equal to WARNING. In order to actually see these logs in the console you have to -disable pytest output capture by passing ``-s``. - -You can specify the logging level for which log records with equal or higher -level are printed to the console by passing ``--log-cli-level``. This setting -accepts the logging level names as seen in python's documentation or an integer -as the logging level num. - -Additionally, you can also specify ``--log-cli-format`` and -``--log-cli-date-format`` which mirror and default to ``--log-format`` and -``--log-date-format`` if not provided, but are applied only to the console -logging handler. - -All of the CLI log options can also be set in the configuration INI file. The -option names are: - -* ``log_cli_level`` -* ``log_cli_format`` -* ``log_cli_date_format`` - -If you need to record the whole test suite logging calls to a file, you can pass -``--log-file=/path/to/log/file``. This log file is opened in write mode which -means that it will be overwritten at each run tests session. - -You can also specify the logging level for the log file by passing -``--log-file-level``. This setting accepts the logging level names as seen in -python's documentation(ie, uppercased level names) or an integer as the logging -level num. - -Additionally, you can also specify ``--log-file-format`` and -``--log-file-date-format`` which are equal to ``--log-format`` and -``--log-date-format`` but are applied to the log file logging handler. - -All of the log file options can also be set in the configuration INI file. The -option names are: - -* ``log_file`` -* ``log_file_level`` -* ``log_file_format`` -* ``log_file_date_format`` - - .. _durations: Profiling test execution duration From 8aed5fecd9f5b3b715b4cb00c6e2b72dd86f6e70 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Thu, 12 Oct 2017 01:34:03 +0200 Subject: [PATCH 32/33] Remove test_logging_initialized_in_test --- testing/test_capture.py | 17 ----------------- 1 file changed, 17 deletions(-) diff --git a/testing/test_capture.py b/testing/test_capture.py index 79e34a40f..336ca9ef0 100644 --- a/testing/test_capture.py +++ b/testing/test_capture.py @@ -342,23 +342,6 @@ class TestLoggingInteraction(object): # verify proper termination assert "closed" not in s - def test_logging_initialized_in_test(self, testdir): - p = testdir.makepyfile(""" - def test_something(): - import logging - logging.basicConfig() - logging.warn("hello432") - assert 0 - """) - result = testdir.runpytest_subprocess( - p, "--traceconfig", - "-p", "no:capturelog", "-p", "no:hypothesis", "-p", "no:hypothesispytest") - assert result.ret != 0 - result.stdout.fnmatch_lines([ - "*hello432*", - ]) - assert 'operation on closed file' not in result.stderr.str() - def test_conftestlogging_is_shown(self, testdir): testdir.makeconftest(""" import logging From af75ca435b91d7f487c379831be8821630cf5458 Mon Sep 17 00:00:00 2001 From: Thomas Hisch Date: Thu, 12 Oct 2017 01:48:39 +0200 Subject: [PATCH 33/33] Fix some coding-style issues in the logging plugin --- _pytest/logging.py | 18 +++++++----------- 1 file changed, 7 insertions(+), 11 deletions(-) diff --git a/_pytest/logging.py b/_pytest/logging.py index 2d33f98ea..ed4db25ad 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -24,7 +24,6 @@ def get_option_ini(config, *names): def pytest_addoption(parser): """Add options to control log capturing.""" - group = parser.getgroup('logging') def add_option_ini(option, dest, default=None, type=None, **kwargs): @@ -120,13 +119,11 @@ class LogCaptureHandler(logging.StreamHandler): def __init__(self): """Creates a new log handler.""" - logging.StreamHandler.__init__(self, py.io.TextIO()) self.records = [] 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) @@ -260,8 +257,8 @@ class LoggingPlugin(object): self.print_logs = get_option_ini(config, 'log_print') self.formatter = logging.Formatter( - get_option_ini(config, 'log_format'), - get_option_ini(config, 'log_date_format')) + get_option_ini(config, 'log_format'), + get_option_ini(config, 'log_date_format')) log_cli_handler = logging.StreamHandler(sys.stderr) log_cli_format = get_option_ini( @@ -269,8 +266,8 @@ class LoggingPlugin(object): log_cli_date_format = get_option_ini( config, 'log_cli_date_format', 'log_date_format') log_cli_formatter = logging.Formatter( - log_cli_format, - datefmt=log_cli_date_format) + log_cli_format, + datefmt=log_cli_date_format) self.log_cli_handler = log_cli_handler # needed for a single unittest self.live_logs = catching_logs(log_cli_handler, formatter=log_cli_formatter, @@ -288,11 +285,10 @@ class LoggingPlugin(object): self.log_file_handler = logging.FileHandler( log_file, # Each pytest runtests session will write to a clean logfile - mode='w', - ) + mode='w') log_file_formatter = logging.Formatter( - log_file_format, - datefmt=log_file_date_format) + log_file_format, + datefmt=log_file_date_format) self.log_file_handler.setFormatter(log_file_formatter) else: self.log_file_handler = None