diff --git a/_pytest/logging.py b/_pytest/logging.py index 095115cd979..d5184d879ba 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -337,6 +337,11 @@ def __init__(self, config): """ self._config = config + # enable live logs if log_cli_level is explicitly set + log_cli_level = get_actual_log_level(self._config, 'log_cli_level', 'log_level') + if log_cli_level is not None: + # enable live logs if log_cli_level is explicitly set + config._inicache['log_cli'] = config._parser._inidict['log_cli'] = True # enable verbose output automatically if live logging is enabled if self._config.getini('log_cli') and not config.getoption('verbose'): # sanity check: terminal reporter should not have been loaded at this point @@ -371,18 +376,20 @@ def _runtest_for(self, item, when): formatter=self.formatter, level=self.log_level) as log_handler: if self.log_cli_handler: self.log_cli_handler.set_when(when) - if not hasattr(item, 'catch_log_handlers'): + if item and not hasattr(item, 'catch_log_handlers'): item.catch_log_handlers = {} - item.catch_log_handlers[when] = log_handler - item.catch_log_handler = log_handler + if item: + item.catch_log_handlers[when] = log_handler + item.catch_log_handler = log_handler try: yield # run test finally: - del item.catch_log_handler + if item: + del item.catch_log_handler if when == 'teardown': del item.catch_log_handlers - if self.print_logs: + if self.print_logs and item: # Add a captured log section to the report. log = log_handler.stream.getvalue().strip() item.add_report_section(when, 'log', log) @@ -402,9 +409,17 @@ def pytest_runtest_teardown(self, item): with self._runtest_for(item, 'teardown'): yield + @pytest.hookimpl(hookwrapper=True) def pytest_runtest_logstart(self): if self.log_cli_handler: self.log_cli_handler.reset() + with self._runtest_for(None, 'start'): + yield + + @pytest.hookimpl(hookwrapper=True) + def pytest_runtest_logfinish(self): + with self._runtest_for(None, 'finish'): + yield @pytest.hookimpl(hookwrapper=True) def pytest_runtestloop(self, session): @@ -474,10 +489,10 @@ def emit(self, record): if self.capture_manager is not None: self.capture_manager.suspend_global_capture() try: - if not self._first_record_emitted or self._when == 'teardown': + if not self._first_record_emitted or self._when in ('teardown', 'finish'): self.stream.write('\n') self._first_record_emitted = True - if not self._section_name_shown: + if not self._section_name_shown and self._when: self.stream.section('live log ' + self._when, sep='-', bold=True) self._section_name_shown = True logging.StreamHandler.emit(self, record) diff --git a/changelog/3175.bugfix b/changelog/3175.bugfix new file mode 100644 index 00000000000..6269e7deefc --- /dev/null +++ b/changelog/3175.bugfix @@ -0,0 +1 @@ +Don't traceback when logging on unknown(unhandled) sections. diff --git a/changelog/3175.feature b/changelog/3175.feature new file mode 100644 index 00000000000..a3b9331f070 --- /dev/null +++ b/changelog/3175.feature @@ -0,0 +1 @@ +Enable live logs is log_cli_level is passed/set explicitly diff --git a/changelog/3175.trivial b/changelog/3175.trivial new file mode 100644 index 00000000000..5fd81f99fc5 --- /dev/null +++ b/changelog/3175.trivial @@ -0,0 +1 @@ +Allow the logging plugin, when live logs are enabled, to handle the hooks `pytest_runtest_logstart` and `pytest_runtest_logfinish`. diff --git a/testing/logging/test_reporting.py b/testing/logging/test_reporting.py index f5272aa0983..628829cdcae 100644 --- a/testing/logging/test_reporting.py +++ b/testing/logging/test_reporting.py @@ -226,8 +226,20 @@ def test_log_2(): 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.""" + """Check that with live logging enable we are printing the correct headers during + start/setup/call/teardown/finish.""" filename = request.node.name + '.py' + testdir.makeconftest(''' + import pytest + import logging + + def pytest_runtest_logstart(): + logging.warning('>>>>> START >>>>>') + + def pytest_runtest_logfinish(): + logging.warning('<<<<< END <<<<<<<') + ''') + testdir.makepyfile(''' import pytest import logging @@ -252,6 +264,8 @@ def test_log_2(fix): result = testdir.runpytest() result.stdout.fnmatch_lines([ '{}::test_log_1 '.format(filename), + '*-- live log start --*', + '*WARNING* >>>>> START >>>>>*', '*-- live log setup --*', '*WARNING*log message from setup of test_log_1*', '*-- live log call --*', @@ -259,8 +273,12 @@ def test_log_2(fix): 'PASSED *50%*', '*-- live log teardown --*', '*WARNING*log message from teardown of test_log_1*', + '*-- live log finish --*', + '*WARNING* <<<<< END <<<<<<<*', '{}::test_log_2 '.format(filename), + '*-- live log start --*', + '*WARNING* >>>>> START >>>>>*', '*-- live log setup --*', '*WARNING*log message from setup of test_log_2*', '*-- live log call --*', @@ -268,10 +286,68 @@ def test_log_2(fix): 'PASSED *100%*', '*-- live log teardown --*', '*WARNING*log message from teardown of test_log_2*', + '*-- live log finish --*', + '*WARNING* <<<<< END <<<<<<<*', '=* 2 passed in *=', ]) +def test_live_logs_unknown_sections(testdir, request): + """Check that with live logging enable we are printing the correct headers during + start/setup/call/teardown/finish.""" + filename = request.node.name + '.py' + testdir.makeconftest(''' + import pytest + import logging + + def pytest_runtest_protocol(item, nextitem): + logging.warning('Unknown Section!') + + def pytest_runtest_logstart(): + logging.warning('>>>>> START >>>>>') + + def pytest_runtest_logfinish(): + logging.warning('<<<<< END <<<<<<<') + ''') + + 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") + + ''') + testdir.makeini(''' + [pytest] + log_cli=true + ''') + + result = testdir.runpytest() + result.stdout.fnmatch_lines([ + '*WARNING*Unknown Section*', + '{}::test_log_1 '.format(filename), + '*-- live log start --*', + '*WARNING* >>>>> START >>>>>*', + '*-- live log setup --*', + '*WARNING*log message from setup of test_log_1*', + '*-- live log call --*', + '*WARNING*log message from test_log_1*', + 'PASSED *100%*', + '*-- live log teardown --*', + '*WARNING*log message from teardown of test_log_1*', + '*-- live log finish --*', + '*WARNING* <<<<< END <<<<<<<*', + '=* 1 passed in *=', + ]) + + def test_log_cli_level(testdir): # Default log file level testdir.makepyfile('''