Also handle logstart and logfinish hooks

Author: s0undt3ch

_pytest/logging.py

@@ -371,18 +371,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 +404,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,7 +484,7 @@ 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:

testing/logging/test_reporting.py

@@ -226,12 +226,21 @@ 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.makepyfile('''
         import pytest
         import logging
 
+        @pytest.hookimpl(hookwrapper=True)
+        def pytest_runtest_logstart():
+            logging.warning('>>>>> START >>>>>')
+
+        @pytest.hookimpl(hookwrapper=True)
+        def pytest_runtest_logfinish():
+            logging.warning('<<<<< END <<<<<<<')
+
         @pytest.fixture
         def fix(request):
             logging.warning("log message from setup of {}".format(request.node.name))
@@ -252,22 +261,30 @@ def test_log_2(fix):
     result = testdir.runpytest()
     result.stdout.fnmatch_lines([
         '{}::test_log_1 '.format(filename),
+        '*-- live log start --*',
+        '*WARNING*log >>>>> START >>>>> *',
         '*-- 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*',
+        '*-- live log finish --*',
+        '*WARNING*log <<<<< END <<<<<<< *',
 
         '{}::test_log_2 '.format(filename),
+        '*-- live log start --*',
+        '*WARNING*log >>>>> START >>>>> *',
         '*-- 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*',
+        '*-- live log finish --*',
+        '*WARNING*log <<<<< END <<<<<<< *',
         '=* 2 passed in *=',
     ])