google / google/adk-python

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

Open
#6,559 4 comments 0 reactions 2 assignees Claimed by @rohityan View on GitHub
needs review tracing
Dominant language
Python
Stars
21.5k
Forks
4k
Avg merge
1d 14h
Merged PRs (30d)
37

Description

## 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: 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:

```python
# 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: 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`:

```python
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.

```diff
--- 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:

```python
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)

- #1170 (secondary "Failed to detach context" note during `GeneratorExit`)
- #1028, #949, #860, #501 (context-token detach in Loop/Parallel/AgentTool paths)

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

Contributor guide

Open the contributing guide

Assessment

This issue has not been assessed yet.

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.