Skip to content

Test/uv 16309 span flush race + fix - #1901

Open
TeodorEscuUiPath wants to merge 9 commits into
mainfrom
test/uv-16309-span-flush-race
Open

TeodorEscuUiPath wants to merge 9 commits into
mainfrom
test/uv-16309-span-flush-race

Conversation

@TeodorEscuUiPath

@TeodorEscuUiPath TeodorEscuUiPath commented Sep 16, 2026

Copy link
Copy Markdown
Contributor

Proposed fix for two related intermittent/empty AgentRunHistory cases.

1. Genuine tool calls, empty history (intermittent — the async export race)

ExecutionSpanProcessor.on_end() queues spans, while ExecutionSpanExporter.get_spans() only sees spans flushed through export(). The root-span flush can therefore run before a slightly-late tool-call span is queued—for example, when a detached/background task outlives delegate.execute()—leaving the completed span missing when _get_and_clear_execution_data() reads the trace. This timing race would explain the intermittent behavior.

On test/uv-16309-span-flush-race:

  • 611fe7da adds a real-OTel reproduction.
  • 1bdff0c3 flushes immediately before reading execution data.

This closes the race for a span that has already ended by read time (the common case). It does not close it for a span belonging to a task that's still running when the flush happens — there's no handle for the runtime to await in that case, and doing so would be a separate, larger change. Documented in the fix's own comment.

2. Zero tool calls, empty history (deterministic — the "no-tool" corner case)

trace_to_str() only ever renders spans carrying tool.name, so a run where the agent answered in plain text and made no tool calls at all produced an empty AgentRunHistory — not because nothing happened, but because there was nothing tool-shaped to render. This matches the ticket's "AgentRunHistory omits the agent's own text responses, causing false 0s (empty) or unearned high scores (non-empty)" description.

  • 37cb0f1e makes LegacyTrajectoryEvaluator and LLMJudgeTrajectoryEvaluator fall back to WorkloadExecution.workload_output (the agent's actual final answer, independent of the trace) whenever there were no tool-call spans to render.
  • ea96b4d4 adds the repro/verification test.

Review follow-ups

  • 75527225: fixed an invalid dict-valued span attribute in the repro test, and added a test that exercises the real _get_and_clear_execution_data() method directly (verified it fails if the fix line is removed).
  • 54eeb5e9: pinned the test processor's batch schedule delay so the real background BatchSpanProcessor worker thread can't introduce flakiness.

The local eval suite passes with both fixes. Please verify or challenge the mechanism before relying on it — not yet peer-reviewed, no PR merge intended until then.

TeodorEscuUiPath and others added 2 commits September 10, 2026 17:36
ExecutionSpanProcessor is a real OTel BatchSpanProcessor: on_end() only
queues a span, export() (which feeds ExecutionSpanExporter.get_spans(),
read by trace_to_str() to build AgentRunHistory) only sees spans already
flushed. Production flushes when the root execution span ends, but a
tool-call span that genuinely finishes a beat later (e.g. a detached
background task) is queued but not yet exported at that point - so a read
taken before the next flush sees a real, completed tool call as if it
never happened. Reproduces the exporter-level race, ties it to
trace_to_str() producing an empty AgentRunHistory for a real tool call,
and shows a flush immediately before the read closes the race.

Co-Authored-By: Claude Sonnet 5 <[email protected]>
_get_and_clear_execution_data() read ExecutionSpanExporter.get_spans()
without first flushing the batch span processor. The flush triggered by
the root execution span ending only exports spans whose on_end() already
fired by that moment, so a tool-call span finishing a beat later (e.g. a
detached background task) could still be queued, unexported, and missing
from AgentRunHistory when the evaluator reads the trace (UV-16309).

Force a flush immediately before the read so every span that has ended
by then is guaranteed to be exported first.

See UV-16309 and the repro test in
test/uv-16309-span-flush-race (test_execution_span_race.py).

Co-Authored-By: Claude Sonnet 5 <[email protected]>
Copilot AI lite review requested due to automatic review settings September 16, 2026 10:02
@github-actions github-actions Bot added test:uipath-langchain Triggers tests in the uipath-langchain-python repository test:uipath-integrations labels Sep 16, 2026

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

The production path lacks direct coverage, late spans may still be missed, and the race test is not deterministic.

Get a fresh assessment by requesting another Copilot review.

Pull request overview

This PR addresses intermittent missing tool-call spans in AgentRunHistory by flushing OpenTelemetry spans before collecting execution data.

Changes:

  • Adds OpenTelemetry race reproduction tests.
  • Flushes spans before reading and clearing execution data.
File summaries
File Description
packages/uipath/tests/cli/eval/test_execution_span_race.py Adds race and regression tests for span export behavior.
packages/uipath/src/uipath/eval/runtime/runtime.py Flushes spans before evaluation data collection.
Review details

Suppressed comments (3)

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

  • This flush is only a snapshot barrier: BatchSpanProcessor.force_flush() drains spans already queued when it runs. If the detached task described above ends after this call, its on_end() queues the span after the flush, and the following clear() can discard the execution's data without another flush. Please synchronize with or await execution-owned background tasks (or otherwise wait for their spans) before reading and clearing; this line alone does not close that race.
        self.trace_manager.flush_spans()

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

  • These tests call processor.force_flush() directly and never exercise _get_and_clear_execution_data(), so they would still pass if the new self.trace_manager.flush_spans() line were removed. Add a test through UiPathEvalRuntime (or a focused test of this method) that verifies the production read/clear path flushes the processor before get_spans().
    processor.force_flush()

    spans_at_read_time = exporter.get_spans(EXECUTION_ID)
    assert {s.name for s in spans_at_read_time} == {"root", "tool_call"}

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

  • input.value is an OpenTelemetry span attribute, and dict values are not valid attribute values; the SDK drops this field and logs an invalid-attribute warning. That makes the real-OTel reproduction noisy and loses the tool arguments from the history. Encode the value as a string, as the other evaluator span tests do.
            "input.value": {"query": "uipath"},
  • Files reviewed: 2/2 changed files
  • Comments generated: 2
  • Review effort level: Lite

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment thread packages/uipath/tests/cli/eval/test_execution_span_race.py
# (e.g. a detached background task) would otherwise still be sitting
# in the batch processor's queue and be silently missing from
# AgentRunHistory (UV-16309).
self.trace_manager.flush_spans()

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Agreed — added test_get_and_clear_execution_data_flushes_before_reading in 7552722. It builds the same trace_manager/span_exporter/span_collector/logs_exporter wiring UiPathEvalRuntime.__init__ sets up, then calls the real _get_and_clear_execution_data (unbound, via the class, against a duck-typed self). I verified it directly: temporarily removed the flush_spans() line locally, confirmed this new test fails ({'root'} == {'root', 'tool_call'}), then restored the line and confirmed it passes again.

TeodorEscuUiPath and others added 4 commits September 16, 2026 14:11
… called

trace_to_str() only ever renders spans carrying tool.name, so a run where
the agent answered in plain text and made zero tool calls produced an
empty AgentRunHistory - not because nothing happened, but because
trace_to_str had nothing tool-shaped to render. This hid the agent's real
final answer from both trajectory evaluators, matching UV-16309's
"AgentRunHistory omits the agent's own text responses, causing false 0s
(empty) or unearned high scores (non-empty)" description.

Both LegacyTrajectoryEvaluator and LLMJudgeTrajectoryEvaluator (via
BaseLLMTrajectoryEvaluator) now append WorkloadExecution.workload_output -
the agent's actual final answer, independent of the trace - whenever it's
non-empty, so the judge always sees what the agent answered.

Co-Authored-By: Claude Sonnet 5 <[email protected]>
Covers the deterministic corner case behind the async span-export race
fixed in 611fe7d/1bdff0c3: a run with zero tool-call spans left
AgentRunHistory silently empty for both trajectory evaluators, hiding the
agent's actual final answer. Verifies both LegacyTrajectoryEvaluator and
LLMJudgeTrajectoryEvaluator now fall back to workload_output in that case.

Co-Authored-By: Claude Sonnet 5 <[email protected]>
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]>
…kiness

