fix(ci_visibility): do not propagate ddtrace logs to the root logger

ddtrace/contrib/internal/pytest/_plugin_v2.py

@@ -237,11 +237,12 @@ def _pytest_load_initial_conftests_pre_yield(early_config, parser, args):
     ModuleCodeCollector has a tangible impact on the time it takes to load modules, so it should only be installed if
     coverage collection is requested by the backend.
     """
+    take_over_logger_stream_handler()
+
     if not _is_enabled_early(early_config, args):
         return
 
     try:
-        take_over_logger_stream_handler()
         dd_config.test_visibility.itr_skipping_level = ITR_SKIPPING_LEVEL.SUITE
         enable_test_visibility(config=dd_config.pytest)
         if InternalTestSession.should_collect_coverage():

ddtrace/internal/ci_visibility/utils.py

@@ -112,11 +112,10 @@ def take_over_logger_stream_handler(remove_ddtrace_stream_handlers=True):
         log.debug("CIVisibility not taking over ddtrace logger because level is set to: %s", level)
         return
 
-    root_logger = logging.getLogger()
+    ddtrace_logger = logging.getLogger("ddtrace")
 
     if remove_ddtrace_stream_handlers:
         log.debug("CIVisibility removing DDTrace logger handler")
-        ddtrace_logger = logging.getLogger("ddtrace")
         for handler in list(ddtrace_logger.handlers):
             ddtrace_logger.removeHandler(handler)
     else:
@@ -136,8 +135,9 @@ def take_over_logger_stream_handler(remove_ddtrace_stream_handlers=True):
         log.warning("Invalid log level: %s", level)
         return
 
-    root_logger.addHandler(ci_visibility_handler)
-    root_logger.setLevel(min(root_logger.level, ci_visibility_handler.level))
+    ddtrace_logger.addHandler(ci_visibility_handler)
+    ddtrace_logger.setLevel(min(ddtrace_logger.level, ci_visibility_handler.level))
+    ddtrace_logger.propagate = False
 
     log.debug("logger setup complete")
 

releasenotes/notes/ci_visibility-fix-pytest-log-capture-b135eb77a4fcd2b9.yaml

@@ -0,0 +1,6 @@
+---
+fixes:
+  - |
+    CI Visibility: This fix resolves an issue where setting custom loggers during a test session could cause the tracer
+    to emit logs to a logging stream handler that was already closed by ``pytest``, leading to ``I/O operation on closed
+    file`` errors at the end of the test session.

tests/conftest.py

@@ -6,6 +6,7 @@
 import importlib
 from itertools import product
 import json
+import logging
 import os
 from os.path import split
 from os.path import splitext
@@ -678,3 +679,20 @@ def test_agent_session(telemetry_writer, request):
     finally:
         os.environ["DD_CIVISIBILITY_AGENTLESS_ENABLED"] = p_agentless
         telemetry_writer.reset_queues()
+
+
+@pytest.fixture()
+def caplog(caplog):
+    """
+    During tests, ddtrace logs are not propagated to the root logger by default (see PR #14121).
+    This breaks caplog tests that capture logs from the ddtrace logger, so we need to re-enable propagation for those.
+    """
+    ddtrace_logger = logging.getLogger("ddtrace")
+
+    try:
+        original_propagate = ddtrace_logger.propagate
+        ddtrace_logger.propagate = True
+        yield caplog
+
+    finally:
+        ddtrace_logger.propagate = original_propagate

tests/contrib/pytest/test_pytest.py

@@ -4187,6 +4187,94 @@ def test_dependency_collection_disabled():
         result = self.subprocess_run("--ddtrace", file_name)
         assert result.ret == 0
 
+    def test_pytest_ddtrace_logger_unaffected_by_log_capture(self):
+        py_file = self.testdir.makepyfile(
+            """
+            import os
+            import sys
+            import logging.config
+
+            def test_log_capture():
+                config = {
+                    "version": 1,
+                    "disable_existing_loggers": False,
+                    "formatters": {
+                        "simple": {
+                            "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s",
+                            "datefmt": "%Y-%m-%d %H:%M:%S"
+                        }
+                    },
+                    "handlers": {
+                        "stdout": {
+                            "class": "logging.StreamHandler",
+                            "level": "DEBUG",
+                            "formatter": "simple",
+                            "stream": "ext://sys.stdout"
+                        }
+                    },
+                    "loggers": {
+                        "root": {
+                            "level": "DEBUG",
+                            "handlers": [
+                                "stdout"
+                            ]
+                        }
+                    }
+                }
+                logging.config.dictConfig(config)
+
+            """
+        )
+        file_name = os.path.basename(py_file.strpath)
+
+        result = self.subprocess_run("--ddtrace", file_name)
+        assert "I/O operation on closed file" not in result.stderr.str()
+        assert result.ret == 0
+
+    def test_pytest_no_ddtrace_logger_unaffected_by_log_capture(self):
+        py_file = self.testdir.makepyfile(
+            """
+            import os
+            import sys
+            import logging.config
+
+            def test_log_capture():
+                config = {
+                    "version": 1,
+                    "disable_existing_loggers": False,
+                    "formatters": {
+                        "simple": {
+                            "format": "%(asctime)s - %(name)s - %(levelname)s - %(message)s",
+                            "datefmt": "%Y-%m-%d %H:%M:%S"
+                        }
+                    },
+                    "handlers": {
+                        "stdout": {
+                            "class": "logging.StreamHandler",
+                            "level": "DEBUG",
+                            "formatter": "simple",
+                            "stream": "ext://sys.stdout"
+                        }
+                    },
+                    "loggers": {
+                        "root": {
+                            "level": "DEBUG",
+                            "handlers": [
+                                "stdout"
+                            ]
+                        }
+                    }
+                }
+                logging.config.dictConfig(config)
+
+            """
+        )
+        file_name = os.path.basename(py_file.strpath)
+
+        result = self.subprocess_run(file_name)
+        assert "I/O operation on closed file" not in result.stderr.str()
+        assert result.ret == 0
+
 
 def test_pytest_coverage_data_format_handling_none_value():
     """Test that coverage data format issues are handled correctly with proper logging for None value."""