Handle recursive logging from OTEL (#35)

logfire/integrations/logging.py

@@ -2,7 +2,8 @@
 
 from __future__ import annotations
 
-from logging import Handler as LoggingHandler, LogRecord
+import inspect
+from logging import NOTSET, Handler as LoggingHandler, LogRecord, StreamHandler
 from typing import Any, ClassVar, Mapping, cast
 
 from logfire import log
@@ -45,12 +46,31 @@ class LogfireLoggingHandler(LoggingHandler):
 
     custom_scope_suffix: ClassVar[str] = 'stdlib.logging'
 
+    def __init__(self, level: int | str = NOTSET, fallback: LoggingHandler = StreamHandler()) -> None:
+        super().__init__(level=level)
+        self.fallback = fallback
+
     def emit(self, record: LogRecord) -> None:
         """Send the log to Logfire.
 
         Args:
             record: The log record to send.
         """
+        if record.name.startswith('opentelemetry.'):
+            # This method can lead to OTEL calling logging methods which recursively calls this again.
+            # If we detect recursion, use the fallback handler instead.
+            # TODO find a better way to handle this,
+            #  or document the fallback clearly and nudge the user to configure it.
+            frame = inspect.currentframe()
+            assert frame is not None
+            code_here = frame.f_code
+            frame = frame.f_back
+            while frame:
+                if frame.f_code is code_here:
+                    self.fallback.emit(record)
+                    return
+                frame = frame.f_back
+
         attributes = self.fill_attributes(record)
 
         log(

tests/test_stdlib_logging.py

@@ -1,9 +1,17 @@
+from __future__ import annotations
+
+import logging
 from logging import Logger, getLogger
+from typing import Sequence
 
 import pytest
 from dirty_equals import IsJson, IsPositiveInt
 from inline_snapshot import snapshot
+from opentelemetry.sdk.trace import ReadableSpan
+from opentelemetry.sdk.trace.export import SimpleSpanProcessor, SpanExporter
+from opentelemetry.trace import Status
 
+import logfire
 from logfire.integrations.logging import LogfireLoggingHandler
 from logfire.testing import TestExporter
 
@@ -173,3 +181,94 @@ def test_stdlib_logging_warning(exporter: TestExporter, logger: Logger) -> None:
             },
         }
     ]
+
+
+def test_recursive_logging_from_opentelemetry() -> None:
+    class ExceptionExporter(SpanExporter):
+        def export(self, spans: Sequence[ReadableSpan]):
+            raise Exception()
+
+    logfire.configure(
+        send_to_logfire=False,
+        processors=[SimpleSpanProcessor(ExceptionExporter())],
+    )
+
+    class TestLoggingHandler(logging.Handler):
+        def __init__(self):
+            super().__init__()
+            self.logs: list[logging.LogRecord] = []
+            self.emit = self.logs.append  # type: ignore
+
+    # Add our handler to the root logger (not the logger fixture) to get internal logs from OTEL.
+    logger = getLogger()
+    test_logging_handler = TestLoggingHandler()
+    logfire_logging_handler = LogfireLoggingHandler(fallback=test_logging_handler)
+    logger.addHandler(logfire_logging_handler)
+
+    try:
+        # This calls ExceptionExporter.export which causes OTEL to log an exception.
+        # That log call goes to LogfireLoggingHandler.emit, which tries to emit another logfire log,
+        # causing another stdlib log from OTEL, potentially leading to infinite recursion.
+        # This tests that we handle that by using the fallback test_logging_handler when recursion is detected.
+        logfire.info('test')
+    finally:
+        # Don't mess with the root logger longer than needed.
+        logger.removeHandler(logfire_logging_handler)
+
+    [record] = test_logging_handler.logs
+    # This is the message logged by OTEL.
+    assert record.message == 'Exception while exporting Span.'
+
+
+def test_logging_from_opentelemetry(exporter: TestExporter) -> None:
+    # Add our handler to the root logger (not the logger fixture) to get internal logs from OTEL.
+    logger = getLogger()
+    logfire_logging_handler = LogfireLoggingHandler()
+    logger.addHandler(logfire_logging_handler)
+    try:
+        logger.error('test')  # sanity check
+
+        # This causes OTEL to log a warning.
+        # Unlike the test above, there's no risk of recursion since the exporter doesn't raise errors.
+        # So the log appears in the exported spans below.
+        Status(description=4)  # type: ignore
+    finally:
+        # Don't mess with the root logger longer than needed.
+        logger.removeHandler(logfire_logging_handler)
+
+    assert exporter.exported_spans_as_dict() == snapshot(
+        [
+            {
+                'name': 'test',
+                'context': {'trace_id': 1, 'span_id': 1, 'is_remote': False},
+                'parent': None,
+                'start_time': 1000000000,
+                'end_time': 1000000000,
+                'attributes': {
+                    'logfire.span_type': 'log',
+                    'logfire.level_num': 17,
+                    'logfire.msg_template': 'test',
+                    'logfire.msg': 'test',
+                    'code.filepath': 'test_stdlib_logging.py',
+                    'code.function': 'test_logging_from_opentelemetry',
+                    'code.lineno': 123,
+                },
+            },
+            {
+                'name': 'Invalid status description type, expected str',
+                'context': {'trace_id': 2, 'span_id': 2, 'is_remote': False},
+                'parent': None,
+                'start_time': 2000000000,
+                'end_time': 2000000000,
+                'attributes': {
+                    'logfire.span_type': 'log',
+                    'logfire.level_num': 13,
+                    'logfire.msg_template': 'Invalid status description type, expected str',
+                    'logfire.msg': 'Invalid status description type, expected str',
+                    'code.filepath': 'status.py',
+                    'code.function': '__init__',
+                    'code.lineno': 123,
+                },
+            },
+        ]
+    )