Skip to content

Commit 8f85b89

Browse files
authored
fix(otel): don't log an error when a span ends in another context (#1071)
> 🤖 **This text was AI-generated.** With `BRAINTRUST_OTEL_COMPAT=true`, async frameworks such as LangGraph can start a span in one asyncio task and end it in another. Each task runs in its own `contextvars.Context`, so the token saved when the span became current belongs to a different Context than the one ending it: ``` task A (Context 1) task B (Context 2) on_chain_start on_chain_end span.set_current() span.unset_current() token = attach(ctx) context.detach(token) -> ValueError (other Context) -> OTel logs it at ERROR ``` OpenTelemetry's `context.detach()` catches that `ValueError` itself and logs "Failed to detach context" with a traceback. Nothing reaches Braintrust, so the `except ValueError` guard in the LangChain callback handler never ran. Every such run printed an ERROR, even though span parenting was correct (#1062). The OTel `ContextManager` now resets OTel's default contextvars token directly instead of calling `context.detach()`: ```python try: token.var.reset(token) except ValueError: # token came from another Context; leave both contexts as-is log.debug(...) except Exception: log.exception("Failed to detach context") ``` - A token from another Context is logged at DEBUG. Neither context is changed, so an unrelated span that is active where the run ends stays current. - Other failures, such as reusing a token, are still logged at ERROR and not raised, same as before. - Tokens from other OTel runtime implementations still go through `context.detach()`. The dead `try/except ValueError` around `span.unset_current()` in the LangChain handler is removed, since `unset_current()` never raises. Limitation: the Context where the span started still treats the ended span as current. `BraintrustContextManager` skips ended spans when it looks up the current one; the OTel manager does not yet. Fixes #1062
1 parent 3f5b3d4 commit 8f85b89

4 files changed

Lines changed: 93 additions & 12 deletions

File tree

‎py/noxfile.py‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -929,7 +929,7 @@ def test_otel(session, version):
929929
_install_matrix_dep(session, "opentelemetry-api", version)
930930
_install_matrix_dep(session, "opentelemetry-sdk", version)
931931
_install_matrix_dep(session, "opentelemetry-exporter-otlp-proto-http", version)
932-
_run_tests(session, "braintrust/test_otel.py", version=version)
932+
_run_tests(session, ["braintrust/test_otel.py", "braintrust/otel/"], version=version)
933933

934934

935935
@nox.session()

‎py/src/braintrust/integrations/langchain/callbacks.py‎

Lines changed: 1 addition & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -246,15 +246,7 @@ def _end_span(
246246
dataset_record_id=dataset_record_id,
247247
)
248248

249-
# Async callbacks may unset from a different context; span state is
250-
# tracked in self.spans, so this ValueError is benign.
251-
try:
252-
span.unset_current()
253-
except ValueError as e:
254-
if "was created in a different Context" in str(e):
255-
pass
256-
else:
257-
raise
249+
span.unset_current()
258250

259251
span.end()
260252

‎py/src/braintrust/otel/context.py‎

Lines changed: 22 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
"""Unified context management using OTEL's built-in context."""
22

33
import logging
4+
from contextvars import Token
45
from typing import Any
56

67
from braintrust.context import ParentSpanIds, SpanInfo
@@ -90,8 +91,12 @@ def unset_current_span(self, context_token: Any = None) -> None:
9091
"""Unset the current active span from OTEL context."""
9192

9293
if context_token:
93-
# Detaching the token restores the previous context
94-
context.detach(context_token)
94+
# OTel's default ContextVarsRuntimeContext hands out contextvars tokens.
95+
if isinstance(context_token, Token):
96+
_reset_contextvars_token(context_token)
97+
else:
98+
# Non-contextvars OTel runtimes keep their own detach semantics.
99+
context.detach(context_token)
95100
else:
96101
# No token means we need to explicitly clear the span
97102
# This shouldn't normally happen, but handle it gracefully
@@ -108,6 +113,21 @@ def get_parent_span_ids(self) -> ParentSpanIds | None:
108113
)
109114

