fix(observability-python): prevent logging recursion with coexisting agents

sdk/@launchdarkly/observability-python/ldobserve/_otel/configuration.py

@@ -29,6 +29,10 @@
 )
 
 from opentelemetry.sdk._logs import LoggerProvider, LoggingHandler
+from ldobserve._otel.logging_handler import (
+    LDLoggingHandler,
+    install_on_root_logger,
+)
 from opentelemetry.sdk.resources import Resource
 from opentelemetry.sdk.trace import TracerProvider
 import opentelemetry._logs as _logs
@@ -132,7 +136,12 @@ def __init__(self, project_id: str, config: _ProcessedConfig):
 
         # The log handler is always created even if logging is not instrumented.
         # This allows directly logging to OpenTelemetry.
-        self._log_handler = LoggingHandler(
+        #
+        # LDLoggingHandler is a hardened LoggingHandler: it is safe to install on
+        # the root logger alongside other logging instrumentation (e.g. the New
+        # Relic agent) because it guards against re-entrancy and never forwards
+        # non-serializable record attributes. See logging_handler.py.
+        self._log_handler = LDLoggingHandler(
             level=self._config.log_level, logger_provider=self._logger_provider
         )
 
@@ -158,7 +167,11 @@ def __init__(self, project_id: str, config: _ProcessedConfig):
             # If log_correlation is false, then the LoggingInstrumentor will not
             # configure basic logging. If it does, then this call has no effect.
             logging.basicConfig(level=self._config.log_level)
-            logging.getLogger().addHandler(self._log_handler)
+            # Registration is idempotent: if the SDK is initialized more than
+            # once in the same process (e.g. a repeated set_config, a test suite,
+            # or a gunicorn preload + worker) this never stacks duplicate handlers
+            # on the root logger, which would double-export every log record.
+            install_on_root_logger(self._log_handler)
 
         metric_reader = PeriodicExportingMetricReader(
             exporter=OTLPMetricExporter(

sdk/@launchdarkly/observability-python/ldobserve/_otel/logging_handler.py

@@ -0,0 +1,97 @@
+"""A hardened OpenTelemetry logging handler.
+
+The SDK attaches a :class:`~opentelemetry.sdk._logs.LoggingHandler` to the root
+logger so that application logs are exported to LaunchDarkly. Because the handler
+lives on the root logger it sees *every* log record in the process, including
+records produced by other logging instrumentation (the New Relic agent, Datadog,
+Sentry, ...) and records produced synchronously by our own export pipeline.
+
+Two failure modes follow from that, both of which this handler defends against:
+
+1. **Foreign record attributes.** Other logging instrumentation stashes
+   arbitrary objects on the :class:`logging.LogRecord` (for example the New Relic
+   agent leaves ``record._nr_original_message``, a function wrapper). When the
+   stock handler forwards those attributes, OpenTelemetry's attribute validation
+   rejects the non-serializable value and emits its own ``WARNING`` log. If
+   another agent re-dispatches that warning back through the root logger, it is
+   re-captured here, producing a new warning, and so on -- an unbounded feedback
+   loop. We drop attribute values that are not valid OpenTelemetry types before
+   they ever reach validation.
+
+2. **Re-entrancy.** Any log emitted *while we are inside* ``emit`` (an attribute
+   warning, an exporter error, a gRPC log) must not be captured again by this
+   handler, or a single application log can recurse. A context-local guard makes
+   re-entrant calls a no-op.
+
+Together these make the handler safe to run alongside any other logging
+instrumentation without disabling log capture.
+"""
+
+import contextvars
+import logging
+import typing
+
+from opentelemetry.sdk._logs import LoggingHandler
+
+# Set while this handler is emitting a record. Any log produced synchronously by
+# the emit/export pipeline re-enters ``emit`` with this flag set and is dropped,
+# which breaks otherwise-unbounded recursion. A module-level ContextVar (rather
+# than per-instance state) also guards the case where more than one LD handler
+# ends up on the root logger.
+_in_emit: contextvars.ContextVar[bool] = contextvars.ContextVar(
+    "ldobserve_in_emit", default=False
+)
+
+# Types OpenTelemetry accepts as attribute values (or sequences thereof).
+_VALID_ATTRIBUTE_TYPES = (bool, bytes, int, float, str)
+
+
+def _is_valid_attribute_value(value: typing.Any) -> bool:
+    if isinstance(value, _VALID_ATTRIBUTE_TYPES):
+        return True
+    if isinstance(value, (list, tuple)):
+        return all(isinstance(item, _VALID_ATTRIBUTE_TYPES) for item in value)
+    return False
+
+
+class LDLoggingHandler(LoggingHandler):
+    """An :class:`~opentelemetry.sdk._logs.LoggingHandler` that is safe to
+    install on the root logger alongside other logging instrumentation."""
+
+    def emit(self, record: logging.LogRecord) -> None:
+        # Re-entrancy guard: drop records produced while we are already emitting.
+        if _in_emit.get():
+            return
+        token = _in_emit.set(True)
+        try:
+            super().emit(record)
+        finally:
+            _in_emit.reset(token)
+
+    def _get_attributes(
+        self, record: logging.LogRecord
+    ) -> typing.Dict[str, typing.Any]:
+        # Never forward foreign / non-serializable record attributes (e.g. the
+        # New Relic agent's ``_nr_original_message`` function wrapper); they would
+        # fail OpenTelemetry's attribute validation and trigger a warning that can
+        # feed back into the root logger.
+        attributes = super()._get_attributes(record)
+        return {
+            key: value
+            for key, value in attributes.items()
+            if _is_valid_attribute_value(value)
+        }
+
+
+def install_on_root_logger(handler: LDLoggingHandler) -> None:
+    """Install ``handler`` on the root logger, idempotently.
+
+    Any previously installed :class:`LDLoggingHandler` is removed first, so that
+    repeated SDK initialization in the same process never stacks duplicate
+    handlers on the root logger (which would double-export every log record).
+    """
+    root_logger = logging.getLogger()
+    for existing in list(root_logger.handlers):
+        if isinstance(existing, LDLoggingHandler):
+            root_logger.removeHandler(existing)
+    root_logger.addHandler(handler)

sdk/@launchdarkly/observability-python/ldobserve/_otel/test_logging_handler.py

@@ -0,0 +1,105 @@
+import logging
+
+import pytest
+from opentelemetry.sdk._logs import LoggerProvider
+from opentelemetry.sdk._logs.export import (
+    InMemoryLogExporter,
+    SimpleLogRecordProcessor,
+)
+
+from ldobserve._otel.logging_handler import (
+    LDLoggingHandler,
+    install_on_root_logger,
+)
+
+
+def _make_handler(provider: LoggerProvider) -> LDLoggingHandler:
+    return LDLoggingHandler(level=logging.NOTSET, logger_provider=provider)
+
+
+def test_get_attributes_drops_non_serializable_values():
+    """Foreign / non-serializable record attributes (e.g. the New Relic agent's
+    ``_nr_original_message`` function wrapper) must not be forwarded -- they fail
+    OpenTelemetry attribute validation and seed a logging feedback loop."""
+    handler = _make_handler(LoggerProvider())
+
+    record = logging.LogRecord(
+        name="app",
+        level=logging.WARNING,
+        pathname=__file__,
+        lineno=1,
+        msg="hello",
+        args=None,
+        exc_info=None,
+    )
+    # mimic the attributes a coexisting logging instrumentation leaves behind
+    record._nr_original_message = lambda: "wrapped"  # function wrapper
+    record.some_object = object()
+    record.ok_str = "value"
+    record.ok_int = 7
+    record.ok_seq = ["a", "b"]
+
+    attributes = handler._get_attributes(record)
+
+    assert "_nr_original_message" not in attributes
+    assert "some_object" not in attributes
+    assert attributes["ok_str"] == "value"
+    assert attributes["ok_int"] == 7
+    assert attributes["ok_seq"] == ["a", "b"]
+
+
+def test_emit_is_not_reentrant():
+    """A log produced synchronously by the export pipeline must not be captured
+    again by the handler, otherwise a single application log recurses."""
+    exporter = InMemoryLogExporter()
+    provider = LoggerProvider()
+    provider.add_log_record_processor(SimpleLogRecordProcessor(exporter))
+    handler = _make_handler(provider)
+
+    export_calls = {"count": 0}
+    original_export = exporter.export
+
+    def logging_export(batch):
+        # Simulate a pipeline component that logs synchronously during export
+        # (the real OTLP exporter does exactly this on connection errors).
+        export_calls["count"] += 1
+        logging.getLogger("pipeline.exporter").warning(
+            "synchronous export log %d", export_calls["count"]
+        )
+        return original_export(batch)
+
+    exporter.export = logging_export
+
+    root = logging.getLogger()
+    install_on_root_logger(handler)
+    old_level = root.level
+    root.setLevel(logging.DEBUG)
+    try:
+        logging.getLogger("app").warning("application log line")
+    finally:
+        root.setLevel(old_level)
+        root.removeHandler(handler)
+
+    # Without the re-entrancy guard the synchronous export log re-enters emit and
+    # recurses unboundedly. With it, only the bounded set of distinct records is
+    # exported. The exact count is small and finite -- never a runaway loop.
+    assert export_calls["count"] <= 3
+    assert exporter.export.__name__ == "logging_export"
+
+
+def test_install_on_root_logger_is_idempotent():
+    """Repeated installation must not stack duplicate LD handlers on the root
+    logger (which would double-export every record)."""
+    root = logging.getLogger()
+    before = [h for h in root.handlers if isinstance(h, LDLoggingHandler)]
+    handlers = [_make_handler(LoggerProvider()) for _ in range(3)]
+    try:
+        for handler in handlers:
+            install_on_root_logger(handler)
+        ld_handlers = [h for h in root.handlers if isinstance(h, LDLoggingHandler)]
+        # exactly one LD handler remains -- the most recently installed one
+        assert len(ld_handlers) == len(before) + 1
+        assert ld_handlers[-1] is handlers[-1]
+    finally:
+        for handler in handlers:
+            root.removeHandler(handler)