Add support for logging in collection-phase

The logging plugin does not output log messages generated during the
collection-phase when live-logging is enabled. This fixes this.

Fixes pytest-dev#3964

changelog/3964.rst

@@ -0,0 +1,2 @@
+Log messages generated in the collection phase are now shown when
+live-logging is enabled.

src/_pytest/logging.py

@@ -414,7 +414,6 @@ def __init__(self, config):
         else:
             self.log_file_handler = None
 
-        # initialized during pytest_runtestloop
         self.log_cli_handler = None
 
     def _log_cli_enabled(self):
@@ -425,6 +424,22 @@ def _log_cli_enabled(self):
             "--log-cli-level"
         ) is not None or self._config.getini("log_cli")
 
+    @pytest.hookimpl(hookwrapper=True)
+    def pytest_collection(self):
+        # needs to be called as early as possible
+        self._setup_cli_logging()
+
+        # TODO write to file support needed?
+        with self.live_logs_context():
+            with catching_logs(
+                    LogCaptureHandler(),
+                    formatter=self.formatter,
+                    level=self.log_level):
+                if self.log_cli_handler:
+                    self.log_cli_handler.set_when('collection')
+
+                yield
+
     @contextmanager
     def _runtest_for(self, item, when):
         """Implements the internals of pytest_runtest_xxx() hook."""
@@ -484,8 +499,7 @@ def pytest_runtest_logfinish(self):
     @pytest.hookimpl(hookwrapper=True)
     def pytest_runtestloop(self, session):
         """Runs all collected test items."""
-        self._setup_cli_logging()
-        with self.live_logs_context:
+        with self.live_logs_context():
             if self.log_file_handler is not None:
                 with closing(self.log_file_handler):
                     with catching_logs(
@@ -529,11 +543,14 @@ def _setup_cli_logging(self):
                 self._config, "log_cli_level", "log_level"
             )
             self.log_cli_handler = log_cli_handler
-            self.live_logs_context = catching_logs(
+            self.live_logs_context = lambda: catching_logs(
                 log_cli_handler, formatter=log_cli_formatter, level=log_cli_level
             )
         else:
-            self.live_logs_context = dummy_context_manager()
+            self.live_logs_context = lambda: dummy_context_manager()
+        # Note that the lambda for the live_logs_context is needed because
+        # live_logs_context can otherwise not be entered multiple times due
+        # to limitations of contextlib.contextmanager
 
 
 class _LiveLoggingStreamHandler(logging.StreamHandler):

testing/logging/test_reporting.py

@@ -908,3 +908,21 @@ def section(self, *args, **kwargs):
     else:
         assert MockCaptureManager.calls == []
     assert out_file.getvalue() == "\nsome message\n"
+
+
+def test_collection_live_logging(testdir):
+    testdir.makepyfile(
+        """
+        import logging
+
+        logging.getLogger().info("Normal message")
+    """
+    )
+
+    result = testdir.runpytest("--log-cli-level=INFO")
+    result.stdout.fnmatch_lines([
+        "collecting*",
+        "*--- live log collection ---*",
+        "*Normal message*",
+        "collected 0 items"]
+    )