Skip to content

Commit 7552722

Browse files
test(eval): address PR review feedback on the span-flush race repro
Addresses three points from the Copilot review on this PR: - Encode input.value as a JSON string in the repro test, matching real span attribute constraints (a raw dict is not a valid OTel attribute value and would be silently dropped). - Add test_get_and_clear_execution_data_flushes_before_reading, which exercises the real production method through a fake self carrying the same trace_manager/span_exporter/span_collector/logs_exporter wiring UiPathEvalRuntime.__init__ sets up - unlike the earlier tests, this one fails if flush_spans() were removed from _get_and_clear_execution_data. - Document, in both the test module docstring and the fix's own comment, that the flush is a snapshot barrier: it closes the race for a span that has already ended by read time, but not for one belonging to a task that is still running at that point - there is no handle to await such a task, and closing that fully is a separate, larger change. Co-Authored-By: Claude Sonnet 5 <[email protected]>
1 parent ea96b4d commit 7552722

2 files changed

Lines changed: 82 additions & 6 deletions

File tree

packages/uipath/src/uipath/eval/runtime/runtime.py

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -973,9 +973,13 @@ def _get_and_clear_execution_data(
973973
# Force a flush right before reading: the flush triggered by the root
974974
# execution span ending only exports spans whose on_end() had already
975975
# fired by that moment. A tool-call span that finishes a beat later
976-
# (e.g. a detached background task) would otherwise still be sitting
977-
# in the batch processor's queue and be silently missing from
978-
# AgentRunHistory (UV-16309).
976+
# (e.g. a short-lived background task) would otherwise still be
977+
# sitting in the batch processor's queue and be silently missing from
978+
# AgentRunHistory (UV-16309). This is a snapshot barrier, not a full
979+
# closure: a span belonging to a task that is still running (hasn't
980+
# called on_end() yet) when this flush runs is still missed - closing
981+
# that would require the runtime to track and await such tasks before
982+
# this point, which is out of scope for this fix.
979983
self.trace_manager.flush_spans()
980984
spans = self.span_exporter.get_spans(execution_id)
981985
self.span_exporter.clear(execution_id)

packages/uipath/tests/cli/eval/test_execution_span_race.py

Lines changed: 75 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -15,19 +15,38 @@
1515
"next flush" sees a real, completed tool call as if it never happened -
1616
exactly the "history genuinely exists but AgentRunHistory is empty,
1717
intermittently" symptom.
18+
19+
The fix in `_get_and_clear_execution_data()` adds one more flush right before
20+
the read, which closes the race for any span that has *already ended* by
21+
read time - the common case, e.g. a tool call wrapped in a short-lived
22+
background task. It does NOT close the race for a span belonging to a truly
23+
detached task that is still running (has no `on_end()` yet) when the read
24+
happens - there is no handle for the runtime to await in that case, and
25+
closing it would require tracking/awaiting such tasks, which is a separate,
26+
larger change than this one-line flush.
1827
"""
1928

29+
import json
30+
2031
from opentelemetry import trace
2132
from opentelemetry.sdk.trace import TracerProvider
2233

34+
from uipath.core.tracing import UiPathTraceManager
2335
from uipath.eval._execution_context import ExecutionSpanCollector
2436
from uipath.eval._helpers.evaluators_helpers import trace_to_str
25-
from uipath.eval.runtime._exporters import ExecutionSpanExporter, ExecutionSpanProcessor
37+
from uipath.eval.runtime._exporters import (
38+
ExecutionLogsExporter,
39+
ExecutionSpanExporter,
40+
ExecutionSpanProcessor,
41+
)
42+
from uipath.eval.runtime.runtime import UiPathEvalRuntime
2643

2744
EXECUTION_ID = "exec-race-1"
2845

2946

30-
def _make_processor() -> tuple[ExecutionSpanProcessor, ExecutionSpanExporter, trace.Tracer]:
47+
def _make_processor() -> tuple[
48+
ExecutionSpanProcessor, ExecutionSpanExporter, trace.Tracer
49+
]:
3150
exporter = ExecutionSpanExporter()
3251
collector = ExecutionSpanCollector()
3352
processor = ExecutionSpanProcessor(exporter, collector)
@@ -120,7 +139,10 @@ def test_race_produces_empty_agent_run_history_for_a_real_tool_call() -> None:
120139
attributes={
121140
"execution.id": EXECUTION_ID,
122141
"tool.name": "search",
123-
"input.value": {"query": "uipath"},
142+
# input.value/output.value are OTel span attributes: they must be
143+
# primitive/sequence-of-primitive values, so real spans always
144+
# carry a JSON-encoded string here, never a raw dict.
145+
"input.value": json.dumps({"query": "uipath"}),
124146
"output.value": "42 results",
125147
},
126148
):
@@ -141,3 +163,53 @@ def test_race_produces_empty_agent_run_history_for_a_real_tool_call() -> None:
141163
agent_run_history_after_flush = trace_to_str(exporter.get_spans(EXECUTION_ID))
142164
assert "Tool: search" in agent_run_history_after_flush
143165
assert "42 results" in agent_run_history_after_flush
166+
167+
168+
def test_get_and_clear_execution_data_flushes_before_reading() -> None:
169+
"""Exercises the actual production method, not just a standalone processor.
170+
171+
Builds the same trace_manager/span_exporter/span_collector/logs_exporter
172+
wiring UiPathEvalRuntime.__init__ sets up, then calls the real
173+
`_get_and_clear_execution_data` (unbound, via the class) against it. This
174+
fails without the `flush_spans()` line in that method - removing that
175+
line reproduces the empty-AgentRunHistory bug here directly, not just in
176+
the lower-level exporter tests above.
177+
"""
178+
trace_manager = UiPathTraceManager()
179+
span_exporter = ExecutionSpanExporter()
180+
span_collector = ExecutionSpanCollector()
181+
span_processor = ExecutionSpanProcessor(span_exporter, span_collector)
182+
trace_manager.add_span_processor(span_processor)
183+
logs_exporter = ExecutionLogsExporter()
184+
185+
fake_runtime = type(
186+
"FakeEvalRuntime",
187+
(),
188+
{
189+
"trace_manager": trace_manager,
190+
"span_exporter": span_exporter,
191+
"span_collector": span_collector,
192+
"logs_exporter": logs_exporter,
193+
},
194+
)()
195+
196+
tracer = trace_manager.tracer_provider.get_tracer("test")
197+
with tracer.start_as_current_span(
198+
"root", attributes={"execution.id": EXECUTION_ID}
199+
):
200+
pass
201+
# Root span's own flush (mirrors start_execution_span's finally block)
202+
# happens before the late tool call below - only the tool call is at risk.
203+
trace_manager.flush_spans()
204+
205+
with tracer.start_as_current_span(
206+
"tool_call",
207+
attributes={"execution.id": EXECUTION_ID, "tool.name": "search"},
208+
):
209+
pass
210+
211+
spans, _logs = UiPathEvalRuntime._get_and_clear_execution_data(
212+
fake_runtime, EXECUTION_ID
213+
)
214+
215+
assert {s.name for s in spans} == {"root", "tool_call"}

0 commit comments

Comments
 (0)