Skip to content

Commit 03dd599

Browse files
Detect SDK handler in install_log_bridge (#97)
The install_log_bridge idempotency check only recognized the instrumentation LoggingHandler (the class OA itself installs). Applications that attached opentelemetry.sdk._logs.LoggingHandler against the same LoggerProvider in their own logging setup got a SECOND OTel-Logs handler from OA's bridge, doubling every record through the OTLP export path. Console handlers are independent so the duplication is OTLP-only, which made it slow to diagnose. Widen the check to detect either OTel-Logs handler class wired to the same provider. The correlation_id LogRecord factory still installs regardless. Provider-scoped so applications running a separate logs pipeline against a DIFFERENT LoggerProvider still get OA's bridge attached against the OA provider. Document the collision shape in docs/agent/non-obvious-shapes.md and regenerate the bundled AGENTS.md. Reported via downstream integration.
1 parent 9368940 commit 03dd599

4 files changed

Lines changed: 160 additions & 10 deletions

File tree

docs/agent/non-obvious-shapes.md

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -100,6 +100,17 @@ if summary.timeout_reached:
100100

101101
The compiled graph stays usable for subsequent invocations after a timed-out drain — workers are cancelled cleanly, no partial state leaks.
102102

103+
### `install_log_bridge` skips its own handler when the application already attached one to the same `LoggerProvider`
104+
105+
Two distinct classes both named `LoggingHandler` exist in the OTel Python ecosystem and both bridge stdlib log records to the OTel Logs SDK:
106+
107+
- `opentelemetry.sdk._logs.LoggingHandler` (the SDK class). Typically attached by an application's own logging setup — e.g., a FastAPI `setup_logging(...)` step that wires up an OTLP-backed `LoggerProvider` for log export.
108+
- `opentelemetry.instrumentation.logging.handler.LoggingHandler` (the instrumentation class). What `openarmature.observability.otel.install_log_bridge` attaches when it runs.
109+
110+
Different classes, same OTel-Logs export path. If both are attached against the same `LoggerProvider`, every stdlib log record fires through both handlers, both call `provider.get_logger(...).emit(...)`, and `BatchLogRecordProcessor` ships the record TWICE to the OTLP endpoint. The duplication is OTLP-only — a console handler attached separately is unaffected, which makes "OTLP rows are doubled, console isn't" a head-scratcher to diagnose.
111+
112+
`install_log_bridge` detects either handler class against the same provider and skips its own `addHandler` accordingly; the `openarmature.correlation_id` LogRecord factory still installs. The check is provider-scoped, so an application that intentionally attaches a handler against a DIFFERENT `LoggerProvider` (a separate logs pipeline) still gets the OA bridge against the OA provider — the helper only dedups when the SAME provider would receive duplicate emissions.
113+
103114
### Three exception hierarchies; know which one your code catches
104115

105116
`openarmature` exceptions split across three sibling hierarchies:

src/openarmature/AGENTS.md

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -963,6 +963,17 @@ if summary.timeout_reached:
963963

964964
The compiled graph stays usable for subsequent invocations after a timed-out drain — workers are cancelled cleanly, no partial state leaks.
965965

966+
### `install_log_bridge` skips its own handler when the application already attached one to the same `LoggerProvider`
967+
968+
Two distinct classes both named `LoggingHandler` exist in the OTel Python ecosystem and both bridge stdlib log records to the OTel Logs SDK:
969+
970+
- `opentelemetry.sdk._logs.LoggingHandler` (the SDK class). Typically attached by an application's own logging setup — e.g., a FastAPI `setup_logging(...)` step that wires up an OTLP-backed `LoggerProvider` for log export.
971+
- `opentelemetry.instrumentation.logging.handler.LoggingHandler` (the instrumentation class). What `openarmature.observability.otel.install_log_bridge` attaches when it runs.
972+
973+
Different classes, same OTel-Logs export path. If both are attached against the same `LoggerProvider`, every stdlib log record fires through both handlers, both call `provider.get_logger(...).emit(...)`, and `BatchLogRecordProcessor` ships the record TWICE to the OTLP endpoint. The duplication is OTLP-only — a console handler attached separately is unaffected, which makes "OTLP rows are doubled, console isn't" a head-scratcher to diagnose.
974+
975+
`install_log_bridge` detects either handler class against the same provider and skips its own `addHandler` accordingly; the `openarmature.correlation_id` LogRecord factory still installs. The check is provider-scoped, so an application that intentionally attaches a handler against a DIFFERENT `LoggerProvider` (a separate logs pipeline) still gets the OA bridge against the OA provider — the helper only dedups when the SAME provider would receive duplicate emissions.
976+
966977
### Three exception hierarchies; know which one your code catches
967978

968979
`openarmature` exceptions split across three sibling hierarchies:

src/openarmature/observability/otel/logs.py

Lines changed: 53 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -95,24 +95,36 @@ def install_log_bridge(
9595
logger or handler dispatch, so every record gets the attribute
9696
regardless of which logger originated it.
9797
98-
Idempotent: re-calling is a no-op (we check for the existing
99-
OA-tagged handler on the root logger AND for the OA-installed
100-
factory marker on the current global factory).
98+
Idempotent across both OTel-Logs handler classes. Two different
99+
classes both named ``LoggingHandler`` exist in the OTel Python
100+
ecosystem and both bridge stdlib records to the Logs SDK:
101+
102+
- :class:`opentelemetry.sdk._logs.LoggingHandler` (the SDK class,
103+
what an application's own logging setup typically installs).
104+
- :class:`opentelemetry.instrumentation.logging.handler.LoggingHandler`
105+
(the instrumentation class, what this helper installs).
106+
107+
Different classes, same OTel-Logs export path. If an application
108+
has already attached the SDK class against the same
109+
:class:`LoggerProvider`, calling this helper would attach the
110+
instrumentation class on top and every record would emit to OTLP
111+
twice. The check below detects EITHER class against the same
112+
provider and skips the ``addHandler`` step accordingly; the
113+
correlation_id factory still installs. Re-calling with no prior
114+
OA-installed handler is also a no-op via the OA marker check.
101115
102116
The user retains responsibility for providing the
103117
:class:`LoggerProvider` (typically built with their preferred
104118
exporter; :class:`InMemoryLogRecordExporter` for tests,
105119
:class:`OTLPLogExporter` for production).
106120
"""
107-
from opentelemetry.instrumentation.logging.handler import LoggingHandler
121+
from opentelemetry.instrumentation.logging.handler import (
122+
LoggingHandler as _InstrLoggingHandler,
123+
)
108124

109125
root = logging.getLogger()
110-
# Idempotency #1: don't double-add the OTel LoggingHandler.
111-
handler_already_installed = any(
112-
isinstance(h, LoggingHandler) and getattr(h, "_openarmature_installed", False) for h in root.handlers
113-
)
114-
if not handler_already_installed:
115-
handler = LoggingHandler(level=level, logger_provider=provider)
126+
if not _otel_logs_handler_already_bridges(root, provider):
127+
handler = _InstrLoggingHandler(level=level, logger_provider=provider)
116128
# Direct assignment isn't typed on LoggingHandler; route
117129
# through ``object.__setattr__`` to avoid pyright's strict
118130
# attribute-access check without losing the idempotency-
@@ -123,6 +135,37 @@ def install_log_bridge(
123135
_install_correlation_id_factory()
124136

125137

138+
def _otel_logs_handler_already_bridges(root: logging.Logger, provider: LoggerProvider) -> bool:
139+
"""True iff the root logger already has an OTel-Logs
140+
``LoggingHandler`` (SDK class OR instrumentation class) wired to
141+
``provider`` — meaning every record will already reach the OTLP
142+
export path and a second ``addHandler`` here would duplicate.
143+
144+
Handler-class isinstance covers the case where an application
145+
attached the SDK handler in its own logging setup; the
146+
``_openarmature_installed`` marker covers the case where this
147+
helper was already called previously. ``_logger_provider`` is
148+
OTel-private on both handler classes today — if a future SDK
149+
rename hides it, ``getattr`` returns ``None`` and we conclude
150+
"doesn't bridge", falling back to adding our own handler. Worst
151+
case is the pre-fix behavior (potential dup); we never crash.
152+
"""
153+
from opentelemetry.instrumentation.logging.handler import (
154+
LoggingHandler as _InstrLoggingHandler,
155+
)
156+
from opentelemetry.sdk._logs import LoggingHandler as _SDKLoggingHandler
157+
158+
handler_classes = (_SDKLoggingHandler, _InstrLoggingHandler)
159+
for handler in root.handlers:
160+
if not isinstance(handler, handler_classes):
161+
continue
162+
if getattr(handler, "_openarmature_installed", False):
163+
return True
164+
if getattr(handler, "_logger_provider", None) is provider:
165+
return True
166+
return False
167+
168+
126169
__all__ = [
127170
"install_log_bridge",
128171
]

tests/unit/test_observability_otel.py

Lines changed: 85 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -695,6 +695,91 @@ def test_install_log_bridge_is_idempotent() -> None:
695695
logging.setLogRecordFactory(prior_factory)
696696

697697

698+
def test_install_log_bridge_skips_when_sdk_handler_already_attached() -> None:
699+
"""Downstream report (HyperDX integration): if an application's
700+
own logging setup attached
701+
:class:`opentelemetry.sdk._logs.LoggingHandler` against the same
702+
:class:`LoggerProvider` BEFORE ``install_log_bridge`` runs, the
703+
helper MUST NOT attach a second
704+
:class:`opentelemetry.instrumentation.logging.handler.LoggingHandler`
705+
against the same provider — both classes bridge to the same OTel
706+
Logs SDK and a second attach causes every record to ship to OTLP
707+
twice. The correlation_id factory still installs."""
708+
from opentelemetry.sdk._logs import LoggerProvider
709+
from opentelemetry.sdk._logs import LoggingHandler as _SDKLoggingHandler
710+
711+
root = logging.getLogger()
712+
prior_handlers = list(root.handlers)
713+
prior_factory = logging.getLogRecordFactory()
714+
try:
715+
provider = LoggerProvider()
716+
# Simulate the application's setup: attach the SDK handler
717+
# against `provider` BEFORE OA's bridge runs.
718+
sdk_handler = _SDKLoggingHandler(level=logging.NOTSET, logger_provider=provider)
719+
root.addHandler(sdk_handler)
720+
handler_count_before = len(root.handlers)
721+
722+
install_log_bridge(provider)
723+
724+
# No new handler attached — the SDK handler already bridges
725+
# to `provider`, so installing the instrumentation handler
726+
# would duplicate every emission.
727+
assert len(root.handlers) == handler_count_before, (
728+
f"install_log_bridge MUST NOT add a second OTel-Logs handler when an "
729+
f"SDK handler is already wired to the same provider; "
730+
f"got {len(root.handlers)} handlers (was {handler_count_before})"
731+
)
732+
# The correlation_id factory MUST install regardless — that's
733+
# what the helper is for once handler bridging is already
734+
# taken care of by the application.
735+
current_factory = logging.getLogRecordFactory()
736+
assert getattr(current_factory, "_openarmature_correlation_factory", False), (
737+
"correlation_id factory MUST install even when the OTel-Logs handler "
738+
"is skipped (application already attached one)"
739+
)
740+
finally:
741+
root.handlers[:] = prior_handlers
742+
logging.setLogRecordFactory(prior_factory)
743+
744+
745+
def test_install_log_bridge_adds_handler_when_pre_attached_uses_different_provider() -> None:
746+
"""An application MAY intentionally attach an SDK handler against
747+
a DIFFERENT :class:`LoggerProvider` (e.g., a console-only logs
748+
setup separate from the OA-managed OTLP provider). The
749+
idempotency check is scoped to the SAME provider, so OA's helper
750+
DOES attach its own handler against the OA provider in that
751+
case — no false-positive dedup that would silently break the OA
752+
bridge."""
753+
from opentelemetry.sdk._logs import LoggerProvider
754+
from opentelemetry.sdk._logs import LoggingHandler as _SDKLoggingHandler
755+
756+
root = logging.getLogger()
757+
prior_handlers = list(root.handlers)
758+
prior_factory = logging.getLogRecordFactory()
759+
try:
760+
# Application's pre-attached SDK handler points at a DIFFERENT
761+
# LoggerProvider — its own logs pipeline.
762+
unrelated_provider = LoggerProvider()
763+
unrelated_handler = _SDKLoggingHandler(level=logging.NOTSET, logger_provider=unrelated_provider)
764+
root.addHandler(unrelated_handler)
765+
handler_count_before = len(root.handlers)
766+
767+
# OA's bridge installs against its OWN provider.
768+
oa_provider = LoggerProvider()
769+
install_log_bridge(oa_provider)
770+
771+
# One new handler MUST appear — the OA-installed
772+
# instrumentation handler against `oa_provider`. The
773+
# pre-existing unrelated handler is unaffected.
774+
assert len(root.handlers) == handler_count_before + 1, (
775+
f"install_log_bridge MUST attach when no handler bridges to the "
776+
f"target provider; got {len(root.handlers)} (was {handler_count_before})"
777+
)
778+
finally:
779+
root.handlers[:] = prior_handlers
780+
logging.setLogRecordFactory(prior_factory)
781+
782+
698783
def test_log_bridge_exports_records_with_correlation_id() -> None:
699784
"""Spec §7 end-to-end: a log record emitted on a CHILD logger
700785
under ``current_correlation_id`` flows through the bridge to

0 commit comments

Comments
 (0)