diff --git a/.travis.yml b/.travis.yml index 8d65142..d0eb2a6 100644 --- a/.travis.yml +++ b/.travis.yml @@ -1,14 +1,19 @@ +sudo: false language: python -python: 2.7 -env: - - TOX_ENV=pypy3 - - TOX_ENV=pypy - - TOX_ENV=py34 - - TOX_ENV=py33 - - TOX_ENV=py32 - - TOX_ENV=py27 +python: + - "2.7" + - "3.2" + - "3.3" + - "3.4" + - "3.5" + - "pypy" + - "pypy3" + install: - - pip install tox + - pip install -e . script: - - tox -e $TOX_ENV -sudo: false + - py.test + +cache: + directories: + - $HOME/.cache/pip/http 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 7cd4e0a..299ad21 100644 --- a/pytest_catchlog.py +++ b/pytest_catchlog.py @@ -1,15 +1,75 @@ # -*- coding: utf-8 -*- -from __future__ import (absolute_import, print_function, - unicode_literals, division) +from __future__ import absolute_import, division, print_function import logging +from contextlib import closing, contextmanager +import pytest import py __version__ = '1.1' +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 register 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), \ + logging_using_handler(handler, logger), \ + logging_at_level(min(handler.level, logger.level), logger): + + yield handler + + def add_option_ini(parser, option, dest, default=None, help=None): parser.addini(dest, default=default, help='default value for ' + option) @@ -62,58 +122,39 @@ def __init__(self, config): get_option_ini(config, 'log_format'), get_option_ini(config, 'log_date_format')) + @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): - """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. - """ - - # Create a handler for this test. - item.catch_log_handler = CatchLogHandler() - item.catch_log_handler.setFormatter(self.formatter) + with self._runtest_for(item, 'setup'): + yield - # 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) + @pytest.mark.hookwrapper + def pytest_runtest_call(self, item): + with self._runtest_for(item, 'call'): + yield - def pytest_runtest_makereport(self, __multicall__, item, call): - """Add captured log messages for this report.""" + @pytest.mark.hookwrapper + def pytest_runtest_teardown(self, item): + with self._runtest_for(item, 'teardown'): + yield - report = __multicall__.execute() - # This fn called after setup, call and teardown. Only - # interested in just after test call has finished. - if call.when == 'call': - - # 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) - - # 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) - - # Release the handler resources. - item.catch_log_handler.close() - del item.catch_log_handler - - return report - - -class CatchLogHandler(logging.StreamHandler): +class LogCaptureHandler(logging.StreamHandler): """A logging handler that stores log records and the log text.""" def __init__(self): @@ -136,13 +177,16 @@ def emit(self, record): logging.StreamHandler.emit(self, record) -class CatchLogFuncArg(object): +class LogCaptureFixture(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.""" @@ -184,37 +228,19 @@ def at_level(self, level, logger=None): """ obj = logger and logging.getLogger(logger) or self.handler - return CatchLogLevel(obj, level) - + return logging_at_level(level, obj) -class CatchLogLevel(object): - """Context manager that sets the logging level of a handler or logger.""" - def __init__(self, obj, level): - """Creates a new log level context manager.""" +@pytest.fixture +def caplog(request): + """Access and control log capturing. - self.obj = obj - self.level = level + Captured logs are available through the following methods:: - def __enter__(self): - """Adjust the log level.""" - - self.orig_level = self.obj.level - self.obj.setLevel(self.level) - - def __exit__(self, exc_type, exc_value, traceback): - """Restore the log level.""" - - self.obj.setLevel(self.orig_level) - - -def pytest_funcarg__caplog(request): - """Returns a funcarg to access and control log capturing.""" - - return CatchLogFuncArg(request._pyfuncitem.catch_log_handler) - - -def pytest_funcarg__capturelog(request): - """Returns a funcarg to access and control log capturing.""" + * 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 LogCaptureFixture(request.node) - return CatchLogFuncArg(request._pyfuncitem.catch_log_handler) +capturelog = caplog diff --git a/setup.py b/setup.py index ba84092..6ab8b4a 100755 --- a/setup.py +++ b/setup.py @@ -26,11 +26,11 @@ def _get_version(): author_email='eisensheng@mailbox.org', url='https://github.com/eisensheng/pytest-catchlog', py_modules=['pytest_catchlog', ], - install_requires=['py>=1.1.1', ], + install_requires=['py>=1.1.1', 'pytest>=2.6'], entry_points={'pytest11': ['pytest_catchlog = pytest_catchlog']}, license='MIT License', zip_safe=False, - keywords='py.test pytest', + keywords='py.test pytest logging', classifiers=['Development Status :: 4 - Beta', 'Intended Audience :: Developers', 'License :: OSI Approved :: MIT License', @@ -41,6 +41,7 @@ def _get_version(): 'Programming Language :: Python :: 3.2', 'Programming Language :: Python :: 3.3', 'Programming Language :: Python :: 3.4', + 'Programming Language :: Python :: 3.5', 'Programming Language :: Python :: Implementation :: CPython', 'Programming Language :: Python :: Implementation :: PyPy', 'Topic :: Software Development :: Testing']) diff --git a/test_pytest_catchlog.py b/test_pytest_catchlog.py index 0e9d55f..3b7b1bc 100644 --- a/test_pytest_catchlog.py +++ b/test_pytest_catchlog.py @@ -1,6 +1,6 @@ import py -pytest_plugins = 'pytester', 'catchlog' +pytest_plugins = 'pytester' def test_nothing_logged(testdir): @@ -8,8 +8,6 @@ def test_nothing_logged(testdir): import sys import logging - pytest_plugins = 'catchlog' - def test_foo(): sys.stdout.write('text going to stdout') sys.stderr.write('text going to stderr') @@ -22,7 +20,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): @@ -30,8 +28,6 @@ def test_messages_logged(testdir): import sys import logging - pytest_plugins = 'catchlog' - def test_foo(): sys.stdout.write('text going to stdout') sys.stderr.write('text going to stderr') @@ -40,7 +36,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']) @@ -48,12 +44,50 @@ def test_foo(): 'text going to stderr']) -def test_change_level(testdir): +def test_setup_logging(testdir): + testdir.makepyfile(''' + import sys + import logging + + def setup_function(function): + logging.getLogger().info('text going to logger from setup') + + def test_foo(): + logging.getLogger().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 sys import logging - pytest_plugins = 'catchlog' + def test_foo(): + logging.getLogger().info('text going to logger from call') + + def teardown_function(function): + logging.getLogger().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_change_level(testdir): + testdir.makepyfile(''' + import sys + import logging def test_foo(caplog): caplog.set_level(logging.INFO) @@ -70,13 +104,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)') @@ -86,8 +120,6 @@ def test_with_statement(testdir): import sys import logging - pytest_plugins = 'catchlog' - def test_foo(caplog): with caplog.at_level(logging.INFO): log = logging.getLogger() @@ -103,13 +135,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): @@ -117,8 +149,6 @@ def test_log_access(testdir): import sys import logging - pytest_plugins = 'catchlog' - def test_foo(caplog): logging.getLogger().info('boo %s', 'arg') assert caplog.records()[0].levelname == 'INFO' @@ -139,8 +169,6 @@ def test_record_tuples(testdir): import sys import logging - pytest_plugins = 'catchlog' - def test_foo(caplog): logging.getLogger().info('boo %s', 'arg') @@ -157,8 +185,6 @@ def test_disable_log_capturing(testdir): import sys import logging - pytest_plugins = 'catchlog' - def test_foo(caplog): sys.stdout.write('text going to stdout') logging.getLogger().warning('catch me if you can!') @@ -173,4 +199,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 -*']) diff --git a/tox.ini b/tox.ini index 3be9fcb..eda5e37 100644 --- a/tox.ini +++ b/tox.ini @@ -1,5 +1,5 @@ [tox] -envlist = py{27,32,33,34,py,py3} +envlist = py{27,32,33,34,35}, pypy{,3} [testenv] deps =