Skip to content

Commit 515f86c

Browse files
feat(tracing): wrap a sync agent turn in a root span
Nothing owned the turn on the sync path, so no span covered it and every span was emitted parentless. A trace was a flat list of fragments whose durations did not add up to the turn. run_turn_streamed owns it: one root span, tool spans parented beneath it, orphans drained, root closed when the stream ends. The root's width is the turn's real latency, and the UI can draw a waterfall.
1 parent 035be54 commit 515f86c

2 files changed

Lines changed: 219 additions & 0 deletions

File tree

Lines changed: 95 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,95 @@
1+
"""One traced turn on the sync (non-Temporal) OpenAI Agents path.
2+
3+
Agents on this path call ``Runner.run_streamed`` themselves, so nothing owns the
4+
turn and no span covers it: the provider only spans the inference call, and every
5+
span is emitted with no parent. A trace is therefore a flat list of fragments
6+
whose durations do not add up to the turn, and tool time is missing entirely.
7+
8+
``run_turn_streamed`` owns the turn instead. It opens one root span, hangs the
9+
tool spans off it, drains anything left open, and closes the root when the stream
10+
is done, so the root's width is the turn's real latency.
11+
"""
12+
13+
from __future__ import annotations
14+
15+
from typing import Any, AsyncIterator
16+
from datetime import timedelta
17+
18+
from agents import Agent, Runner, RunConfig
19+
20+
from agentex.lib.utils.logging import make_logger
21+
from agentex.lib.adk._modules._sync_tracing_hooks import SyncTracingHooks
22+
23+
logger = make_logger(__name__)
24+
25+
_TRACE_TIMEOUT = timedelta(seconds=5)
26+
27+
28+
def _get_adk() -> Any:
29+
from agentex.lib import adk
30+
31+
return adk
32+
33+
34+
async def run_turn_streamed(
35+
starting_agent: Agent,
36+
input: Any,
37+
*,
38+
trace_id: str | None = None,
39+
task_id: str | None = None,
40+
run_config: RunConfig | None = None,
41+
max_turns: int | None = None,
42+
span_name: str = "turn",
43+
) -> AsyncIterator[Any]:
44+
"""Stream one agent turn, wrapped in a root span with tool spans beneath it.
45+
46+
Yields the SDK's raw stream events untouched, so callers keep whatever event
47+
conversion they already do.
48+
49+
Tracing is best-effort throughout: if the backend is unreachable the turn
50+
still runs and still streams.
51+
"""
52+
root_span = None
53+
if trace_id:
54+
try:
55+
root_span = await _get_adk().tracing.start_span(
56+
trace_id=trace_id,
57+
task_id=task_id,
58+
name=span_name,
59+
input={"agent": starting_agent.name},
60+
start_to_close_timeout=_TRACE_TIMEOUT,
61+
)
62+
except Exception as e: # noqa: BLE001 - tracing is best-effort
63+
logger.warning(f"[tracing] turn start_span failed (non-fatal): {e}")
64+
65+
hooks = SyncTracingHooks(
66+
trace_id=trace_id,
67+
# Tool spans nest under the turn, which is what lets the UI draw a
68+
# waterfall instead of a flat list.
69+
parent_span_id=getattr(root_span, "id", None),
70+
task_id=task_id,
71+
)
72+
73+
run_kwargs: dict[str, Any] = {"hooks": hooks}
74+
if run_config is not None:
75+
run_kwargs["run_config"] = run_config
76+
if max_turns is not None:
77+
run_kwargs["max_turns"] = max_turns
78+
79+
try:
80+
result = Runner.run_streamed(starting_agent, input, **run_kwargs)
81+
async for event in result.stream_events():
82+
yield event
83+
finally:
84+
# A turn that dies mid-tool (max-turns, cancellation, an SDK error) never
85+
# fires the matching end hook, so drain before closing the root.
86+
await hooks.close_open_tool_spans()
87+
if root_span is not None and trace_id:
88+
try:
89+
await _get_adk().tracing.end_span(
90+
trace_id=trace_id,
91+
span=root_span,
92+
start_to_close_timeout=_TRACE_TIMEOUT,
93+
)
94+
except Exception as e: # noqa: BLE001 - tracing is best-effort
95+
logger.warning(f"[tracing] turn end_span failed (non-fatal): {e}")

tests/lib/adk/test_sync_turn.py

