Skip to content

Commit c2c1eda

Browse files
observability: phase 6.1 concurrency-safe observer (PR-A) (#22)
* observability: phase 6.1 concurrency-safe observer Phase 6.0 left three architectural limitations: OTelObserver state collided across concurrent invocations on a shared instance, OTel attach tokens spanned event boundaries (LIFO violations under interleaved fan-out, suppressed by try/except guards in round-7), and LLM spans had no calling-node identity threaded through, so parent resolution fell back to the OTel current-span context and mis-attributed under concurrent fan-out + retry. Spec agent's ack folded the three into one coherent refactor — they share the same primitive ("parents come from the observer's internal maps within a single event handler's scope") and split would ship intermediate states that fail their own correctness story. Three new ContextVars in observability/correlation.py carry the calling-node identity: current_namespace_prefix (default ()), current_fan_out_index (default None), current_attempt_index (default 0). The engine sets the first two in the outer per-node scope of _step_function_node / _step_subgraph_node / _step_fan_out_node; attempt_index lives inside innermost so retry middleware that re-enters the inner closure bumps the value per attempt. _LlmEventState gains calling_* fields populated from the ContextVars at dispatch time. OTelObserver state is now outer-keyed by invocation_id, not correlation_id. Resume preserves the cid across runs (per spec §5.6 cross-run join), so a cid-keyed map would have the resumed run's spans inherit the prior invocation's trace_id, violating §5.1's "each invocation has its own trace_id". Caught during impl by test_phase5_fixture_031_span_assertions. The cid is still set as openarmature.correlation_id on every span — only the state- scoping key changed. Parent resolution moves entirely to internal maps. _OpenSpan no longer carries an OTel context token; each event handler reads the parent from per-invocation open_spans / subgraph_spans / detached_roots and starts the span with context=set_span_in_context(parent). The round-7 try/except ValueError guards on cross-event detach are deleted (no tokens cross events). The close-prior-correlation_id branch in _handle_started is deleted (per-invocation scoping makes it unreachable). "Concurrency model — NOT safe" warning and cross-event attach-token notes come out of the class docstring. LLM-span parent resolution uses calling-node identity directly: _resolve_llm_parent looks up open_spans by the full _StackKey (calling_namespace_prefix, calling_attempt_index, calling_fan_out_index), then walks ancestors for subgraph dispatch or detached roots, then falls back to the invocation span. Under concurrent fan-out + retry the LLM span lands under exactly the right calling node regardless of dispatch ordering or which sibling instance's span happens to be on the OTel current-span stack. Tests added in tests/unit/test_observability_otel.py: - shared-observer concurrent invocations (asyncio.gather × 5): N distinct trace_ids and clean per-invocation span trees. - concurrent fan-out (4 instances) each calling LLM: every LLM span parents under its own calling instance, not a sibling. - LIFO regression check under warnings.catch_warnings("error"): the path that previously needed try/except guards stays quiet under the new architecture rather than being suppressed. - LLM call inside retried node (max_attempts=3, two failures + one success): each LLM span parents under its own attempt's span, not a hardcoded attempt 0. 387 tests pass (4 new). Pyright clean. * otel: address PR #22 review - Fix _fan_out_node_span_key hardcoding attempt_index=0. Fan-out nodes wrapped with retry middleware open at the bumped attempt_index, so the lookup missed under retry and the detached-instance Link wasn't added to the §4.4 cross-trace navigation. Replaced with _find_fan_out_node_span scan that finds the in-flight fan-out span at prefix regardless of attempt_index (only one such entry is open at a time). - Update close_invocation docstring to be honest about the invocation_id sourcing constraint (CompiledGraph.invoke doesn't return it; the ContextVar is reset before control returns) and recommend shutdown() as the typical-production lifecycle hook. The deeper UX gap (long-lived observers without periodic shutdown accumulate per-invocation residue) is tracked in phase-6-1-conformance-fillin.md for follow-up. - Fix stale "now-cid-scoped" wording in openai.py — observer state is invocation_id-keyed in the merged code.
1 parent 41908c5 commit c2c1eda

6 files changed

Lines changed: 1011 additions & 450 deletions

File tree

src/openarmature/graph/compiled.py

Lines changed: 118 additions & 78 deletions
Original file line numberDiff line numberDiff line change
@@ -44,12 +44,18 @@
4444
from openarmature.observability.correlation import (
4545
_reset_active_dispatch,
4646
_reset_active_observers,
47+
_reset_attempt_index,
4748
_reset_correlation_id,
49+
_reset_fan_out_index,
4850
_reset_invocation_id,
51+
_reset_namespace_prefix,
4952
_set_active_dispatch,
5053
_set_active_observers,
54+
_set_attempt_index,
5155
_set_correlation_id,
56+
_set_fan_out_index,
5257
_set_invocation_id,
58+
_set_namespace_prefix,
5359
)
5460

5561
from .edges import END, ConditionalEdge, EndSentinel, StaticEdge
@@ -558,51 +564,59 @@ async def innermost(s: Any) -> Mapping[str, Any]:
558564
attempt_index = attempt_counter[0]
559565
attempt_counter[0] += 1
560566

561-
self._dispatch_started(context, current, namespace, step, s, attempt_index=attempt_index)
562-
567+
# Calling-node identity for capability backends emitting
568+
# from inside this attempt's scope (e.g., LLM provider's
569+
# span hook). Per-attempt scope so retry middleware that
570+
# re-enters innermost bumps the visible attempt_index.
571+
attempt_token = _set_attempt_index(attempt_index)
563572
try:
564-
partial = await node.run(s)
565-
except Exception as e:
566-
wrapped = NodeException(node_name=current, cause=e, recoverable_state=s)
567-
self._dispatch_completed(
568-
context,
569-
current,
570-
namespace,
571-
step,
572-
s,
573-
error=wrapped,
574-
attempt_index=attempt_index,
575-
)
576-
raise
573+
self._dispatch_started(context, current, namespace, step, s, attempt_index=attempt_index)
574+
575+
try:
576+
partial = await node.run(s)
577+
except Exception as e:
578+
wrapped = NodeException(node_name=current, cause=e, recoverable_state=s)
579+
self._dispatch_completed(
580+
context,
581+
current,
582+
namespace,
583+
step,
584+
s,
585+
error=wrapped,
586+
attempt_index=attempt_index,
587+
)
588+
raise
589+
590+
try:
591+
merged = _merge_partial(s, partial, self.reducers, current)
592+
except (ReducerError, StateValidationError) as e:
593+
self._dispatch_completed(
594+
context,
595+
current,
596+
namespace,
597+
step,
598+
s,
599+
error=e,
600+
attempt_index=attempt_index,
601+
)
602+
raise
577603

578-
try:
579-
merged = _merge_partial(s, partial, self.reducers, current)
580-
except (ReducerError, StateValidationError) as e:
581604
self._dispatch_completed(
582605
context,
583606
current,
584607
namespace,
585608
step,
586609
s,
587-
error=e,
610+
post_state=merged,
588611
attempt_index=attempt_index,
589612
)
590-
raise
591-
592-
self._dispatch_completed(
593-
context,
594-
current,
595-
namespace,
596-
step,
597-
s,
598-
post_state=merged,
599-
attempt_index=attempt_index,
600-
)
601-
# Return the partial (not the merged state) so middleware sees
602-
# the partial-update shape per pipeline-utilities §2. The
603-
# engine's canonical merge against the original state happens
604-
# below, after the chain returns.
605-
return partial
613+
# Return the partial (not the merged state) so middleware sees
614+
# the partial-update shape per pipeline-utilities §2. The
615+
# engine's canonical merge against the original state happens
616+
# below, after the chain returns.
617+
return partial
618+
finally:
619+
_reset_attempt_index(attempt_token)
606620

607621
chain: ChainCall = compose_chain(
608622
list(self.middleware) + list(node.middleware),
@@ -612,12 +626,17 @@ async def innermost(s: Any) -> Mapping[str, Any]:
612626
# Spec observability §3 / Phase 6 LLM-span hook: capability
613627
# backends emitting from inside a node body (the
614628
# llm-provider span instrumentation in OpenAIProvider) need
615-
# to find the observers active for THIS invocation. Set the
616-
# ContextVar around the chain invocation; reset in
617-
# ``try/finally`` so an exception escaping the chain still
618-
# restores the prior value.
629+
# to find the observers active for THIS invocation, which
630+
# node is calling, and which fan-out instance (if any) the
631+
# call belongs to. ``namespace_prefix`` and ``fan_out_index``
632+
# are set in this outer scope (per-node, not per-attempt);
633+
# ``attempt_index`` is set inside ``innermost`` per attempt.
634+
# All four reset in ``try/finally`` so an exception escaping
635+
# the chain still restores the prior values.
619636
observers_token = _set_active_observers(context.full_observers())
620637
dispatch_token = _set_active_dispatch(lambda event: _dispatch(context, event))
638+
namespace_token = _set_namespace_prefix(namespace)
639+
fan_out_token = _set_fan_out_index(context.fan_out_index)
621640
try:
622641
try:
623642
final_partial = await chain(state)
@@ -628,6 +647,8 @@ async def innermost(s: Any) -> Mapping[str, Any]:
628647
# the chain unrecovered. Wrap as NodeException per §4.
629648
raise NodeException(node_name=current, cause=e, recoverable_state=state) from e
630649
finally:
650+
_reset_fan_out_index(fan_out_token)
651+
_reset_namespace_prefix(namespace_token)
631652
_reset_active_dispatch(dispatch_token)
632653
_reset_active_observers(observers_token)
633654
# Engine's canonical merge uses the ORIGINAL state per §2: "the
@@ -686,13 +707,18 @@ async def innermost(s: Any) -> Mapping[str, Any]:
686707
list(self.middleware) + list(node.middleware),
687708
innermost,
688709
)
689-
# Same active-observers scope as _step_function_node — parent
690-
# middleware running before the descent should see the parent's
691-
# observer set; the inner _invoke (called via ``node.run``)
692-
# descends into its own context and sets a new scope from
693-
# there.
710+
# Same active-observers + calling-node scope as
711+
# ``_step_function_node`` — parent middleware running before
712+
# the descent should see the wrapper node's namespace +
713+
# fan_out_index for any LLM-provider hook emissions.
714+
# ``attempt_index`` defaults to 0 from the ContextVar; the
715+
# subgraph wrapper has no engine-managed attempt counter
716+
# (inner ``_step_function_node`` calls own their own).
717+
namespace = context.namespace_prefix + (current,)
694718
observers_token = _set_active_observers(context.full_observers())
695719
dispatch_token = _set_active_dispatch(lambda event: _dispatch(context, event))
720+
namespace_token = _set_namespace_prefix(namespace)
721+
fan_out_token = _set_fan_out_index(context.fan_out_index)
696722

697723
try:
698724
try:
@@ -707,6 +733,8 @@ async def innermost(s: Any) -> Mapping[str, Any]:
707733
# preserved.
708734
raise NodeException(node_name=current, cause=e, recoverable_state=state) from e
709735
finally:
736+
_reset_fan_out_index(fan_out_token)
737+
_reset_namespace_prefix(namespace_token)
710738
_reset_active_dispatch(dispatch_token)
711739
_reset_active_observers(observers_token)
712740
return _merge_partial(state, final_partial, self.reducers, current)
@@ -743,58 +771,68 @@ async def _step_fan_out_node(
743771
async def innermost(s: Any) -> Mapping[str, Any]:
744772
attempt_index = attempt_counter[0]
745773
attempt_counter[0] += 1
746-
self._dispatch_started(context, current, namespace, step, s, attempt_index=attempt_index)
774+
attempt_token = _set_attempt_index(attempt_index)
747775
try:
748-
partial = await node.run_with_context(s, context)
749-
except RuntimeGraphError as e:
750-
self._dispatch_completed(
751-
context, current, namespace, step, s, error=e, attempt_index=attempt_index
752-
)
753-
raise
754-
except Exception as e:
755-
wrapped = NodeException(node_name=current, cause=e, recoverable_state=s)
776+
self._dispatch_started(context, current, namespace, step, s, attempt_index=attempt_index)
777+
try:
778+
partial = await node.run_with_context(s, context)
779+
except RuntimeGraphError as e:
780+
self._dispatch_completed(
781+
context, current, namespace, step, s, error=e, attempt_index=attempt_index
782+
)
783+
raise
784+
except Exception as e:
785+
wrapped = NodeException(node_name=current, cause=e, recoverable_state=s)
786+
self._dispatch_completed(
787+
context,
788+
current,
789+
namespace,
790+
step,
791+
s,
792+
error=wrapped,
793+
attempt_index=attempt_index,
794+
)
795+
raise wrapped from e
796+
797+
try:
798+
merged = _merge_partial(s, partial, self.reducers, current)
799+
except (ReducerError, StateValidationError) as e:
800+
self._dispatch_completed(
801+
context, current, namespace, step, s, error=e, attempt_index=attempt_index
802+
)
803+
raise
804+
756805
self._dispatch_completed(
757806
context,
758807
current,
759808
namespace,
760809
step,
761810
s,
762-
error=wrapped,
811+
post_state=merged,
763812
attempt_index=attempt_index,
764813
)
765-
raise wrapped from e
766-
767-
try:
768-
merged = _merge_partial(s, partial, self.reducers, current)
769-
except (ReducerError, StateValidationError) as e:
770-
self._dispatch_completed(
771-
context, current, namespace, step, s, error=e, attempt_index=attempt_index
772-
)
773-
raise
774-
775-
self._dispatch_completed(
776-
context,
777-
current,
778-
namespace,
779-
step,
780-
s,
781-
post_state=merged,
782-
attempt_index=attempt_index,
783-
)
784-
return partial
814+
return partial
815+
finally:
816+
_reset_attempt_index(attempt_token)
785817

786818
chain: ChainCall = compose_chain(
787819
list(self.middleware) + list(node.middleware),
788820
innermost,
789821
)
790822

791823
# Same observability §3 / LLM-span hook contract as
792-
# _step_function_node: set the active observer set in scope
793-
# around the chain invocation so capability backends emitting
794-
# from inside the fan-out's parent dispatch (or any code
795-
# running on its call stack) can find the observers.
824+
# _step_function_node: set the active observer set, calling
825+
# node identity, and dispatch scope around the chain
826+
# invocation so capability backends emitting from inside the
827+
# fan-out's parent dispatch (or any code running on its call
828+
# stack) can find them. ``fan_out_index`` here is the parent
829+
# context's view (the fan-out node from outside); per-instance
830+
# values get set when the inner subgraph descends with the
831+
# instance's index in its own context.
796832
observers_token = _set_active_observers(context.full_observers())
797833
dispatch_token = _set_active_dispatch(lambda event: _dispatch(context, event))
834+
namespace_token = _set_namespace_prefix(namespace)
835+
fan_out_token = _set_fan_out_index(context.fan_out_index)
798836
try:
799837
try:
800838
final_partial = await chain(state)
@@ -803,6 +841,8 @@ async def innermost(s: Any) -> Mapping[str, Any]:
803841
except Exception as e:
804842
raise NodeException(node_name=current, cause=e, recoverable_state=state) from e
805843
finally:
844+
_reset_fan_out_index(fan_out_token)
845+
_reset_namespace_prefix(namespace_token)
806846
_reset_active_dispatch(dispatch_token)
807847
_reset_active_observers(observers_token)
808848
merged_outer = _merge_partial(state, final_partial, self.reducers, current)

src/openarmature/llm/providers/openai.py

Lines changed: 26 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -47,7 +47,12 @@
4747

4848
from openarmature.graph.events import NodeEvent
4949
from openarmature.graph.state import State
50-
from openarmature.observability.correlation import current_dispatch
50+
from openarmature.observability.correlation import (
51+
current_attempt_index,
52+
current_dispatch,
53+
current_fan_out_index,
54+
current_namespace_prefix,
55+
)
5156

5257
from ..errors import (
5358
ProviderAuthentication,
@@ -554,6 +559,15 @@ class _LlmEventState(State):
554559
LLM-span maps by it so concurrent ``complete()`` calls (e.g.,
555560
fan-out instances each calling the provider) don't collide on
556561
a single sentinel-namespace key.
562+
563+
``calling_namespace_prefix``, ``calling_attempt_index``, and
564+
``calling_fan_out_index`` carry the calling node's identity so
565+
the OTel observer can resolve the §5.5 "parent under calling
566+
node" contract correctly under concurrent fan-out and retry.
567+
Populated from the engine's ContextVars (set in
568+
``_step_*_node`` around node-body execution); fall back to
569+
sentinel defaults (empty tuple, 0, ``None``) when the LLM
570+
provider is called outside any node body.
557571
"""
558572

559573
call_id: str
@@ -571,6 +585,14 @@ class _LlmEventState(State):
571585
error_type: str | None = None
572586
error_message: str | None = None
573587
error_category: str | None = None
588+
# Calling-node identity captured at dispatch time. The OTel
589+
# observer reads these to look up the calling node's span in
590+
# its (now-invocation_id-scoped) ``_open_spans`` map without relying on
591+
# the OTel current-span context (which under concurrent fan-out
592+
# can yield a sibling instance's span).
593+
calling_namespace_prefix: tuple[str, ...] = ()
594+
calling_attempt_index: int = 0
595+
calling_fan_out_index: int | None = None
574596

575597

576598
def _make_llm_event(
@@ -611,6 +633,9 @@ def _make_llm_event(
611633
error_type=error_type,
612634
error_message=error_message,
613635
error_category=error_category,
636+
calling_namespace_prefix=current_namespace_prefix(),
637+
calling_attempt_index=current_attempt_index(),
638+
calling_fan_out_index=current_fan_out_index(),
614639
)
615640
return NodeEvent(
616641
node_name="openarmature.llm.complete",

src/openarmature/observability/__init__.py

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -22,14 +22,20 @@
2222

2323
from .correlation import (
2424
current_active_observers,
25+
current_attempt_index,
2526
current_correlation_id,
2627
current_dispatch,
28+
current_fan_out_index,
2729
current_invocation_id,
30+
current_namespace_prefix,
2831
)
2932

3033
__all__ = [
3134
"current_active_observers",
35+
"current_attempt_index",
3236
"current_correlation_id",
3337
"current_dispatch",
38+
"current_fan_out_index",
3439
"current_invocation_id",
40+
"current_namespace_prefix",
3541
]

0 commit comments

Comments
 (0)