110115

116+
def _reset_contextvars_token(token: Token) -> None:
117+
"""Reset like ``context.detach()``, but treat a cross-Context reset as benign.
118+
119+
Async frameworks (e.g. LangGraph) often end a span in a different Context than
120+
it started in; ``context.detach()`` would log that at ERROR.
121+
"""
122+
try:
123+
token.var.reset(token)
124+
except ValueError:
125+
# Only raised for a token from another Context; leave both contexts as-is.
126+
log.debug("Skipping detach of span context token created in a different Context")
127+
except Exception: # pylint: disable=broad-except
128+
log.exception("Failed to detach context")
129+
130+
111131
def _is_otel_span(span: Any) -> bool:
112132
"""Check if the span object is an OTEL span."""
113133
return hasattr(span, "get_span_context")

‎py/src/braintrust/otel/test_otel_bt_integration.py‎

Lines changed: 69 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,8 @@
55
when created in mixed contexts.
66
"""
77

8+
import contextvars
9+
import logging
810
import os
911

1012
import pytest
@@ -387,5 +389,72 @@ def test_bt_span_without_explicit_parent_inherits_from_otel(otel_fixture):
387389
assert bt_child["span_parents"] == [otel_span_id]
388390

389391

392+
def test_unset_current_span_restores_previous_context(otel_fixture):
393+
from opentelemetry import context
394+
395+
logger = init_test_logger(__name__)
396+
with logger.start_span(name="parent") as parent:
397+
child = logger.start_span(name="child")
398+
child.set_current()
399+
assert context.get_value("braintrust_span") is child
400+
401+
child.unset_current()
402+
child.end()
403+
404+
assert context.get_value("braintrust_span") is parent
405+
406+
407+
def test_unset_current_span_from_another_context_does_not_log_error(otel_fixture, caplog):
408+
"""Regression for #1062: LangGraph-style async callbacks start and end a span
409+
in different contextvars Contexts; that must not log an OTel ERROR."""
410+
from opentelemetry import context
411+
412+
logger = init_test_logger(__name__)
413+
owner = contextvars.copy_context()
414+
other = contextvars.copy_context()
415+
416+
span = logger.start_span(name="cross_context")
417+
other_span = logger.start_span(name="other_active")
418+
owner.run(span.set_current)
419+
other.run(other_span.set_current)
420+
421+
with caplog.at_level(logging.DEBUG):
422+
other.run(span.unset_current)
423+
span.end()
424+
other_span.end()
425+
426+
otel_errors = [r for r in caplog.records if r.levelno >= logging.ERROR and r.name.startswith("opentelemetry")]
427+
assert not otel_errors, [r.getMessage() for r in otel_errors]
428+
# The destination context's own active span must be left untouched.
429+
assert other.run(context.get_value, "braintrust_span") is other_span
430+
431+
432+
def test_unset_current_span_reused_token_still_logs_without_raising(otel_fixture, caplog):
433+
from braintrust.otel.context import ContextManager
434+
from opentelemetry import context
435+
436+
otel_context_manager = ContextManager()
437+
token = context.attach(context.set_value("braintrust_span", "child"))
438+
otel_context_manager.unset_current_span(token)
439+
440+
with caplog.at_level(logging.ERROR, logger="braintrust.otel.context"):
441+
otel_context_manager.unset_current_span(token)
442+
443+
assert any(r.getMessage() == "Failed to detach context" for r in caplog.records)
444+
445+
446+
def test_unset_current_span_non_contextvars_token_uses_otel_detach(otel_fixture, monkeypatch):
447+
from braintrust.otel.context import ContextManager
448+
from opentelemetry import context
449+
450+
token = object()
451+
calls = []
452+
monkeypatch.setattr(context, "detach", calls.append)
453+
454+
ContextManager().unset_current_span(token)
455+
456+
assert calls == [token]
457+
458+
390459
if __name__ == "__main__":
391460
pytest.main([__file__, "-v"])

0 commit comments

Comments
 (0)