diff --git a/_pytest/logging.py b/_pytest/logging.py index 8d6208f1a..5633e4ffc 100644 --- a/_pytest/logging.py +++ b/_pytest/logging.py @@ -271,6 +271,13 @@ class LoggingPlugin(object): 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 @@ class LoggingPlugin(object): """ 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 @@ class LoggingPlugin(object): 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) diff --git a/doc/en/logging.rst b/doc/en/logging.rst index 534ac5687..9fdc6ffe5 100644 --- a/doc/en/logging.rst +++ b/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 ` 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 ` are now sent to ``sys.stdout`` and no longer require the ``-s`` command-line option to work. diff --git a/testing/logging/test_reporting.py b/testing/logging/test_reporting.py index 044088e1e..9bfda325a 100644 --- a/testing/logging/test_reporting.py +++ b/testing/logging/test_reporting.py @@ -156,7 +156,11 @@ def test_log_cli_enabled_disabled(testdir, enabled): ''') 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_default_level(testdir): # 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()