opentelemetry-sdk: deprecate logging handler (open-telemetry#4919)

* opentelemetry-sdk: depcreate logging handler

Move config handling to opentelemetry-instrumentation and the handler to
opentelemetry-instrumentation-logging

* Drop handling of env var

* Fix typo

* Reinstate the old code

* opentelemetry-sdk: stop leaking handler in loggers

While at it also fix the noopprovider test case that was working because
we were asserting against another handler.

* Don't use warnings.deprecated - too new

* Update import in examples

* Cleanup deprecation messages and test for them

* Add changelog

* Don't leak state in logging module

* Add a warning that OTEL_PYTHON_LOGGING_AUTO_INSTRUMENTATION_ENABLED is deprecated

Author: xrmx

CHANGELOG.md

@@ -12,6 +12,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 ## Unreleased
 
+- `opentelemetry-sdk`: deprecate `LoggingHandler` in favor of `opentelemetry-instrumentation-logging`, see `opentelemetry-instrumentation-logging` documentation
+  ([#4919](https://github.com/open-telemetry/opentelemetry-python/pull/4919))
 - `opentelemetry-sdk`: Clarify log processor error handling expectations in documentation
   ([#4915](https://github.com/open-telemetry/opentelemetry-python/pull/4915))
 - bump semantic-conventions to v1.40.0

docs/examples/logs/example.py

@@ -5,7 +5,10 @@
 from opentelemetry.exporter.otlp.proto.grpc._log_exporter import (
     OTLPLogExporter,
 )
-from opentelemetry.sdk._logs import LoggerProvider, LoggingHandler
+
+# this is available in the opentelemetry-instrumentation-logging package
+from opentelemetry.instrumentation.logging.handler import LoggingHandler
+from opentelemetry.sdk._logs import LoggerProvider
 from opentelemetry.sdk._logs.export import BatchLogRecordProcessor
 from opentelemetry.sdk.resources import Resource
 from opentelemetry.sdk.trace import TracerProvider

opentelemetry-sdk/src/opentelemetry/sdk/_configuration/__init__.py

@@ -326,6 +326,13 @@ def _init_logging(
         set_event_logger_provider(event_logger_provider)
 
     if setup_logging_handler:
+        warnings.warn(
+            "The `OTEL_PYTHON_LOGGING_AUTO_INSTRUMENTATION_ENABLED` environment variable "
+            "and the `LoggingHandler` in `opentelemetry-sdk` that it controls are deprecated."
+            "Install `opentelemetry-instrumentation-logging` package instead.",
+            DeprecationWarning,
+        )
+
         # Add OTel handler
         handler = LoggingHandler(
             level=logging.NOTSET, logger_provider=provider

opentelemetry-sdk/src/opentelemetry/sdk/_logs/_internal/__init__.py

@@ -528,6 +528,12 @@ def __init__(
         super().__init__(level=level)
         self._logger_provider = logger_provider or get_logger_provider()
 
+        warnings.warn(
+            "`LoggingHandler` in `opentelemetry-sdk` is deprecated. Use the "
+            "handler from `opentelemetry-instrumentation-logging` instead.",
+            DeprecationWarning,
+        )
+
     @staticmethod
     def _get_attributes(record: logging.LogRecord) -> _ExtendedAttributes:
         attributes = {

opentelemetry-sdk/src/opentelemetry/sdk/environment_variables/__init__.py

@@ -714,6 +714,10 @@ def channel_credential_provider() -> grpc.ChannelCredentials:
 Default: False
 
 Note: Logs SDK and its related settings are experimental.
+
+.. warning::
+
+    This option is deprecated, instead you should install `opentelemetry-instrumentation-logging`.
 """
 
 

opentelemetry-sdk/tests/logs/test_handler.py

@@ -38,8 +38,15 @@
 
 # pylint: disable=too-many-public-methods
 class TestLoggingHandler(unittest.TestCase):
+    def test_warns_when_used(self):
+        with self.assertWarnsRegex(
+            DeprecationWarning,
+            "`LoggingHandler` in `opentelemetry-sdk` is deprecated",
+        ):
+            LoggingHandler()
+
     def test_handler_default_log_level(self):
-        processor, logger = set_up_test_logging(logging.NOTSET)
+        processor, logger, handler = set_up_test_logging(logging.NOTSET)
 
         # Make sure debug messages are ignored by default
         logger.debug("Debug message")
@@ -50,8 +57,10 @@ def test_handler_default_log_level(self):
             logger.warning("Warning message")
         self.assertEqual(processor.emit_count(), 1)
 
+        logger.removeHandler(handler)
+
     def test_handler_custom_log_level(self):
-        processor, logger = set_up_test_logging(logging.ERROR)
+        processor, logger, handler = set_up_test_logging(logging.ERROR)
 
         with self.assertLogs(level=logging.WARNING):
             logger.warning("Warning message test custom log level")
@@ -64,6 +73,8 @@ def test_handler_custom_log_level(self):
             logger.critical("No Time For Caution")
         self.assertEqual(processor.emit_count(), 2)
 
+        logger.removeHandler(handler)
+
     # pylint: disable=protected-access
     def test_log_record_emit_noop(self):
         noop_logger_provder = NoOpLoggerProvider()
@@ -78,9 +89,10 @@ def test_log_record_emit_noop(self):
         with self.assertLogs(level=logging.WARNING):
             logger.warning("Warning message")
 
+        logger.removeHandler(handler_mock)
+
     def test_log_flush_noop(self):
         no_op_logger_provider = NoOpLoggerProvider()
-        no_op_logger_provider.force_flush = Mock()
 
         logger = logging.getLogger("foo")
         handler = LoggingHandler(
@@ -91,11 +103,19 @@ def test_log_flush_noop(self):
         with self.assertLogs(level=logging.WARNING):
             logger.warning("Warning message")
 
-        logger.handlers[0].flush()
-        no_op_logger_provider.force_flush.assert_not_called()
+        # the LoggingHandler flush method will call the force_flush method of LoggerProvider in
+        # a separate thread if present. NoOpLoggerProvider is not supposed to have that
+        with patch(
+            "opentelemetry.sdk._logs._internal.threading"
+        ) as threading_mock:
+            logger.handlers[0].flush()
+
+        threading_mock.Thread.assert_not_called()
+
+        logger.removeHandler(handler)
 
     def test_log_record_no_span_context(self):
-        processor, logger = set_up_test_logging(logging.WARNING)
+        processor, logger, handler = set_up_test_logging(logging.WARNING)
 
         # Assert emit gets called for warning message
         with self.assertLogs(level=logging.WARNING):
@@ -115,18 +135,22 @@ def test_log_record_no_span_context(self):
             INVALID_SPAN_CONTEXT.trace_flags,
         )
 
+        logger.removeHandler(handler)
+
     def test_log_record_observed_timestamp(self):
-        processor, logger = set_up_test_logging(logging.WARNING)
+        processor, logger, handler = set_up_test_logging(logging.WARNING)
 
         with self.assertLogs(level=logging.WARNING):
             logger.warning("Warning message")
 
         record = processor.get_log_record(0)
         self.assertIsNotNone(record.log_record.observed_timestamp)
 
+        logger.removeHandler(handler)
+
     def test_log_record_user_attributes(self):
         """Attributes can be injected into logs by adding them to the ReadWriteLogRecord"""
-        processor, logger = set_up_test_logging(logging.WARNING)
+        processor, logger, handler = set_up_test_logging(logging.WARNING)
 
         # Assert emit gets called for warning message
         with self.assertLogs(level=logging.WARNING):
@@ -155,9 +179,11 @@ def test_log_record_user_attributes(self):
             isinstance(record.log_record.attributes, BoundedAttributes)
         )
 
+        logger.removeHandler(handler)
+
     def test_log_record_exception(self):
         """Exception information will be included in attributes"""
-        processor, logger = set_up_test_logging(logging.ERROR)
+        processor, logger, handler = set_up_test_logging(logging.ERROR)
 
         try:
             raise ZeroDivisionError("division by zero")
@@ -189,9 +215,11 @@ def test_log_record_exception(self):
         self.assertTrue("division by zero" in stack_trace)
         self.assertTrue(__file__ in stack_trace)
 
+        logger.removeHandler(handler)
+
     def test_log_record_recursive_exception(self):
         """Exception information will be included in attributes even though it is recursive"""
-        processor, logger = set_up_test_logging(logging.ERROR)
+        processor, logger, handler = set_up_test_logging(logging.ERROR)
 
         try:
             raise ZeroDivisionError(
@@ -224,9 +252,11 @@ def test_log_record_recursive_exception(self):
         self.assertTrue("division by zero" in stack_trace)
         self.assertTrue(__file__ in stack_trace)
 
+        logger.removeHandler(handler)
+
     def test_log_exc_info_false(self):
         """Exception information will not be included in attributes"""
-        processor, logger = set_up_test_logging(logging.NOTSET)
+        processor, logger, handler = set_up_test_logging(logging.NOTSET)
 
         try:
             raise ZeroDivisionError("division by zero")
@@ -251,8 +281,10 @@ def test_log_exc_info_false(self):
             record.log_record.attributes,
         )
 
+        logger.removeHandler(handler)
+
     def test_log_record_exception_with_object_payload(self):
-        processor, logger = set_up_test_logging(logging.ERROR)
+        processor, logger, handler = set_up_test_logging(logging.ERROR)
 
         class CustomException(Exception):
             def __str__(self):
@@ -287,8 +319,10 @@ def __str__(self):
         self.assertTrue("CustomException" in stack_trace)
         self.assertTrue(__file__ in stack_trace)
 
+        logger.removeHandler(handler)
+
     def test_log_record_trace_correlation(self):
-        processor, logger = set_up_test_logging(logging.WARNING)
+        processor, logger, handler = set_up_test_logging(logging.WARNING)
 
         tracer = trace.TracerProvider().get_tracer(__name__)
         with tracer.start_as_current_span("test") as span:
@@ -325,8 +359,10 @@ def test_log_record_trace_correlation(self):
                     span_context.trace_flags,
                 )
 
+        logger.removeHandler(handler)
+
     def test_log_record_trace_correlation_deprecated(self):
-        processor, logger = set_up_test_logging(logging.WARNING)
+        processor, logger, handler = set_up_test_logging(logging.WARNING)
 
         tracer = trace.TracerProvider().get_tracer(__name__)
         with tracer.start_as_current_span("test") as span:
@@ -349,22 +385,28 @@ def test_log_record_trace_correlation_deprecated(self):
                 record.log_record.trace_flags, span_context.trace_flags
             )
 
+        logger.removeHandler(handler)
+
     def test_warning_without_formatter(self):
-        processor, logger = set_up_test_logging(logging.WARNING)
+        processor, logger, handler = set_up_test_logging(logging.WARNING)
         logger.warning("Test message")
 
         record = processor.get_log_record(0)
         self.assertEqual(record.log_record.body, "Test message")
 
+        logger.removeHandler(handler)
+
     def test_exception_without_formatter(self):
-        processor, logger = set_up_test_logging(logging.WARNING)
+        processor, logger, handler = set_up_test_logging(logging.WARNING)
         logger.exception("Test exception")
 
         record = processor.get_log_record(0)
         self.assertEqual(record.log_record.body, "Test exception")
 
+        logger.removeHandler(handler)
+
     def test_warning_with_formatter(self):
-        processor, logger = set_up_test_logging(
+        processor, logger, handler = set_up_test_logging(
             logging.WARNING,
             formatter=logging.Formatter(
                 "%(name)s - %(levelname)s - %(message)s"
@@ -377,8 +419,10 @@ def test_warning_with_formatter(self):
             record.log_record.body, "foo - WARNING - Test message"
         )
 
+        logger.removeHandler(handler)
+
     def test_log_body_is_always_string_with_formatter(self):
-        processor, logger = set_up_test_logging(
+        processor, logger, handler = set_up_test_logging(
             logging.WARNING,
             formatter=logging.Formatter(
                 "%(name)s - %(levelname)s - %(message)s"
@@ -389,17 +433,21 @@ def test_log_body_is_always_string_with_formatter(self):
         record = processor.get_log_record(0)
         self.assertIsInstance(record.log_record.body, str)
 
+        logger.removeHandler(handler)
+
     @patch.dict(os.environ, {"OTEL_SDK_DISABLED": "true"})
     def test_handler_root_logger_with_disabled_sdk_does_not_go_into_recursion_error(
         self,
     ):
-        processor, logger = set_up_test_logging(
+        processor, logger, handler = set_up_test_logging(
             logging.NOTSET, root_logger=True
         )
         logger.warning("hello")
 
         self.assertEqual(processor.emit_count(), 0)
 
+        logger.removeHandler(handler)
+
     @patch.dict(os.environ, {OTEL_ATTRIBUTE_COUNT_LIMIT: "3"})
     def test_otel_attribute_count_limit_respected_in_logging_handler(self):
         """Test that OTEL_ATTRIBUTE_COUNT_LIMIT is properly respected by LoggingHandler."""
@@ -439,6 +487,8 @@ def test_otel_attribute_count_limit_respected_in_logging_handler(self):
             f"Should have 10 dropped attributes, got {record.dropped_attributes}",
         )
 
+        logger.removeHandler(handler)
+
     @patch.dict(os.environ, {OTEL_ATTRIBUTE_COUNT_LIMIT: "5"})
     def test_otel_attribute_count_limit_includes_code_attributes(self):
         """Test that OTEL_ATTRIBUTE_COUNT_LIMIT applies to all attributes including code attributes."""
@@ -476,9 +526,11 @@ def test_otel_attribute_count_limit_includes_code_attributes(self):
             f"Should have 6 dropped attributes, got {record.dropped_attributes}",
         )
 
+        logger.removeHandler(handler)
+
     def test_logging_handler_without_env_var_uses_default_limit(self):
         """Test that without OTEL_ATTRIBUTE_COUNT_LIMIT, default limit (128) should apply."""
-        processor, logger = set_up_test_logging(logging.WARNING)
+        processor, logger, handler = set_up_test_logging(logging.WARNING)
 
         # Create a log record with many attributes (more than default limit of 128)
         extra_attrs = {f"attr_{i}": f"value_{i}" for i in range(150)}
@@ -505,6 +557,8 @@ def test_logging_handler_without_env_var_uses_default_limit(self):
             f"Should have 25 dropped attributes, got {record.dropped_attributes}",
         )
 
+        logger.removeHandler(handler)
+
 
 def set_up_test_logging(level, formatter=None, root_logger=False):
     logger_provider = LoggerProvider()
@@ -515,7 +569,7 @@ def set_up_test_logging(level, formatter=None, root_logger=False):
     if formatter:
         handler.setFormatter(formatter)
     logger.addHandler(handler)
-    return processor, logger
+    return processor, logger, handler
 
 
 class FakeProcessor(LogRecordProcessor):

opentelemetry-sdk/tests/test_configurator.py

@@ -843,6 +843,19 @@ def test_logging_init_exporter_without_handler_setup(self):
         getLogger(__name__).error("hello")
         self.assertFalse(provider.processors[0].exporter.export_called)
 
+    def test_logging_init_with_setup_logging_handler_to_true_warns(self):
+        resource = Resource.create({})
+        with self.assertWarnsRegex(
+            DeprecationWarning,
+            "and the `LoggingHandler` in `opentelemetry-sdk` that it controls are deprecated",
+        ):
+            with ResetGlobalLoggingState():
+                _init_logging(
+                    {"otlp": DummyOTLPLogExporter},
+                    resource=resource,
+                    setup_logging_handler=True,
+                )
+
     @patch.dict(
         environ,
         {"OTEL_RESOURCE_ATTRIBUTES": "service.name=otlp-service"},