Add newline before log messages and enable -v output when log_cli is enabled

Author: nicoddemus

_pytest/logging.py

@@ -271,6 +271,13 @@ def __init__(self, config):
         create a single one for the entire test session here.
         """
         self._config = config
+
+        # 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
+            assert self._config.pluginmanager.get_plugin('terminalreporter') is None
+            config.option.verbose = 1
+
         self.print_logs = get_option_ini(config, 'log_print')
         self.formatter = logging.Formatter(
             get_option_ini(config, 'log_format'),
@@ -352,7 +359,7 @@ def _setup_cli_logging(self):
         """
         terminal_reporter = self._config.pluginmanager.get_plugin('terminalreporter')
         if self._config.getini('log_cli') and terminal_reporter is not None:
-            log_cli_handler = logging.StreamHandler(terminal_reporter._tw)
+            log_cli_handler = _LiveLoggingStreamHandler(terminal_reporter._tw)
             log_cli_format = get_option_ini(
                 self._config, 'log_cli_format', 'log_format')
             log_cli_date_format = get_option_ini(
@@ -368,3 +375,18 @@ def _setup_cli_logging(self):
         else:
             self.log_cli_handler = None
             self.live_logs_context = _dummy_context_manager()
+
+
+class _LiveLoggingStreamHandler(logging.StreamHandler):
+    """
+    Custom StreamHandler used by the live logging feature: it will write a newline before the first log message
+    in each test.
+    """
+
+    def emit(self, record):
+        if not getattr(self, '_first_record_emitted', False):
+            self.stream.write('\n')
+            # we might consider adding a header at this point using self.stream.sep('-', 'live log') or something
+            # similar when we improve live logging output
+            self._first_record_emitted = True
+        logging.StreamHandler.emit(self, record)

doc/en/logging.rst

@@ -228,7 +228,8 @@ made in ``3.4`` after community feedback:
 * Log levels are no longer changed unless explicitly requested by the :confval:`log_level` configuration
   or ``--log-level`` command-line options. This allows users to configure logger objects themselves.
 * :ref:`Live Logs <live_logs>` is now disabled by default and can be enabled setting the
-  :confval:`log_cli` configuration option to ``true``.
+  :confval:`log_cli` configuration option to ``true``. When enabled, the verbosity is increased so logging for each
+  test is visible.
 * :ref:`Live Logs <live_logs>` are now sent to ``sys.stdout`` and no longer require the ``-s`` command-line option
   to work.
 

testing/logging/test_reporting.py

@@ -156,7 +156,11 @@ def test_log_cli():
         ''')
     result = testdir.runpytest('-s')
     if enabled:
-        assert msg in result.stdout.str()
+        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()
 
@@ -181,6 +185,7 @@ def test_log_cli(request):
 
     # 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()