Lines changed: 124 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,124 @@
1+
"""Tests for the root turn span on the sync OpenAI-Agents path.
2+
3+
The defect these guard: with no root span and no parenting, a trace is a flat
4+
list of fragments whose durations do not sum to the turn, so tool time simply
5+
goes missing. These assert a root span exists, that tool spans hang off it, and
6+
that tracing failures never stop the turn from streaming.
7+
"""
8+
9+
from __future__ import annotations
10+
11+
from types import SimpleNamespace
12+
from unittest.mock import AsyncMock, MagicMock
13+
14+
import pytest
15+
16+
from agentex.lib.adk._modules import _sync_turn as turn_mod
17+
18+
19+
def _adk(root_span=None):
20+
return SimpleNamespace(
21+
tracing=SimpleNamespace(
22+
start_span=AsyncMock(return_value=root_span),
23+
end_span=AsyncMock(),
24+
)
25+
)
26+
27+
28+
def _runner_yielding(*events):
29+
async def _stream():
30+
for e in events:
31+
yield e
32+
33+
result = MagicMock()
34+
result.stream_events = _stream
35+
return MagicMock(return_value=result)
36+
37+
38+
def _agent(name="analyst"):
39+
agent = MagicMock()
40+
agent.name = name
41+
return agent
42+
43+
44+
async def _drain(gen):
45+
return [e async for e in gen]
46+
47+
48+
@pytest.mark.asyncio
49+
async def test_opens_a_root_span_and_closes_it(monkeypatch):
50+
root = SimpleNamespace(id="root-1")
51+
adk = _adk(root)
52+
monkeypatch.setattr(turn_mod, "_get_adk", lambda: adk)
53+
monkeypatch.setattr(turn_mod.Runner, "run_streamed", _runner_yielding("a", "b"))
54+
55+
events = await _drain(turn_mod.run_turn_streamed(_agent(), [], trace_id="tr1", task_id="task1"))
56+
57+
assert events == ["a", "b"]
58+
assert adk.tracing.start_span.await_args.kwargs["name"] == "turn"
59+
adk.tracing.end_span.assert_awaited_once()
60+
assert adk.tracing.end_span.await_args.kwargs["span"] is root
61+
62+
63+
@pytest.mark.asyncio
64+
async def test_tool_spans_are_parented_to_the_root(monkeypatch):
65+
root = SimpleNamespace(id="root-1")
66+
monkeypatch.setattr(turn_mod, "_get_adk", lambda: _adk(root))
67+
68+
captured = {}
69+
70+
class _Hooks:
71+
def __init__(self, **kwargs):
72+
captured.update(kwargs)
73+
74+
async def close_open_tool_spans(self):
75+
return None
76+
77+
monkeypatch.setattr(turn_mod, "SyncTracingHooks", _Hooks)
78+
monkeypatch.setattr(turn_mod.Runner, "run_streamed", _runner_yielding("a"))
79+
80+
await _drain(turn_mod.run_turn_streamed(_agent(), [], trace_id="tr1"))
81+
82+
assert captured["parent_span_id"] == "root-1"
83+
84+
85+
@pytest.mark.asyncio
86+
async def test_no_trace_id_still_streams(monkeypatch):
87+
adk = _adk()
88+
monkeypatch.setattr(turn_mod, "_get_adk", lambda: adk)
89+
monkeypatch.setattr(turn_mod.Runner, "run_streamed", _runner_yielding("a", "b"))
90+
91+
events = await _drain(turn_mod.run_turn_streamed(_agent(), []))
92+
93+
assert events == ["a", "b"]
94+
adk.tracing.start_span.assert_not_awaited()
95+
96+
97+
@pytest.mark.asyncio
98+
async def test_start_span_failure_still_streams(monkeypatch):
99+
adk = _adk()
100+
adk.tracing.start_span.side_effect = RuntimeError("tracing backend down")
101+
monkeypatch.setattr(turn_mod, "_get_adk", lambda: adk)
102+
monkeypatch.setattr(turn_mod.Runner, "run_streamed", _runner_yielding("a"))
103+
104+
assert await _drain(turn_mod.run_turn_streamed(_agent(), [], trace_id="tr1")) == ["a"]
105+
106+
107+
@pytest.mark.asyncio
108+
async def test_root_span_closes_when_the_run_raises(monkeypatch):
109+
root = SimpleNamespace(id="root-1")
110+
adk = _adk(root)
111+
monkeypatch.setattr(turn_mod, "_get_adk", lambda: adk)
112+
113+
async def _boom():
114+
yield "a"
115+
raise RuntimeError("max turns exceeded")
116+
117+
result = MagicMock()
118+
result.stream_events = _boom
119+
monkeypatch.setattr(turn_mod.Runner, "run_streamed", MagicMock(return_value=result))
120+
121+
with pytest.raises(RuntimeError):
122+
await _drain(turn_mod.run_turn_streamed(_agent(), [], trace_id="tr1"))
123+
124+
adk.tracing.end_span.assert_awaited_once()

0 commit comments

Comments
 (0)