Merge pull request #3194 from s0undt3ch/feature/logstart-logfinish

Fix issue where a new line was always written for the live log finish section

_pytest/logging.py

@@ -480,6 +480,7 @@ class _LiveLoggingStreamHandler(logging.StreamHandler):
         self.capture_manager = capture_manager
         self.reset()
         self.set_when(None)
+        self._test_outcome_written = False
 
     def reset(self):
         """Reset the handler; should be called before the start of each test"""
@@ -489,14 +490,20 @@ class _LiveLoggingStreamHandler(logging.StreamHandler):
         """Prepares for the given test phase (setup/call/teardown)"""
         self._when = when
         self._section_name_shown = False
+        if when == 'start':
+            self._test_outcome_written = False
 
     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 in ('teardown', 'finish'):
+            if not self._first_record_emitted:
                 self.stream.write('\n')
                 self._first_record_emitted = True
+            elif self._when in ('teardown', 'finish'):
+                if not self._test_outcome_written:
+                    self._test_outcome_written = True
+                    self.stream.write('\n')
             if not self._section_name_shown:
                 self.stream.section('live log ' + self._when, sep='-', bold=True)
                 self._section_name_shown = True

testing/logging/test_reporting.py

@@ -1,4 +1,5 @@
 # -*- coding: utf-8 -*-
+import re
 import os
 
 import six
@@ -293,6 +294,64 @@ def test_log_cli_default_level_sections(testdir, request):
     ])
 
 
+def test_sections_single_new_line_after_test_outcome(testdir, request):
+    """Check that only a single new line is written between log messages during
+    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 <<<<<<<')
+            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))
+            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([
+        '{}::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 <<<<<<<*',
+        '*WARNING* <<<<< END <<<<<<<*',
+        '=* 1 passed in *=',
+    ])
+    assert re.search(r'(.+)live log teardown(.+)\n(.+)WARNING(.+)\n(.+)WARNING(.+)',
+                     result.stdout.str(), re.MULTILINE) is not None
+    assert re.search(r'(.+)live log finish(.+)\n(.+)WARNING(.+)\n(.+)WARNING(.+)',
+                     result.stdout.str(), re.MULTILINE) is not None
+
+
 def test_log_cli_level(testdir):
     # Default log file level
     testdir.makepyfile('''