# -*- coding: utf-8 -*- import os import six 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('--log-level=INFO') 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('--log-level=INFO') 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('--log-level=INFO') 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 -*']) @pytest.mark.parametrize('enabled', [True, False]) def test_log_cli_enabled_disabled(testdir, enabled): msg = 'critical message logged by test' testdir.makepyfile(''' import logging def test_log_cli(): logging.critical("{}") '''.format(msg)) if enabled: testdir.makeini(''' [pytest] log_cli=true ''') result = testdir.runpytest() if enabled: result.stdout.fnmatch_lines([ 'test_log_cli_enabled_disabled.py::test_log_cli ', 'test_log_cli_enabled_disabled.py* CRITICAL critical message logged by test', 'PASSED*', ]) else: assert msg not in result.stdout.str() 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('logging-plugin') assert plugin.log_cli_handler.level == logging.NOTSET logging.getLogger('catchlog').info("INFO message won't be shown") logging.getLogger('catchlog').warning("WARNING message will be shown") ''') testdir.makeini(''' [pytest] log_cli=true ''') result = testdir.runpytest() # fnmatch_lines does an assertion internally result.stdout.fnmatch_lines([ 'test_log_cli_default_level.py::test_log_cli ', 'test_log_cli_default_level.py*WARNING message will be shown*', ]) assert "INFO message won't be shown" not in result.stdout.str() # make sure that that we get a '0' exit code for the testsuite assert result.ret == 0 def test_log_cli_default_level_multiple_tests(testdir, request): """Ensure we reset the first newline added by the live logger between tests""" filename = request.node.name + '.py' testdir.makepyfile(''' import logging def test_log_1(): logging.warning("log message from test_log_1") def test_log_2(): logging.warning("log message from test_log_2") ''') testdir.makeini(''' [pytest] log_cli=true ''') result = testdir.runpytest() result.stdout.fnmatch_lines([ '{}::test_log_1 '.format(filename), '*WARNING*log message from test_log_1*', 'PASSED *50%*', '{}::test_log_2 '.format(filename), '*WARNING*log message from test_log_2*', 'PASSED *100%*', '=* 2 passed in *=', ]) def test_log_cli_default_level_sections(testdir, request): """Check that with live logging enable we are printing the correct headers during setup/call/teardown.""" filename = request.node.name + '.py' testdir.makepyfile(''' import pytest import logging @pytest.fixture def fix(request): logging.warning("log message from setup of {}".format(request.node.name)) yield logging.warning("log message from teardown of {}".format(request.node.name)) def test_log_1(fix): logging.warning("log message from test_log_1") def test_log_2(fix): logging.warning("log message from test_log_2") ''') testdir.makeini(''' [pytest] log_cli=true ''') result = testdir.runpytest() result.stdout.fnmatch_lines([ '{}::test_log_1 '.format(filename), '*-- live log setup --*', '*WARNING*log message from setup of test_log_1*', '*-- live log call --*', '*WARNING*log message from test_log_1*', 'PASSED *50%*', '*-- live log teardown --*', '*WARNING*log message from teardown of test_log_1*', '{}::test_log_2 '.format(filename), '*-- live log setup --*', '*WARNING*log message from setup of test_log_2*', '*-- live log call --*', '*WARNING*log message from test_log_2*', 'PASSED *100%*', '*-- live log teardown --*', '*WARNING*log message from teardown of test_log_2*', '=* 2 passed in *=', ]) 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('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") print('PASSED') ''') testdir.makeini(''' [pytest] log_cli=true ''') result = testdir.runpytest('-s', '--log-cli-level=INFO') # fnmatch_lines does an assertion internally result.stdout.fnmatch_lines([ 'test_log_cli_level.py*This log message will be shown', 'PASSED', # 'PASSED' on its own line because the log message prints a new line ]) assert "This log message won't be shown" not in result.stdout.str() # 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* This log message will be shown', 'PASSED', # 'PASSED' on its own line because the log message prints a new line ]) assert "This log message won't be shown" not in result.stdout.str() # 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=true log_cli_level = INFO """) testdir.makepyfile(''' import pytest import logging def test_log_cli(request): 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") print('PASSED') ''') result = testdir.runpytest('-s') # fnmatch_lines does an assertion internally result.stdout.fnmatch_lines([ 'test_log_cli_ini_level.py* This log message will be shown', 'PASSED', # 'PASSED' on its own line because the log message prints a new line ]) assert "This log message won't be shown" not in result.stdout.str() # 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('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") print('PASSED') ''') log_file = testdir.tmpdir.join('pytest.log').strpath result = testdir.runpytest('-s', '--log-file={0}'.format(log_file), '--log-file-level=WARNING') # 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('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") 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_level_not_changed_by_default(testdir): testdir.makepyfile(''' import logging def test_log_file(): assert logging.getLogger().level == logging.WARNING ''') result = testdir.runpytest('-s') result.stdout.fnmatch_lines('* 1 passed in *') def test_log_file_ini(testdir): log_file = testdir.tmpdir.join('pytest.log').strpath testdir.makeini( """ [pytest] log_file={0} log_file_level=WARNING """.format(log_file)) testdir.makepyfile(''' import pytest import logging def test_log_file(request): 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") 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('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") 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 @pytest.mark.parametrize('has_capture_manager', [True, False]) def test_live_logging_suspends_capture(has_capture_manager, request): """Test that capture manager is suspended when we emitting messages for live logging. This tests the implementation calls instead of behavior because it is difficult/impossible to do it using ``testdir`` facilities because they do their own capturing. We parametrize the test to also make sure _LiveLoggingStreamHandler works correctly if no capture manager plugin is installed. """ import logging from functools import partial from _pytest.capture import CaptureManager from _pytest.logging import _LiveLoggingStreamHandler class MockCaptureManager: calls = [] def suspend_global_capture(self): self.calls.append('suspend_global_capture') def resume_global_capture(self): self.calls.append('resume_global_capture') # sanity check assert CaptureManager.suspend_capture_item assert CaptureManager.resume_global_capture class DummyTerminal(six.StringIO): def section(self, *args, **kwargs): pass out_file = DummyTerminal() capture_manager = MockCaptureManager() if has_capture_manager else None handler = _LiveLoggingStreamHandler(out_file, capture_manager) handler.set_when('call') logger = logging.getLogger(__name__ + '.test_live_logging_suspends_capture') logger.addHandler(handler) request.addfinalizer(partial(logger.removeHandler, handler)) logger.critical('some message') if has_capture_manager: assert MockCaptureManager.calls == ['suspend_global_capture', 'resume_global_capture'] else: assert MockCaptureManager.calls == [] assert out_file.getvalue() == '\nsome message\n'