Skip to content

"Failed to detach context" (Token created in a different Context) logged as ERROR when caller stops runner.run_async() early #6559

Description

@GanziMan

Description

When a caller stops iterating Runner.run_async() early (a break/return as soon as the final response arrives — a very common pattern), an ERROR-level log is emitted on every invocation:

ERROR opentelemetry.context Failed to detach context
Traceback (most recent call last):
  File ".../opentelemetry/trace/__init__.py", line 589, in use_span
    yield span
  File ".../opentelemetry/trace/__init__.py", line 508, in start_as_current_span
    yield span
  File ".../google/adk/runners.py", line 572, in _run_node_async
    yield event
GeneratorExit

During handling of the above exception, another exception occurred:
  File ".../opentelemetry/context/__init__.py", line 143, in detach
    _RUNTIME_CONTEXT.detach(token)
  File ".../opentelemetry/context/contextvars_context.py", line 42, in detach
    self._current_context.reset(token)
ValueError: <Token ...> was created in a different Context

Functionally the invocation completes correctly (OpenTelemetry swallows the exception inside detach() and only logs it), so this is cosmetic — but it is logged at ERROR level on every early-terminated run, which creates significant log noise and false-positive error-rate alerts (e.g. Datadog).

Environment

  • google-adk: observed in production on 2.3.0; the relevant structure is unchanged through v2.6.1 (verified by source inspection)
  • Python 3.13 (also reproduces on 3.9–3.12)
  • FastAPI + uvicorn (--workers 2), run under ddtrace-run (Datadog APM); logs shipped to Datadog
  • OTEL_SDK_DISABLED=true is set
  • opentelemetry-api / -sdk: current 1.x (its context.detach() wraps the failure in try/except and calls logger.exception("Failed to detach context"))

Note: setting OTEL_SDK_DISABLED=true does not suppress this — that flag disables the SDK (export/sampling), but context.attach()/detach() live in the context API and keep running. Running under ddtrace-run (which proxies the OTel context) makes the cross-context mismatch surface reliably.

Root cause

runners._run_node_async is an async generator whose event-yielding loop is wrapped in an OpenTelemetry current-span context manager:

# runners.py -> telemetry/_instrumentation.record_invocation (schema v1)
with tracer.start_as_current_span("invocation"):
    ...
    async for event in agen:
        yield event

start_as_current_span does attach() on entry (creating a contextvars Token) and detach(token) on exit. In an async generator the attach() happens in the execution context where the generator is resumed to produce a value. When the caller stops early, the generator is not finalized in that same context — it is closed later by GC / loop.shutdown_asyncgens() / a different task, which raises GeneratorExit (or CancelledError) at the yield. The context manager's __exit__ then calls detach(token) in a different context than the one where the token was created, which is exactly the situation contextvars.Token forbids → ValueError: <Token ...> was created in a different Context.

This is the well-known "start_as_current_span around an async generator" anti-pattern; it only manifests on early close, never on full consumption.

Minimal reproduction (no ADK / API key required)

Reproduces the exact OTel interaction with only opentelemetry-sdk:

import asyncio, contextlib, logging
logging.basicConfig(level=logging.ERROR)
from opentelemetry import trace, context as context_api
from opentelemetry.sdk.trace import TracerProvider
trace.set_tracer_provider(TracerProvider())
tracer = trace.get_tracer("adk-repro")

@contextlib.contextmanager
def record_invocation_current():            # current ADK structure
    with tracer.start_as_current_span("invocation"):
        yield

async def event_queue():
    for i in range(10):
        await asyncio.sleep(0)
        yield i

async def run_node():                       # ~ runners._run_node_async
    with record_invocation_current():
        async for ev in event_queue():
            yield ev

async def caller_early_stop():
    async for ev in run_node():
        if ev == 2:
            return                          # early stop -> generator closed later
                                            # in a different context

asyncio.run(caller_early_stop())            # -> ERROR "Failed to detach context"
Scenario Current structure With proposed fix
Caller stops early (break/return) Failed to detach context ERROR ✅ clean
Caller consumes to completion ✅ clean ✅ clean (unchanged)

Proposed fix (minimal — schema v1 invocation span)

Manage the span/context explicitly and only detach() when the generator body completed normally; skip detach() on early close (the token belongs to a different context and the generator's context is discarded anyway). The span is always ended, so trace completeness is preserved.

--- a/src/google/adk/telemetry/_instrumentation.py
+++ b/src/google/adk/telemetry/_instrumentation.py
@@ def record_invocation(...):
     if resolve_schema_version() < SCHEMA_VERSION_SEMCONV_ALIGNED:
-      with tracing.tracer.start_as_current_span("invocation"):
-        yield
-      return
+      # NOTE: this context manager wraps an async generator (runners.
+      # _run_node_async). If the caller stops iterating early, the generator is
+      # finalized (GeneratorExit / CancelledError) in a different execution
+      # context than the one where the span was attached, so an automatic
+      # detach() would raise "Token was created in a different Context" (OTel
+      # swallows it but logs an ERROR). Detach only on normal completion; always
+      # end the span.
+      span = tracing.tracer.start_span("invocation")
+      token = context_api.attach(trace.set_span_in_context(span))
+      completed = False
+      try:
+        yield
+        completed = True
+      finally:
+        if completed:
+          context_api.detach(token)
+        span.end()
+      return

(trace and context_api are already imported in _instrumentation.py.)

The same start_as_current_span-around-async-generator pattern also exists on the schema v2 path (node_tracing._use_invoke_workflow_span) and could get the same treatment, but this issue/PR intentionally scopes to the default (schema v1) invocation span that users hit today.

Workaround (for users, until fixed)

Consume the generator to completion instead of returning early — capture the final response and let the loop end naturally:

final = None
async for event in runner.run_async(...):
    if event.is_final_response():
        final = event          # don't break/return here
# loop ends naturally -> attach/detach occur in the same context, no error

Related (same root cause, different layers)

Happy to send a PR with the fix + a unit test if this direction looks good.

Metadata

Metadata

Assignees

Labels

tracing[Component] This issue is related to OpenTelemetry tracing

Type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions