Fix max recursion bug by removing logging.log calls in emit

Author: DylanRussell

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

@@ -167,15 +167,14 @@ def _export(self, batch_strategy: BatchExportStrategy) -> None:
                     )
                 detach(token)
 
+    # Do not add any logging.log statements to this function, they can be being routed back to this `emit` function,
+    # resulting in endless recursive calls that crash the program.
     def emit(self, data: Telemetry) -> None:
         if self._shutdown:
-            self._logger.info("Shutdown called, ignoring %s.", self._exporting)
             return
         if self._pid != os.getpid():
             self._bsp_reset_once.do_once(self._at_fork_reinit)
-
-        if len(self._queue) == self._max_queue_size:
-            self._logger.warning("Queue full, dropping %s.", self._exporting)
+        # This will drop a log from the right side if the queue is at _max_queue_length.
         self._queue.appendleft(data)
         if len(self._queue) >= self._max_export_batch_size:
             self._worker_awaken.set()

opentelemetry-sdk/tests/shared_internal/test_batch_processor.py

@@ -14,6 +14,7 @@
 
 # pylint: disable=protected-access
 import gc
+import logging
 import multiprocessing
 import os
 import time
@@ -27,13 +28,17 @@
 import pytest
 from pytest import mark
 
+from opentelemetry._logs import set_logger_provider
 from opentelemetry.sdk._logs import (
     LogData,
+    LoggerProvider,
+    LoggingHandler,
     LogRecord,
 )
 from opentelemetry.sdk._logs.export import (
     BatchLogRecordProcessor,
 )
+from opentelemetry.sdk.resources import Resource
 from opentelemetry.sdk.util.instrumentation import InstrumentationScope
 
 EMPTY_LOG = LogData(
@@ -88,7 +93,7 @@ def test_telemetry_exported_once_schedule_delay_reached(
         exporter.export.assert_called_once_with([telemetry])
 
     def test_telemetry_flushed_before_shutdown_and_dropped_after_shutdown(
-        self, batch_processor_class, telemetry, caplog
+        self, batch_processor_class, telemetry
     ):
         exporter = Mock()
         batch_processor = batch_processor_class(
@@ -107,8 +112,6 @@ def test_telemetry_flushed_before_shutdown_and_dropped_after_shutdown(
 
         # This should not be flushed.
         batch_processor.emit(telemetry)
-        assert len(caplog.records) == 1
-        assert "Shutdown called, ignoring" in caplog.text
         exporter.export.assert_called_once()
 
     # pylint: disable=no-self-use
@@ -211,3 +214,29 @@ def test_record_processor_is_garbage_collected(
 
         # Then the reference to the processor should no longer exist
         assert weak_ref() is None
+
+    def test_logging_lib_not_invoked_in_emit(
+        self, batch_processor_class, telemetry
+    ):
+        exporter = Mock()
+        processor = batch_processor_class(exporter)
+        processor._batch_processor.emit(telemetry)
+        logger_provider = LoggerProvider(
+            resource=Resource.create(
+                {
+                    "service.name": "shoppingcart",
+                    "service.instance.id": "instance-12",
+                }
+            ),
+        )
+        set_logger_provider(logger_provider)
+        logger_provider.add_log_record_processor(processor)
+        handler = LoggingHandler(
+            level=logging.INFO, logger_provider=logger_provider
+        )
+        # Attach OTLP handler to root logger
+        logging.getLogger().addHandler(handler)
+        # If `emit` calls logging.log then this test will throw a maximum recursion depth exceeded exception and fail.
+        processor.emit(telemetry)
+        processor.shutdown()
+        processor.emit(telemetry)