Copilot review comment: ExecutionSpanProcessor is a real BatchSpanProcessor
with its own background worker thread, which auto-flushes every 5s by
default (or when its queue fills). Tests asserting "not yet exported at
this exact moment" could in principle flake if that worker thread woke up
and exported on its own between a span ending and the assertion running.

Push the processor's schedule delay to 1 hour right after construction so
only the explicit force_flush() calls in these tests ever export anything,
removing the wall-clock dependency entirely rather than relying on the
worker thread simply not winning the race in practice.

Co-Authored-By: Claude Sonnet 5 <[email protected]>
@github-actions

Copy link
Copy Markdown

🚨 Heads up: uipath-integrations cross-tests are FAILING 🚨

Your changes may break one or more integrations in uipath-integrations-python:

  • uipath-openai-agents
  • uipath-google-adk
  • uipath-agent-framework
  • uipath-llamaindex
  • uipath-pydantic-ai

⚠️ These checks are NOT enforced by branch protection rules. Please review the failures before merging.

🔍 Inspect the failed run →

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

Moderate unresolved issues remain in both evaluators and the span-race test.

Get a fresh assessment by requesting another Copilot review.

Review details

Suppressed comments (4)

packages/uipath/src/uipath/eval/evaluators/legacy_trajectory_evaluator.py:152

  • WorkloadExecution.workload_output explicitly allows dictionaries, so {} is a valid falsey final output. This truthiness check omits it from the legacy prompt, leaving a tool-free run without the final response section. Check against None instead of truthiness to preserve valid falsey outputs.
        if workload_output:

