diff --git a/README.rst b/README.rst index e192bc0..bd31294 100644 --- a/README.rst +++ b/README.rst @@ -30,11 +30,11 @@ Running without options:: Shows failed tests like so:: - -------------------------- Captured log --------------------------- + ----------------------- Captured stdlog call ---------------------- test_pytest_catchlog.py 26 INFO text going to logger - ------------------------- Captured stdout ------------------------- + ----------------------- Captured stdout call ---------------------- text going to stdout - ------------------------- Captured stderr ------------------------- + ----------------------- Captured stderr call ---------------------- text going to stderr ==================== 2 failed in 0.02 seconds ===================== @@ -50,11 +50,11 @@ Running pytest specifying formatting options:: Shows failed tests like so:: - -------------------------- Captured log --------------------------- + ----------------------- Captured stdlog call ---------------------- 2010-04-10 14:48:44 INFO text going to logger - ------------------------- Captured stdout ------------------------- + ----------------------- Captured stdout call ---------------------- text going to stdout - ------------------------- Captured stderr ------------------------- + ----------------------- Captured stderr call ---------------------- text going to stderr ==================== 2 failed in 0.02 seconds ===================== @@ -77,9 +77,9 @@ completely with:: Shows failed tests in the normal manner as no logs were captured:: - ------------------------- Captured stdout ------------------------- + ----------------------- Captured stdout call ---------------------- text going to stdout - ------------------------- Captured stderr ------------------------- + ----------------------- Captured stderr call ---------------------- text going to stderr ==================== 2 failed in 0.02 seconds ===================== @@ -87,7 +87,7 @@ Inside tests it is possible to change the log level for the captured log messages. This is supported by the ``caplog`` funcarg:: def test_foo(caplog): - caplog.setLevel(logging.INFO) + caplog.set_level(logging.INFO) pass By default the level is set on the handler used to catch the log @@ -95,21 +95,21 @@ messages, however as a convenience it is also possible to set the log level of any logger:: def test_foo(caplog): - caplog.setLevel(logging.CRITICAL, logger='root.baz') + 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.atLevel(logging.INFO): + 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.atLevel(logging.CRITICAL, logger='root.baz'): + with caplog.at_level(logging.CRITICAL, logger='root.baz'): pass Lastly all the logs sent to the logger during the test run are made diff --git a/pytest_catchlog.py b/pytest_catchlog.py index a8a6588..ed60fa2 100644 --- a/pytest_catchlog.py +++ b/pytest_catchlog.py @@ -2,6 +2,7 @@ from __future__ import absolute_import, division, print_function import logging +from contextlib import closing, contextmanager import pytest import py @@ -62,55 +63,40 @@ def __init__(self, config): get_option_ini(config, 'log_format'), get_option_ini(config, 'log_date_format')) - def pytest_runtest_setup(self, item): - """Start capturing log messages for this test. - - Creating a specific handler for each test ensures that we - avoid multi threading issues. - - Attaching the handler and setting the level at the beginning - of each test ensures that we are setup to capture log - messages. - """ - + @pytest.mark.hookwrapper + def pytest_runtest_call(self, item): # Create a handler for this test. - item.catch_log_handler = CatchLogHandler() - item.catch_log_handler.setFormatter(self.formatter) + # Creating a specific handler for each test ensures that we + # avoid multi threading issues. + with closing(CatchLogHandler()) as log_handler: + log_handler.setFormatter(self.formatter) - # Attach the handler to the root logger and ensure that the - # root logger is set to log all levels. - root_logger = logging.getLogger() - root_logger.addHandler(item.catch_log_handler) - root_logger.setLevel(logging.NOTSET) + # Attach the handler to the root logger and ensure that the + # root logger is set to log all levels. + root_logger = logging.getLogger() + root_logger.addHandler(log_handler) - def pytest_runtest_makereport(self, __multicall__, item, call): - """Add captured log messages for this report.""" + root_level = root_logger.level + root_logger.setLevel(logging.NOTSET) - report = __multicall__.execute() + item.catch_log_handler = log_handler + try: - # This fn called after setup, call and teardown. Only - # interested in just after test call has finished. - if call.when == 'call': + yield # run test - # Detach the handler from the root logger to ensure no - # further access to the handler. - root_logger = logging.getLogger() - root_logger.removeHandler(item.catch_log_handler) + finally: + del item.catch_log_handler - # For failed tests that have captured log messages add a - # captured log section to the report if desired. - if not report.passed and self.print_logs: - long_repr = getattr(report, 'longrepr', None) - if hasattr(long_repr, 'addsection'): - log = item.catch_log_handler.stream.getvalue().strip() - if log: - long_repr.addsection('Captured log', log) + root_logger.level = root_level - # Release the handler resources. - item.catch_log_handler.close() - del item.catch_log_handler + # Detach the handler from the root logger to ensure no + # further access to the handler. + root_logger.removeHandler(log_handler) - return report + if self.print_logs: + # Add a captured log section to the report. + log = log_handler.stream.getvalue().strip() + item.add_report_section('call', 'log', log) class CatchLogHandler(logging.StreamHandler): @@ -139,10 +125,13 @@ def emit(self, record): class CatchLogFuncArg(object): """Provides access and control of log capturing.""" - def __init__(self, handler): - """Creates a new funcarg.""" + @property + def handler(self): + return self._item.catch_log_handler - self.handler = handler + def __init__(self, item): + """Creates a new funcarg.""" + self._item = item def text(self): """Returns the log text.""" @@ -218,6 +207,6 @@ def caplog(request): * caplog.records() -> list of logging.LogRecord instances * caplog.record_tuples() -> list of (logger_name, level, message) tuples """ - return CatchLogFuncArg(request._pyfuncitem.catch_log_handler) + return CatchLogFuncArg(request.node) capturelog = caplog diff --git a/test_pytest_catchlog.py b/test_pytest_catchlog.py index 0e9d55f..3152bb7 100644 --- a/test_pytest_catchlog.py +++ b/test_pytest_catchlog.py @@ -22,7 +22,7 @@ def test_foo(): result.stdout.fnmatch_lines(['*- Captured stderr call -*', 'text going to stderr']) py.test.raises(Exception, result.stdout.fnmatch_lines, - ['*- Captured log -*']) + ['*- Captured *log call -*']) def test_messages_logged(testdir): @@ -40,7 +40,7 @@ def test_foo(): ''') result = testdir.runpytest() assert result.ret == 1 - result.stdout.fnmatch_lines(['*- Captured log -*', + result.stdout.fnmatch_lines(['*- Captured *log call -*', '*text going to logger*']) result.stdout.fnmatch_lines(['*- Captured stdout call -*', 'text going to stdout']) @@ -70,13 +70,13 @@ def test_foo(caplog): ''') result = testdir.runpytest() assert result.ret == 1 - result.stdout.fnmatch_lines(['*- Captured log -*', + result.stdout.fnmatch_lines(['*- Captured *log call -*', '*handler INFO level*', '*logger CRITICAL level*']) py.test.raises(Exception, result.stdout.fnmatch_lines, - ['*- Captured log -*', '*handler DEBUG level*']) + ['*- Captured *log call -*', '*handler DEBUG level*']) py.test.raises(Exception, result.stdout.fnmatch_lines, - ['*- Captured log -*', '*logger WARNING level*']) + ['*- Captured *log call -*', '*logger WARNING level*']) @py.test.mark.skipif('sys.version_info < (2,5)') @@ -103,13 +103,13 @@ def test_foo(caplog): ''') result = testdir.runpytest() assert result.ret == 1 - result.stdout.fnmatch_lines(['*- Captured log -*', + result.stdout.fnmatch_lines(['*- Captured *log call -*', '*handler INFO level*', '*logger CRITICAL level*']) py.test.raises(Exception, result.stdout.fnmatch_lines, - ['*- Captured log -*', '*handler DEBUG level*']) + ['*- Captured *log call -*', '*handler DEBUG level*']) py.test.raises(Exception, result.stdout.fnmatch_lines, - ['*- Captured log -*', '*logger WARNING level*']) + ['*- Captured *log call -*', '*logger WARNING level*']) def test_log_access(testdir): @@ -173,4 +173,4 @@ def test_foo(caplog): result.stdout.fnmatch_lines(['*- Captured stderr call -*', 'text going to stderr']) py.test.raises(Exception, result.stdout.fnmatch_lines, - ['*- Captured log -*']) + ['*- Captured *log call -*'])