fix(otel): balance context attach and detach across plugin lifecycles - #647
fix(otel): balance context attach and detach across plugin lifecycles#647wangyb-A wants to merge 4 commits into
Conversation
This comment has been minimized.
This comment has been minimized.
Both OTel plugins called opentelemetry.context.attach() without keeping the returned token, and "restored" the enclosing span by attaching another context rather than detaching. Every operation pushed two context layers and popped none, leaving an ended span current after its scope had finished. The worst consequence is not in the issue. The invocation-start attach ran on the Lambda handler thread, which is reused across warm invocations, so the next execution's context extractor and GLOBAL-mode ambient-parent lookup adopted the previous execution's ended Workflow span. A valid parent overrides the deterministic ID generator's trace ID, so two unrelated durable executions merged into a single trace. Two runtime properties shaped the fix. The hooks run on several threads -- the invocation hooks on the Lambda handler thread, the user-function hooks on the worker that runs user code, and on a branch worker per map/parallel branch -- and ContextVar.reset() only accepts a token created in the same contextvars.Context. And unlike Java's ScopeImpl.close(), which ignores a close that does not represent the current context, ContextVar.reset() writes back its captured value unconditionally, so detaching out of order revives a stale context instead of failing safe. Changes: - Add context_scope, a thread-confined LIFO stack of attach tokens. Detaches unwind downwards so the ContextVar is always reset in order. The stack is module level so the two plugins, which ship as separate entry points and can be enabled together, still unwind in true LIFO order. An epoch check discards scopes a suspended operation left behind, since the SDK re-raises SuspendExecution without calling on_user_function_end. - Pair every user-function attach with a detach on the same thread, replacing the re-attach that previously stood in for restoring the enclosing context. - Unwind any remaining scopes at invocation end. - Drop the invocation-start attach. User code runs on a separate worker and ThreadPoolExecutor does not copy contextvars, so that attach never reached the code it was meant to parent; it only leaked. The Workflow and Invocation spans are used as explicit parents instead, matching the Java plugins, which never make either span current. Ambient spans emitted outside any operation are no longer parented to the Invocation span; the README documents this, and log correlation is unchanged because the logging filter resolves through the plugin's span registry. Tests no longer reset the OTel context to isolate themselves; an autouse fixture asserts instead that every test leaves the context exactly as it found it. Adds coverage for nested contexts, sequential steps, failures, suspension, worker-thread hooks, both plugins on one thread, and warm invocation reuse keeping two executions in separate traces. Fixes #643
Three review findings, all real: Same-invocation re-entry. The epoch check only caught a previous invocation's leftovers, but the same operation key can be entered twice inside one invocation: a suspended operation is re-entered when its branch is resubmitted, and its first scope is still attached because the suspending path has no end hook. The second enter stacked on the first and the end hook popped one, leaving a stale layer per re-entry. enter_scope now unwinds an existing (owner, key) even when the epoch matches. Extracted context values. Basing every scope on the current context dropped baggage and other non-span values supplied by the context extractor, because the worker running user code starts with an empty context. The outermost scope on a thread is now layered onto the extracted context; nested scopes keep using the current one, which already carries it transitively. Ambient span vs durable span. In GLOBAL mode the ADOT Lambda span stays current on the handler thread, so get_current_span_context returned it instead of the Invocation span, contradicting what the previous commit documented. The current span is now trusted only while this plugin holds a scope on this thread; otherwise the registry answers. The earlier test missed this by using an explicit provider with no ambient span. Adds the tests each finding asked for: same-key re-entry at the helper level and through the plugin hooks on a worker thread, baggage surviving into user code and into a nested scope, and a GLOBAL-mode ambient Lambda span not displacing the Invocation span in log records.
ceb4551 to
c79cfda
Compare
This comment has been minimized.
This comment has been minimized.
Two more review findings, both real. Branch workers have no branch affinity. If branch A suspends without an end hook and its pool worker next runs branch B, A's scope has the same epoch and a different key, so neither the epoch check nor the same-key check cleared it. B nested inside A and, on exit, detached back into it -- later records on that worker correlated to the wrong branch, and one layer accumulated per suspended branch. Replaces the same-key guard with an ancestry check: a scope may stay attached only while the operation it belongs to is still running on this thread, so anything above the new scope's parent is stale, and when the parent is absent -- a root-level operation, or one whose parent ran elsewhere -- nothing held here can enclose it. The plugins pass the enclosing operation as parent_key. The normal nesting path is a no-op, which matters because detaching necessarily discards entries above the cut, including a second plugin's. An empty extracted context was being discarded. Context subclasses dict, so an empty one is falsy and `extracted or current` silently inverted the intent of an extractor that returns an empty context to isolate the operation, inheriting the worker's ambient baggage and suppression values instead. Now tested with `is not None`. Adds the tests both findings asked for: a sibling scope dropped rather than nested into, a nested scope whose parent never ran on this thread, a plugin-level branch-A-suspends-then-branch-B case pinned to one worker, and an empty extracted context isolating the operation from ambient baggage. Two existing helper tests nested without declaring a parent, which now reads as a root operation; they pass parent_key like the plugins do.
This comment has been minimized.
This comment has been minimized.
Reverts the ancestry check from the previous commit and fixes the order in which the attached context is built. Both were review findings; the first one was a regression I introduced. parent_id is checkpoint hierarchy, not the Python call stack. A virtual (FLAT) map/parallel branch deliberately reports its inner operations' parent as the grandparent -- None for a top-level branch -- while the branch's own context scope is still running (see DurableContext.is_virtual and create_child_context, where child_parent_id is the *parent's* parent when is_virtual). Treating such an inner step as root-level therefore detached the live branch scope at the first inner step, and work between two inner steps fell out of the durable trace. That is worse than the abandoned sibling scope the check was meant to catch, so the narrower same-key guard is restored. The gap that leaves -- a scope abandoned by a *different* operation on the same branch-pool worker -- cannot be closed from the hook payloads, because a live FLAT branch scope is indistinguishable from an abandoned sibling. It needs the SDK to report the end of a suspended user function, which is tracked separately; the docstring says so rather than implying the helper handles it. Second finding: the context to attach was built by the caller before enter_scope ran its cleanup, so it copied baggage and suppression values out of the very scope about to be detached, and detaching afterwards could not remove them from an already-built Context. enter_scope now takes a factory and calls it after cleanup. Adds a FLAT-branch test asserting the branch scope stays current across two inner steps that report no parent, and a test that the factory observes the post-cleanup context. Drops the three tests that asserted the reverted rule.
| _discard_stale(owner_id, epoch) | ||
| _discard_reentered(owner_id, key) |
There was a problem hiding this comment.
Codex AI review
[P1] Clean up suspended scopes before branch workers are reused. These guards only remove scopes from an older invocation or the same operation key. A timed-out map/parallel branch skips on_user_function_end, and its pool thread can then resume a different branch in the same invocation. The new scope stacks above the abandoned sibling and detaching it restores that sibling's span, leaking log correlation, baggage, and suppression state across branches. Add a same-thread suspension cleanup hook in the core user-function lifecycle rather than relying on key/epoch heuristics, with an executor-level resubmission test.
| def depth(owner: Any | None = None) -> int: | ||
| """Return the number of scopes attached on this thread (for tests).""" | ||
| if owner is None: | ||
| return len(_state.entries) | ||
| owner_id = id(owner) | ||
| return sum(1 for entry in _state.entries if entry.owner_id == owner_id) |
There was a problem hiding this comment.
Codex AI review
[P2] Do not use thread-local depth as operation-context ownership. Both plugins now use this value to decide whether the current span is durable. When an operation's OTel context is propagated through asyncio.to_thread, copy_context, or an instrumented executor, the child thread has the correct operation span but depth zero, so logs incorrectly fall back to the invocation span and nested scopes discard propagated context. Keep detach tokens thread-local, but add an ownership marker to the attached OTel context or validate the current span against the plugin registry; cover propagated child-thread logging in both plugins.
Codex AI reviewThe normal lifecycle is balanced, but two concurrency paths remain unsafe. Add executor-level tests for branch resubmission and propagated OTel contexts. Reviewed commit |
Claude AI reviewReview: fix(otel): balance context attach and detach across plugin lifecyclesNo blocking findings. This is a careful, well-tested fix that correctly addresses the trace-pollution bug (unbalanced Verified correct:
Test coverage is strong: the autouse fixtures were upgraded from hiding leaks (global reset) to asserting balance, and new tests cover suspension, re-entry, worker-thread confinement, FLAT branches, empty/populated extracted context, and both plugins on one thread. Residual risk (documented in the PR, not a regression): a scope abandoned by a suspended operation on a per-invocation worker thread cannot be detached from the handler-thread Reviewed commit |
Fixes #643
Problem
Both OTel plugins called
opentelemetry.context.attach()without keeping the returned token, and "restored" the enclosing span by attaching another context rather than detaching. Every operation therefore pushed two context layers and popped none, leaving an ended span current after its scope had finished.The worst consequence is not in the issue. The invocation-start attach (
execution_plugin.py:219) ran on the Lambda handler thread, which is reused across warm invocations, so the next execution's context extractor (context_extractors.py:27) and GLOBAL-mode ambient-parent lookup (execution_plugin.py:252) adopted the previous execution's ended Workflow span. A valid parent overrides the deterministic ID generator's trace ID, so two unrelated durable executions merged into a single trace. Measured with a runtime probe before the fix:and after:
Two runtime properties shaped the fix. First, the hooks run on several threads — the invocation hooks on the Lambda handler thread, the user-function hooks on the
dex-handlerworker that runs user code, and on a branch worker permap/parallelbranch — andContextVar.reset()only accepts a token created in the samecontextvars.Context. Second, unlike Java'sScopeImpl.close(), which ignores a close that does not represent the current context,ContextVar.reset()writes back its captured value unconditionally, so detaching out of order revives a stale context instead of failing safe.Changes
context_scope.py— a module-level, thread-confined LIFO stack of attach tokens.exit_scopeunwinds downwards so the underlyingContextVaris always reset in order. The stack is module level rather than per plugin instance because both plugins ship as separate entry points and can be enabled together: hooks dispatch in registration order, so the second plugin's scope must come off while the first plugin's end hook runs. An epoch check discards scopes a suspended operation left behind, since the SDK re-raisesSuspendExecutionwithout callingon_user_function_end(state.py:1171).ThreadPoolExecutordoes not copy contextvars, so that attach never reached the code it was meant to parent — it only leaked. The Workflow and Invocation spans are used as explicit parents instead, matching the Java plugins, which never make either span current.Behaviour change
Ambient auto-instrumented spans emitted outside any operation — for example directly in the handler between two steps — are no longer parented to the Invocation span. In an ADOT deployment they attach to the ambient Lambda invocation span instead, which the previous invocation-start attach was shadowing. This matches
ExecutionOtelPlugin/InvocationOtelPluginin the Java SDK, which cover the same window with MDC rather than an attached span. Calls inside a step or child context are unaffected.Log correlation is unchanged: the logging filter resolves through the plugin's span registry, so records emitted between operations still carry the invocation's
traceIdandspanId. One visible detail — handler-thread records now carry the Invocation span'sspanIdinstead of the Workflow span's (sametraceId), since the registry prefers the Invocation span; there is a test pinning this.The durable span hierarchy itself is untouched: parents, links, and deterministic IDs are all chosen explicitly in
_start_span, never taken from the ambient context.Acceptance criteria
context.attach()token owned by the plugin has a correspondingcontext.detach()— with one documented exception below.Documented exception to the first criterion: scopes attached on a worker thread that suspends cannot be detached from the handler thread where invocation end runs, because a token is only resettable in the context that created it. Those threads are created per invocation and their
ContextVardies with them, and the epoch check discards any leftover if a thread is ever reused. The Java plugins have the same gap — their invocation-end sweep iterates an unordered map from the handler thread, so those closes hitScopeImpl's guard and are ignored.Testing
129 tests pass in the otel package, 3223 across the monorepo;
hatch fmt --checkandhatch run types:checkclean.New coverage:
tests/test_context_scope.py(13 tests — LIFO nesting, unwind-above-target, unknown-key no-op, epoch discard, thread confinement, suspension, worker-thread hooks, both plugins on one thread), a warm-reuse test asserting two executions land in separate traces, a pre/post invocation context-restore test, and a log-filter test pinning the handler-threadspanId.Both halves were mutation-tested. Restoring the invocation-start attach fails 11 tests including the warm-reuse and context-restore ones; skipping the detach in
on_user_function_endfails 10 across the balance fixtures and the restore tests.Four tests that asserted "the invocation span is current again after a step" were rewritten to assert exact context restore instead, since that behaviour came from the unbalanced re-attach. Three nested-context tests kept their assertions unchanged and needed only their lifecycle completed — they started a child context and never ended it, which the old reset fixture silently swallowed. Notably
test_get_current_span_context_returns_invocation_span_between_stepspasses untouched, which is the evidence that log correlation survived.Follow-ups (not in this PR)
wrap_user_functionre-raisesSuspendExecutionwithout callingon_user_function_end(state.py:1171), so a suspended operation's hooks are structurally unpaired for every plugin, not just these two. Worth a core-side fix or an explicit suspension hook.AGENTS.mdthat belongs upstream inaws-durable-execution-conformance-testsfirst.