packages/uipath/src/uipath/eval/evaluators/legacy_trajectory_evaluator.py:156

  • As in the LLM-judge evaluator, this appends workload_output whenever it is truthy, including when the rendered history already contains tool calls. The stated fix is a no-tool fallback, so this silently changes existing legacy trajectory prompts and may duplicate or inflate them for normal tool runs. Please either restrict the append to empty rendered history or clarify and cover the intentional broader contract.
        if workload_output:
            final_output_section = f"Agent Final Response:\n{workload_output}"
            agent_run_history = (
                f"{agent_run_history}\n\n{final_output_section}"
                if agent_run_history

packages/uipath/src/uipath/eval/evaluators/llm_judge_trajectory_evaluator.py:93

  • WorkloadExecution.workload_output explicitly allows dictionaries, so {} is a valid falsey final output. In the no-tool case this branch skips it and _get_actual_output() still returns an empty string, leaving that valid output absent from the judge prompt. Use is not None so the optional parameter's None sentinel is distinguished from a falsey result.
        if final_output:

packages/uipath/src/uipath/eval/evaluators/llm_judge_trajectory_evaluator.py:97

  • The PR description scopes this change as a fallback for runs with no tool-call spans, but this condition appends workload_output even when history already contains tool calls. That changes every mixed/tool trajectory prompt (and can duplicate or substantially expand the input) rather than only fixing the empty-history case. Please either gate this on an empty rendered history or explicitly document and test the broader behavior; the correct choice is ambiguous from the stated scope.
        if final_output:
            final_output_section = f"Agent Final Response:\n{final_output}"
            history = (
                f"{history}\n\n{final_output_section}"
                if history
  • Files reviewed: 5/5 changed files
  • Comments generated: 1
  • Review effort level: Lite

Comment thread packages/uipath/tests/cli/eval/test_execution_span_race.py Outdated
Copilot review comment: test_get_and_clear_execution_data_flushes_before_reading
builds its own ExecutionSpanProcessor directly (not via _make_processor()),
so it had the same unpinned 5s default background-worker schedule and could
in principle auto-export tool_call on its own, passing even with the
flush_spans() fix removed.

Factor the schedule-pinning into a shared _pin_batch_schedule() helper and
apply it in both places.

Co-Authored-By: Claude Sonnet 5 <[email protected]>

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🔵 Needs a closer look

The span-race test must shut down its trace manager to prevent leaked processors and worker threads.

Review details

Suppressed comments (1)

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

  • This test creates a UiPathTraceManager, which registers a default BatchSpanProcessor and retains both processors in the global delegating processor, but it never shuts them down. The default worker thread therefore remains alive and the old processors stay attached to subsequent tests/jobs, potentially receiving and queuing unrelated spans. Wrap the test body in try/finally and call trace_manager.shutdown() so the processors are unregistered and their workers are stopped.
    trace_manager = UiPathTraceManager()
    span_exporter = ExecutionSpanExporter()
    span_collector = ExecutionSpanCollector()
    span_processor = ExecutionSpanProcessor(span_exporter, span_collector)
    _pin_batch_schedule(span_processor)
    trace_manager.add_span_processor(span_processor)
  • Files reviewed: 5/5 changed files
  • Comments generated: 0 new
  • Review effort level: Lite

Copilot review comment (2026-09-17): UiPathTraceManager() registers a
default batch span processor on the process-global delegating processor
and never unregisters it on its own. The test never called shutdown(), so
that processor and its background worker thread leaked into whatever ran
next in the same process.

Wrap the test body in try/finally and call trace_manager.shutdown().

Co-Authored-By: Claude Sonnet 5 <[email protected]>
@github-actions

Copy link
Copy Markdown

🚨 Heads up: uipath-langchain cross-tests are FAILING 🚨

Your changes may break the uipath-langchain-python integration.

⚠️ These checks are NOT enforced by branch protection rules. Please review the failures before merging.

🔍 Inspect the failed run →

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

Extract legacy evaluator output through the base helper to preserve target_output_key and attachment handling.

Get a fresh assessment by requesting another Copilot review.

Review details
  • Files reviewed: 5/5 changed files
  • Comments generated: 1
  • Review effort level: Lite

evaluation_prompt = self._create_evaluation_prompt(
expected_agent_behavior=workload_execution.expected_agent_behavior,
agent_run_history=workload_execution.workload_trace,
workload_output=workload_execution.workload_output,

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good catch. Fixed in 8dde043 — evaluate() now calls self._get_actual_output(workload_execution) instead of passing workload_execution.workload_output directly, so target_output_key extraction and job-attachment URI resolution both apply before the value reaches AgentRunHistory. Added a test (target_output_key="result", a multi-key output dict) that fails without this fix — it previously leaked the whole output object (including an unrelated key) into the prompt.

…utput()

Copilot review comment: evaluate() was passing workload_execution.workload_output
straight through, bypassing BaseLegacyEvaluator._get_actual_output() - the
existing path that applies target_output_key extraction and resolves
job-attachment URIs. A trajectory evaluator configured with a specific
target_output_key (e.g. "result") would therefore get the whole output
object, or an unresolved attachment URI, spliced into AgentRunHistory
instead of the agent's actual selected answer.

Added test_legacy_trajectory_evaluate_resolves_target_output_key_for_fallback,
verified it fails when evaluate() is reverted to use the raw field directly.

Co-Authored-By: Claude Sonnet 5 <[email protected]>
@sonarqubecloud

Copy link
Copy Markdown

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

test:uipath-integrations test:uipath-langchain Triggers tests in the uipath-langchain-python repository

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants