Skip to content

Commit 5c7ee10

Browse files
feat(tracing): per-step obs wrappers inside business Temporal activities (#491)
1 parent 0f820a3 commit 5c7ee10

5 files changed

Lines changed: 310 additions & 66 deletions

File tree

src/agentex/lib/core/tracing/obs_ids.py

Lines changed: 52 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -28,15 +28,22 @@
2828
from __future__ import annotations
2929

3030
import os
31+
import logging
3132
from typing import Dict, Tuple, Optional
3233

33-
__all__ = ("get_obs_mode", "obs_correlation")
34+
__all__ = ("get_obs_mode", "obs_correlation", "warn_on_backend_drift")
3435

3536
DD_ONLY = "dd_only"
3637
LGTM = "lgtm"
3738
_DEFAULT_MODE = DD_ONLY
3839
_VALID_MODES = (DD_ONLY, LGTM)
3940

41+
_log = logging.getLogger(__name__)
42+
# Deduped (expected, actual) drift directions already warned about, so a genuine
43+
# mismatch logs once instead of once per span. Bounded by construction: at most
44+
# the 2 direction pairs ("otel"/"ddtrace" either way).
45+
_WARNED_DRIFT: set[Tuple[str, str]] = set()
46+
4047

4148
def get_obs_mode() -> str:
4249
"""Unset/empty/unrecognized -> ``dd_only`` (current behavior)."""
@@ -69,7 +76,7 @@ def _ddtrace_ids() -> Optional[Tuple[str, str]]:
6976
return None
7077

7178

72-
def obs_correlation(prefer_otel: bool = False) -> Dict[str, str]:
79+
def obs_correlation(expect_otel: bool = False) -> Dict[str, str]:
7380
"""Return ``{"obs_trace_id": ..., "obs_span_id": ...}`` for the active
7481
observability context, or ``{}`` if none is active.
7582
@@ -79,15 +86,15 @@ def obs_correlation(prefer_otel: bool = False) -> Dict[str, str]:
7986
dotted) keep them addressable via Postgres JSON paths
8087
(``operation_metadata->>'obs_trace_id'``).
8188
82-
``prefer_otel``: on the Temporal path the active span is the temporalio OTel
89+
``expect_otel``: on the Temporal path the active span is the temporalio OTel
8390
``TracingInterceptor`` span regardless of ``SGP_OBS_MODE``, so callers there
8491
read OTel first (falling back to ddtrace) -- otherwise the default ``dd_only``
8592
mode would read ids for an unrelated ddtrace trace, not the activity span.
8693
8794
Never fabricates ids -- this is a correlation tag, not the span's id.
8895
"""
8996
try:
90-
if prefer_otel:
97+
if expect_otel:
9198
ids = _lgtm_ids() or _ddtrace_ids()
9299
else:
93100
ids = _lgtm_ids() if get_obs_mode() == LGTM else _ddtrace_ids()
@@ -97,3 +104,44 @@ def obs_correlation(prefer_otel: bool = False) -> Dict[str, str]:
97104
if not ids:
98105
return {}
99106
return {"obs_trace_id": ids[0], "obs_span_id": ids[1]}
107+
108+
109+
def warn_on_backend_drift(expect_otel: bool = False) -> None:
110+
"""Log once when the EXPECTED obs backend has no active span but the OTHER one
111+
does.
112+
113+
Expected backend = OTel when ``expect_otel`` (the Temporal path, where the
114+
interceptor span is OTel regardless of ``SGP_OBS_MODE``), otherwise the backend
115+
the mode implies. A mismatch means the mode does not match the tracer actually
116+
running at this call site -- e.g. ``dd_only`` configured but the live span is
117+
OTel -- which is a real config/instrumentation drift worth surfacing rather
118+
than silently correlating against whatever happens to be live.
119+
120+
Not a hard failure: obs stays fail-open (the caller still reads and falls back,
121+
so no correlation is lost). The warning is deduped per direction, so a standing
122+
mismatch logs once, not once per span. Probes the expected backend first and
123+
returns early when it is live, so the healthy common path never touches the
124+
other backend. Never raises."""
125+
try:
126+
if expect_otel or get_obs_mode() == LGTM:
127+
expected, expected_probe, other_probe, actual = "otel", _lgtm_ids, _ddtrace_ids, "ddtrace"
128+
else:
129+
expected, expected_probe, other_probe, actual = "ddtrace", _ddtrace_ids, _lgtm_ids, "otel"
130+
if expected_probe() is not None:
131+
return # expected backend is live -> healthy; skip the other probe
132+
if other_probe() is None:
133+
return # nothing live at all -> uninstrumented path, not drift
134+
if (expected, actual) not in _WARNED_DRIFT:
135+
_WARNED_DRIFT.add((expected, actual))
136+
_log.warning(
137+
"obs backend drift: expected %s here (SGP_OBS_MODE=%s%s) but the "
138+
"active span is %s; correlating against %s. Check SGP_OBS_MODE and "
139+
"the running instrumentation.",
140+
expected,
141+
get_obs_mode(),
142+
", temporal path" if expect_otel else "",
143+
actual,
144+
actual,
145+
)
146+
except Exception: # obs must never fail an app call
147+
pass

src/agentex/lib/core/tracing/obs_span.py

Lines changed: 27 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -175,6 +175,7 @@ def open_obs_span(
175175
name: str,
176176
business_span_id: Optional[str] = None,
177177
business_trace_id: Optional[str] = None,
178+
expect_otel: bool = False,
178179
) -> Optional[ObsSpanHandle]:
179180
"""Open an obs span named ``name`` in the active backend, make it the active
180181
span, and return a handle carrying its ``{"obs_trace_id","obs_span_id"}``.
@@ -183,6 +184,14 @@ def open_obs_span(
183184
the reverse tag (``agentex.business_span_id`` / ``agentex.business_trace_id``)
184185
so you can pivot obs -> business by searching them in Tempo/DD.
185186
187+
``expect_otel``: open an OTel wrapper first, regardless of ``SGP_OBS_MODE``.
188+
Set on the Temporal path, where the ambient span is the temporalio OTel
189+
``TracingInterceptor`` span regardless of mode -- an OTel wrapper nests under
190+
it and yields valid ids, whereas the default ``dd_only`` path would open a
191+
ddtrace wrapper, which finds no request context in a worker and returns None
192+
(dropping the per-step span and its ids). Falls back to ddtrace if no OTel
193+
span materializes.
194+
186195
Returns ``None`` (so the caller falls back to ambient behavior) when the
187196
backend tracer isn't available or, in ``dd_only``, no request trace is
188197
active.
@@ -192,8 +201,14 @@ def open_obs_span(
192201
never fail an app call.
193202
"""
194203
try:
195-
if get_obs_mode() == LGTM:
196-
return _open_otel_span(name, business_span_id, business_trace_id)
204+
if expect_otel or get_obs_mode() == LGTM:
205+
handle = _open_otel_span(name, business_span_id, business_trace_id)
206+
if handle is not None or not expect_otel:
207+
# In lgtm mode a None handle means "no OTel span -> caller uses the
208+
# ambient fallback". Only when expect_otel is set (Temporal path)
209+
# do we try ddtrace as a second choice.
210+
return handle
211+
return _open_ddtrace_span(name, business_span_id, business_trace_id)
197212
return _open_ddtrace_span(name, business_span_id, business_trace_id)
198213
except Exception: # pragma: no cover - backstop; obs must never break a call
199214
return None
@@ -236,26 +251,27 @@ def _tag_ddtrace_ambient(business_span_id: Optional[str], business_trace_id: Opt
236251
def tag_ambient_obs_span(
237252
business_span_id: Optional[str] = None,
238253
business_trace_id: Optional[str] = None,
239-
prefer_otel: bool = False,
254+
expect_otel: bool = False,
240255
) -> None:
241256
"""Stamp the reverse tag onto the CURRENTLY ACTIVE obs span -- without opening
242257
a new one.
243258
244-
Used on the Temporal path (see ``trace._in_temporal_activity``): there we must
245-
NOT open our own wrapper span, because start_span/end_span run as separate
246-
activities on possibly different workers and the wrapper could never be
247-
closed. Instead we lean on the span the Temporal OTel ``TracingInterceptor``
248-
already made active for this activity and just add
259+
Used inside the SDK's dispatched start-span/end-span activities (see
260+
``trace._in_tracing_dispatch_activity``): there we must NOT open our own
261+
wrapper span, because start_span/end_span run as separate activities on
262+
possibly different workers and the wrapper could never be closed. Instead we
263+
lean on the span the Temporal OTel ``TracingInterceptor`` already made active
264+
for this activity and just add
249265
``agentex.business_span_id`` / ``agentex.business_trace_id`` so the obs -> business
250266
pivot still works. Best-effort; never raises.
251267
252-
``prefer_otel``: on the Temporal path the ambient span is the temporalio OTel
268+
``expect_otel``: on the Temporal path the ambient span is the temporalio OTel
253269
``TracingInterceptor`` span REGARDLESS of ``SGP_OBS_MODE`` -- so callers there
254-
pass ``prefer_otel=True`` to tag OTel first (falling back to ddtrace only if
270+
pass ``expect_otel=True`` to tag OTel first (falling back to ddtrace only if
255271
no valid OTel span is active). Without this, the default ``dd_only`` mode would
256272
tag an unrelated ddtrace span (or nothing) instead of the real activity span."""
257273
try:
258-
if prefer_otel:
274+
if expect_otel:
259275
if _tag_otel_ambient(business_span_id, business_trace_id):
260276
return
261277
_tag_ddtrace_ambient(business_span_id, business_trace_id)

src/agentex/lib/core/tracing/trace.py

Lines changed: 87 additions & 43 deletions
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,7 @@
1212
from agentex.types.span import Span
1313
from agentex.lib.utils.logging import make_logger
1414
from agentex.lib.utils.model_utils import recursive_model_dump
15-
from agentex.lib.core.tracing.obs_ids import obs_correlation
15+
from agentex.lib.core.tracing.obs_ids import obs_correlation, warn_on_backend_drift
1616
from agentex.lib.core.tracing.obs_span import (
1717
ObsSpanHandle,
1818
open_obs_span,
@@ -106,35 +106,54 @@ def _run_on_span_end(processor: SyncTracingProcessor, span: Span) -> None:
106106
)
107107

108108

109+
def _in_tracing_dispatch_activity() -> bool:
110+
"""True only when running inside the SDK's OWN dispatched START_SPAN / END_SPAN
111+
activity (the ``in_temporal_workflow()`` path, where a workflow runs span start
112+
and end as SEPARATE activities that Temporal can route to different workers).
113+
114+
That is the one case a per-step obs wrapper can't work: the wrapper opened in
115+
the START_SPAN activity could never be closed by the END_SPAN activity. A span
116+
created directly inside a *business* activity (an agent turn's own
117+
``adk.tracing.span``) runs start AND end in the same activity process, so a
118+
wrapper there is safe -- it nests under the interceptor's ambient RunActivity
119+
span and closes in-process. The tracing dispatch activities are named by
120+
``TracingActivityName`` (``start-span`` / ``end-span``). Never raises; False
121+
when temporalio isn't importable or we're not in an activity."""
122+
try:
123+
from temporalio import activity
124+
125+
if not activity.in_activity():
126+
return False
127+
# Import only AFTER the in_activity() guard: the pure-sync ACP path never
128+
# runs this, so it doesn't pull the temporal activities module graph
129+
# (activities -> TracingService -> AsyncTracer -> trace, also circular at
130+
# import time) into a process that never runs a workflow, and a broken
131+
# import can't silently disable the guard on that path. Inside an activity
132+
# the graph is fully loaded, so the lazy import is safe -- and it keeps the
133+
# discriminator keyed on the enum, not on drifting string literals.
134+
# ``activity_type`` round-trips as the enum's str value, which a str-Enum
135+
# member compares equal to.
136+
from agentex.lib.core.temporal.activities.adk.tracing_activities import (
137+
TracingActivityName,
138+
)
139+
140+
return activity.info().activity_type in (
141+
TracingActivityName.START_SPAN,
142+
TracingActivityName.END_SPAN,
143+
)
144+
except Exception:
145+
return False
146+
147+
109148
def _in_temporal_activity() -> bool:
110-
"""True when executing inside a Temporal activity.
111-
112-
On the Temporal path ``start_span`` and ``end_span`` run as SEPARATE
113-
activities (START_SPAN / END_SPAN) that Temporal can route to DIFFERENT
114-
worker processes. A wrapper obs span opened in the START_SPAN activity could
115-
therefore never be closed by END_SPAN -- its handle lives in another
116-
process's ``_OBS_HANDLES`` -- so it would leak (unbounded, OOM risk) and its
117-
persisted ``obs_span_id`` would dangle (the span is never .end()ed, so never
118-
exported to Tempo).
119-
120-
So inside an activity we do NOT open our own wrapper. We lean on the span the
121-
Temporal OTel ``TracingInterceptor`` (see ``core/tracing/temporal.py`` +
122-
scale-agentex-python#485) already made active for this activity -- which is
123-
rooted under the turn's propagated trace -- and merely stamp the reverse tag
124-
onto it (``tag_ambient_obs_span``). That keeps trace-level correlation with
125-
no cross-process handle to leak.
126-
127-
Never raises; returns False when temporalio isn't importable.
128-
129-
TODO(obs-followup): this intentionally drops the *named per-step* wrapper on
130-
the Temporal path (obs_span_id becomes the ambient activity span, not a
131-
step-named span) and does NOT add TurnTrace RETRY/ASYNC roll-up -- retried
132-
turns still surface as N unlinked spans. Follow-up diff should (a) optionally
133-
materialize a self-contained named wrapper inside a single activity using the
134-
span's own start/end timestamps, and (b) build the TurnTrace roll-up.
135-
Test-later: on a multi-replica worker fleet, assert _OBS_HANDLES stays
136-
bounded (no leak / OOM) and that obs_trace_id resolves to the turn trace.
137-
"""
149+
"""True inside ANY Temporal activity. There the ambient span is the temporalio
150+
OTel ``TracingInterceptor`` span REGARDLESS of ``SGP_OBS_MODE``, so callers
151+
prefer OTel for both the wrapper backend and the correlation read: a plain
152+
``dd_only`` read would target ddtrace, which has no request context in a worker
153+
(no inbound HTTP), so ``open_obs_span`` would return None and the fallback ids
154+
would be empty -- the business span would persist with no obs_* ids at all.
155+
Never raises; False when temporalio isn't importable or we're not in an
156+
activity."""
138157
try:
139158
from temporalio import activity
140159

@@ -148,27 +167,52 @@ def _begin_obs(
148167
span_id: str,
149168
trace_id: str | None,
150169
) -> tuple[ObsSpanHandle | None, dict[str, str]]:
151-
"""Open the obs wrapper for a business span (or, inside a Temporal activity,
152-
tag the ambient interceptor span) and return ``(handle, correlation)``.
170+
"""Open the obs wrapper for a business span and return ``(handle, correlation)``.
153171
154172
Shared by ``Trace.start_span`` and ``AsyncTrace.start_span`` so the two paths
155173
can't drift. The wrapper is named for the step so ``obs_span_id`` is
156174
stable/meaningful (not an arbitrary innermost httpx span), and it carries the
157175
reverse tag (business span/trace id) for the obs -> business pivot.
158176
159-
Temporal path: we do NOT open our own wrapper -- start_span / end_span run as
160-
separate activities on possibly different workers, so the handle could never
161-
be closed. Instead we tag the span the temporalio OTel ``TracingInterceptor``
162-
already made active. That span is OTel REGARDLESS of ``SGP_OBS_MODE``, so we
163-
pass ``prefer_otel=True`` to both the tag and the correlation read -- otherwise
164-
the default ``dd_only`` mode would tag/read an unrelated ddtrace span and the
165-
ids would point at the wrong trace. See ``_in_temporal_activity``.
177+
We open a real per-step wrapper on the sync path AND inside a *business*
178+
Temporal activity -- there the wrapper nests under the interceptor's ambient
179+
RunActivity span and start/end run in-process, so it closes cleanly and each
180+
business step gets its own obs span (1:1), just like sync.
181+
182+
The ONE exception is the SDK's own dispatched START_SPAN / END_SPAN activity
183+
(a workflow calling ``adk.tracing`` -- see ``_in_tracing_dispatch_activity``):
184+
there start and end are separate activities on possibly different workers, so
185+
a wrapper could never be closed. We fall back to tagging the ambient
186+
interceptor span instead, with ``expect_otel=True`` (the interceptor span is
187+
OTel regardless of ``SGP_OBS_MODE``, so a plain ``dd_only`` read would
188+
otherwise point at an unrelated ddtrace span).
189+
190+
Inside ANY activity we also pass ``expect_otel`` to the wrapper and the ambient
191+
fallback: the ambient span is the interceptor's OTel span regardless of mode,
192+
so a per-step OTel wrapper nests under it and yields valid ids, whereas the
193+
default ``dd_only`` path would open a ddtrace wrapper -- which finds no request
194+
context in a worker and returns None, leaving the business span with empty
195+
obs_* ids.
166196
"""
167-
if _in_temporal_activity():
168-
tag_ambient_obs_span(business_span_id=span_id, business_trace_id=trace_id, prefer_otel=True)
169-
return None, obs_correlation(prefer_otel=True)
170-
handle = open_obs_span(name, business_span_id=span_id, business_trace_id=trace_id)
171-
correlation = handle.correlation if handle is not None else obs_correlation()
197+
if _in_tracing_dispatch_activity():
198+
warn_on_backend_drift(expect_otel=True)
199+
tag_ambient_obs_span(business_span_id=span_id, business_trace_id=trace_id, expect_otel=True)
200+
return None, obs_correlation(expect_otel=True)
201+
# TODO(obs-followup): two items formerly tracked on the (now-deleted)
202+
# _in_temporal_activity docstring, still open after this change:
203+
# (1) TurnTrace RETRY/ASYNC roll-up. A retried business activity now emits a
204+
# full per-step wrapper set PER ATTEMPT, each nested under that attempt's
205+
# RunActivity. Each attempt correlates to the turn on its own, but they
206+
# are not yet rolled up, so a retried turn surfaces as N per-attempt span
207+
# sets rather than one PRIMARY + N RETRY view.
208+
# (2) On a multi-replica worker fleet, assert _OBS_HANDLES stays bounded (no
209+
# leak / OOM) and that obs_trace_id resolves to the turn trace.
210+
expect_otel = _in_temporal_activity()
211+
warn_on_backend_drift(expect_otel)
212+
handle = open_obs_span(
213+
name, business_span_id=span_id, business_trace_id=trace_id, expect_otel=expect_otel
214+
)
215+
correlation = handle.correlation if handle is not None else obs_correlation(expect_otel=expect_otel)
172216
return handle, correlation
173217

174218

tests/lib/core/tracing/test_obs_span.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -351,7 +351,7 @@ def test_lgtm_wrapper_marked_error_when_business_step_raises(self, monkeypatch):
351351
def test_dd_only_no_ctx_falls_back_to_ambient(self, monkeypatch):
352352
monkeypatch.setenv("SGP_OBS_MODE", "dd_only")
353353
_install_fake_ddtrace(monkeypatch, active=False)
354-
monkeypatch.setattr("agentex.lib.core.tracing.trace.obs_correlation", lambda: {})
354+
monkeypatch.setattr("agentex.lib.core.tracing.trace.obs_correlation", lambda **_k: {})
355355

356356
trace = Trace(processors=[], client=MagicMock(), trace_id="task-run-3")
357357
span = trace.start_span(name="get_state")

0 commit comments

Comments
 (0)