fix(logging): apply format/level when logging preconfigured

CHANGELOG.md

@@ -59,6 +59,9 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
   ([#4139](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/4139))
 
 ### Fixed
+
+- `opentelemetry-instrumentation-logging`: Apply log format/level when logging already configured (autoinstrumentation, Gunicorn, Flask)
+  ([#4204](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/4204))
 - `opentelemetry-instrumentation-mysql`: Refactor MySQL integration test mocks to use concrete DBAPI connection attributes, reducing noisy attribute type warnings.
   ([#4116](https://github.com/open-telemetry/opentelemetry-python-contrib/pull/4116))
 - `opentelemetry-instrumentation-cassandra`: Use `_instruments_any` instead of `_instruments` for driver dependencies so that having either `cassandra-driver` or `scylla-driver` installed is sufficient

instrumentation/opentelemetry-instrumentation-logging/src/opentelemetry/instrumentation/logging/__init__.py

@@ -87,6 +87,24 @@
 }
 
 
+def _apply_log_settings(log_format, log_level):
+    """Apply format/level to logging, handling pre-configured scenarios.
+
+    If root logger has handlers, update formatters on all handlers.
+    If no handlers, call basicConfig.
+    """
+    root_logger = logging.getLogger()
+
+    if root_logger.hasHandlers():
+        # Logging already configured - update existing handlers
+        for handler in root_logger.handlers:
+            handler.setFormatter(logging.Formatter(log_format))
+        root_logger.setLevel(log_level)
+    else:
+        # No handlers - use basicConfig (backward compatible)
+        logging.basicConfig(format=log_format, level=log_level)
+
+
 class LoggingInstrumentor(BaseInstrumentor):  # pylint: disable=empty-docstring
     __doc__ = f"""An instrumentor for stdlib logging module.
 
@@ -120,6 +138,8 @@ def log_hook(span: Span, record: LogRecord):
 
     _old_factory = None
     _log_hook = None
+    _old_handler_formatters = None
+    _old_level = None
 
     def instrumentation_dependencies(self) -> Collection[str]:
         return _instruments
@@ -149,7 +169,17 @@ def _instrument(self, **kwargs):
             )
             log_level = log_level or logging.INFO
 
-            logging.basicConfig(format=log_format, level=log_level)
+            root_logger = logging.getLogger()
+
+            # Save old state if logging already configured
+            if root_logger.hasHandlers():
+                LoggingInstrumentor._old_handler_formatters = [
+                    (handler, handler.formatter)
+                    for handler in root_logger.handlers
+                ]
+                LoggingInstrumentor._old_level = root_logger.level
+
+            _apply_log_settings(log_format, log_level)
 
         def record_factory(*args, **kwargs):
             record = old_factory(*args, **kwargs)
@@ -203,3 +233,16 @@ def _uninstrument(self, **kwargs):
         if LoggingInstrumentor._old_factory:
             logging.setLogRecordFactory(LoggingInstrumentor._old_factory)
             LoggingInstrumentor._old_factory = None
+
+        # Restore formatters and level
+        if LoggingInstrumentor._old_handler_formatters is not None:
+            for (
+                handler,
+                old_formatter,
+            ) in LoggingInstrumentor._old_handler_formatters:
+                handler.setFormatter(old_formatter)
+            LoggingInstrumentor._old_handler_formatters = None
+
+        if LoggingInstrumentor._old_level is not None:
+            logging.getLogger().setLevel(LoggingInstrumentor._old_level)
+            LoggingInstrumentor._old_level = None

instrumentation/opentelemetry-instrumentation-logging/tests/test_logging.py

@@ -145,8 +145,13 @@ def test_basic_config_called(self, basic_config_mock):
         self.assertFalse(basic_config_mock.called)
         LoggingInstrumentor().uninstrument()
 
-        with mock.patch.dict(
-            "os.environ", {"OTEL_PYTHON_LOG_CORRELATION": "true"}
+        with (
+            mock.patch.object(
+                logging.getLogger(), "hasHandlers", return_value=False
+            ),
+            mock.patch.dict(
+                "os.environ", {"OTEL_PYTHON_LOG_CORRELATION": "true"}
+            ),
         ):
             LoggingInstrumentor().instrument()
             basic_config_mock.assert_called_with(
@@ -160,13 +165,18 @@ def test_custom_format_and_level_env(self, basic_config_mock):
         self.assertFalse(basic_config_mock.called)
         LoggingInstrumentor().uninstrument()
 
-        with mock.patch.dict(
-            "os.environ",
-            {
-                "OTEL_PYTHON_LOG_CORRELATION": "true",
-                "OTEL_PYTHON_LOG_FORMAT": "%(message)s %(otelSpanID)s",
-                "OTEL_PYTHON_LOG_LEVEL": "error",
-            },
+        with (
+            mock.patch.object(
+                logging.getLogger(), "hasHandlers", return_value=False
+            ),
+            mock.patch.dict(
+                "os.environ",
+                {
+                    "OTEL_PYTHON_LOG_CORRELATION": "true",
+                    "OTEL_PYTHON_LOG_FORMAT": "%(message)s %(otelSpanID)s",
+                    "OTEL_PYTHON_LOG_LEVEL": "error",
+                },
+            ),
         ):
             LoggingInstrumentor().instrument()
             basic_config_mock.assert_called_with(
@@ -176,14 +186,19 @@ def test_custom_format_and_level_env(self, basic_config_mock):
     @mock.patch("logging.basicConfig")
     def test_custom_format_and_level_api(self, basic_config_mock):  # pylint: disable=no-self-use
         LoggingInstrumentor().uninstrument()
-        LoggingInstrumentor().instrument(
-            set_logging_format=True,
-            logging_format="%(message)s span_id=%(otelSpanID)s",
-            log_level=logging.WARNING,
-        )
-        basic_config_mock.assert_called_with(
-            format="%(message)s span_id=%(otelSpanID)s", level=logging.WARNING
-        )
+
+        with mock.patch.object(
+            logging.getLogger(), "hasHandlers", return_value=False
+        ):
+            LoggingInstrumentor().instrument(
+                set_logging_format=True,
+                logging_format="%(message)s span_id=%(otelSpanID)s",
+                log_level=logging.WARNING,
+            )
+            basic_config_mock.assert_called_with(
+                format="%(message)s span_id=%(otelSpanID)s",
+                level=logging.WARNING,
+            )
 
     def test_log_hook(self):
         LoggingInstrumentor().uninstrument()
@@ -257,3 +272,150 @@ def test_no_op_tracer_provider(self):
             self.assertEqual(record.otelTraceID, "0")
             self.assertEqual(record.otelServiceName, "")
             self.assertEqual(record.otelTraceSampled, False)
+
+
+class TestLoggingInstrumentorPreConfigured(TestBase):
+    """Tests for pre-configured logging scenarios."""
+
+    @pytest.fixture(autouse=True)
+    def inject_fixtures(self, caplog):
+        self.caplog = caplog  # pylint: disable=attribute-defined-outside-init
+
+    def setUp(self):
+        super().setUp()
+        self.tracer = get_tracer(__name__)
+        # Clear any existing handlers
+        root = logging.getLogger()
+        for handler in root.handlers[:]:
+            root.removeHandler(handler)
+
+    def tearDown(self):
+        super().tearDown()
+        LoggingInstrumentor().uninstrument()
+        # Clear handlers
+        root = logging.getLogger()
+        for handler in root.handlers[:]:
+            root.removeHandler(handler)
+
+    def test_preconfigured_logging(self):
+        """Test instrumentation works when logging is already configured."""
+        # Configure logging before instrumentation
+        logging.basicConfig(format="OLD: %(message)s", level=logging.WARNING)
+
+        # Instrument with set_logging_format=True
+        LoggingInstrumentor().instrument(set_logging_format=True)
+
+        # Verify root logger level updated
+        self.assertEqual(logging.getLogger().level, logging.INFO)
+
+        # Verify formatter updated to include OTel fields
+        handler = logging.getLogger().handlers[0]
+        format_str = handler.formatter._style._fmt
+        self.assertIn("otelTraceID", format_str)
+        self.assertIn("otelSpanID", format_str)
+
+        # Verify trace context injection works
+        # Note: caplog doesn't capture properly when basicConfig is called before it,
+        # so we verify by checking that the formatter includes the required fields
+        # and that log records have the otel attributes injected
+        with self.tracer.start_as_current_span("test") as span:
+            span_ctx = span.get_span_context()
+            logger = logging.getLogger("test logger")
+
+            # Create a test handler to capture log records
+            test_handler = logging.StreamHandler()
+            test_handler.setLevel(logging.INFO)
+            test_records = []
+
+            class RecordCapture(logging.Handler):
+                def emit(self, record):
+                    test_records.append(record)
+
+            capture_handler = RecordCapture()
+            capture_handler.setLevel(logging.INFO)
+            logger.addHandler(capture_handler)
+
+            try:
+                logger.info("test message")
+                self.assertEqual(len(test_records), 1)
+                record = test_records[0]
+                self.assertEqual(
+                    record.otelSpanID, format(span_ctx.span_id, "016x")
+                )
+                self.assertEqual(
+                    record.otelTraceID, format(span_ctx.trace_id, "032x")
+                )
+            finally:
+                logger.removeHandler(capture_handler)
+
+        # Uninstrument and verify restoration
+        LoggingInstrumentor().uninstrument()
+        self.assertEqual(handler.formatter._style._fmt, "OLD: %(message)s")
+        self.assertEqual(logging.getLogger().level, logging.WARNING)
+
+    def test_multiple_handlers(self):
+        """Test that all handlers are updated and restored."""
+        root = logging.getLogger()
+        h1 = logging.StreamHandler()
+        h1.setFormatter(logging.Formatter("H1: %(message)s"))
+        h2 = logging.StreamHandler()
+        h2.setFormatter(logging.Formatter("H2: %(message)s"))
+        root.addHandler(h1)
+        root.addHandler(h2)
+
+        LoggingInstrumentor().instrument(set_logging_format=True)
+
+        # Both handlers updated
+        self.assertIn("otelTraceID", h1.formatter._style._fmt)
+        self.assertIn("otelTraceID", h2.formatter._style._fmt)
+
+        LoggingInstrumentor().uninstrument()
+
+        # Both restored
+        self.assertEqual(h1.formatter._style._fmt, "H1: %(message)s")
+        self.assertEqual(h2.formatter._style._fmt, "H2: %(message)s")
+
+    def test_handler_without_formatter(self):
+        """Test handler with no formatter gets one set."""
+        root = logging.getLogger()
+        handler = logging.StreamHandler()
+        # Don't set formatter
+        root.addHandler(handler)
+
+        self.assertIsNone(handler.formatter)
+
+        LoggingInstrumentor().instrument(set_logging_format=True)
+
+        # Formatter now set
+        self.assertIsNotNone(handler.formatter)
+        self.assertIn("otelTraceID", handler.formatter._style._fmt)
+
+        LoggingInstrumentor().uninstrument()
+
+        # Restored to None
+        self.assertIsNone(handler.formatter)
+
+    def test_instrument_uninstrument_cycle(self):
+        """Test multiple instrument/uninstrument cycles."""
+        logging.basicConfig(
+            format="ORIGINAL: %(message)s", level=logging.ERROR
+        )
+
+        LoggingInstrumentor().instrument(set_logging_format=True)
+        handler = logging.getLogger().handlers[0]
+        self.assertIn("otelTraceID", handler.formatter._style._fmt)
+
+        LoggingInstrumentor().uninstrument()
+        self.assertEqual(
+            handler.formatter._style._fmt, "ORIGINAL: %(message)s"
+        )
+
+        # Re-instrument
+        LoggingInstrumentor().instrument(set_logging_format=True)
+        self.assertIn("otelTraceID", handler.formatter._style._fmt)
+
+        # Re-uninstrument
+        LoggingInstrumentor().uninstrument()
+        self.assertEqual(
+            handler.formatter._style._fmt, "ORIGINAL: %(message)s"
+        )