偶发：platform-llm 追踪测试在 CI 上捕获不到 llm.request span（provider_span_preserves_upstream_errors_and_closes_on_cancellation） #512

New Issue

2026-09-24T18:09:27+08:00

suzmii commented

2026-09-24 18:09:27 +08:00

现象

PR #507 的 CI run 2900（sha 8514f109）里 job「AI game creator shell Rust crates」失败：

panicked at crates/platform-llm/src/observability_tests.rs:98
assertion `left == right` failed  left: 0  right: 1
test result: FAILED. 160 passed; 1 failed; 0 ignored

断言位置是 Capture::provider_span() 中的 assert_eq!(provider_spans.len(), 1)：一个名为 llm.request 的 span 都没被捕获到（0 个）。

run：https://git.genarrative.world/git/GenarrativeAI/Genarrative/actions/runs/2900 （job id 15877，2026-09-24T08:34:03Z）
同一个 job 在后一个新 head（run 2909 / sha 997eba2b）同一测试通过 → 偶发，不是稳定失败。

定位

server-rs/crates/platform-llm/src/observability_tests.rs:293-333（provider_span_preserves_upstream_errors_and_closes_on_cancellation）：

测试用 per-future with_subscriber(tracing_subscriber::registry().with(capture.clone())) 采集 span，本地 TCP fixture 在另一个线程里服务请求。
流程是：起请求（Box::pin(fixture.client.run(request()))）→ tokio::select! 等 fixture 线程发出的 entered 信号 → 立刻断言 span 已存在、未关闭 → drop(future) 取消 → 释放 fixture → 收尾断言。
entered 的语义只是「fixture 收到了请求」，而 span 由被测代码在请求路径上建立。CI 上同时跑 8 个 lane、机器负载高时，主测试任务可能在 span 建立之前就先观察到 entered 并执行断言，于是 provider_spans.len() == 0。
同一文件里 provider_span_covers_awaited_execution_and_keeps_parent_without_arguments 与 stream_callbacks_inherit_provider_span_and_keep_result 用的是同一模式，理论上有同样风险。

复现状态

本地连续 3 次跑整个 cargo test -p platform-llm --lib（161 tests、默认并行）均全绿，单机无法稳定复现；CI 上表现为负载相关的时序问题。

影响

CI 偶发红灯，PR 需要重跑、误导评审结论（本次就出现了「同一 job 在新 head 上直接通过」的情况）。
产品行为无影响，属测试脆弱性。

建议修法（任选其一）

断言前等 span 就绪：把 capture.provider_span() 换成带超时的轮询（例如 200ms 内每 5ms 检查），超时才失败，并在失败信息里带上已捕获的 span 名称，便于下次一眼看出是「没建立」还是「名字变了」。
合并信号语义：让 fixture 的 entered 改在「请求已进入被测代码且 span 已建立」之后才发出（例如由被测路径上的 hook/一次性哨兵触发），断言时就不存在这个窗口。
收窄抢占窗口：确认是调度时序后，可把该测试固定到单线程 runtime（#[tokio::test(flavor = "current_thread")]），或在释放 fixture 前先让出执行权。

验收

本地连续 20 次 cargo test -p platform-llm --lib（默认并行）全绿。
CI 上「AI game creator shell Rust crates」job 不再出现该偶发失败（连续若干次 run 观察）。

相关（同类偶发，未在本 issue 处理）

run 2906（master a07bff85）job「AI game creator shell Rust lane 1/2」：src/command_exec.rs:3409 的测试在 shard 跑满 200.1s 后失败（[rust-shards] shard 1/4 FAILED ... in 200.1s）——同类时间敏感/超时脆弱，建议单独跟踪。

## 现象 PR #507 的 CI run 2900（sha `8514f109`）里 job「AI game creator shell Rust crates」失败： ``` panicked at crates/platform-llm/src/observability_tests.rs:98 assertion `left == right` failed left: 0 right: 1 test result: FAILED. 160 passed; 1 failed; 0 ignored ``` 断言位置是 `Capture::provider_span()` 中的 `assert_eq!(provider_spans.len(), 1)`：一个名为 `llm.request` 的 span 都没被捕获到（0 个）。 - run：https://git.genarrative.world/git/GenarrativeAI/Genarrative/actions/runs/2900 （job id 15877，2026-09-24T08:34:03Z） - 同一个 job 在后一个新 head（run 2909 / sha `997eba2b`）**同一测试通过** → 偶发，不是稳定失败。 ## 定位 `server-rs/crates/platform-llm/src/observability_tests.rs:293-333`（`provider_span_preserves_upstream_errors_and_closes_on_cancellation`）： - 测试用 per-future `with_subscriber(tracing_subscriber::registry().with(capture.clone()))` 采集 span，本地 TCP fixture 在另一个线程里服务请求。 - 流程是：起请求（`Box::pin(fixture.client.run(request()))`）→ `tokio::select!` 等 fixture 线程发出的 `entered` 信号 → **立刻**断言 span 已存在、未关闭 → `drop(future)` 取消 → 释放 fixture → 收尾断言。 - `entered` 的语义只是「fixture 收到了请求」，而 span 由被测代码在请求路径上建立。CI 上同时跑 8 个 lane、机器负载高时，主测试任务可能在 span 建立之前就先观察到 `entered` 并执行断言，于是 `provider_spans.len() == 0`。 - 同一文件里 `provider_span_covers_awaited_execution_and_keeps_parent_without_arguments` 与 `stream_callbacks_inherit_provider_span_and_keep_result` 用的是同一模式，理论上有同样风险。 ## 复现状态本地连续 3 次跑整个 `cargo test -p platform-llm --lib`（161 tests、默认并行）均全绿，单机无法稳定复现；CI 上表现为负载相关的时序问题。 ## 影响 - CI 偶发红灯，PR 需要重跑、误导评审结论（本次就出现了「同一 job 在新 head 上直接通过」的情况）。 - 产品行为无影响，属测试脆弱性。 ## 建议修法（任选其一） 1. **断言前等 span 就绪**：把 `capture.provider_span()` 换成带超时的轮询（例如 200ms 内每 5ms 检查），超时才失败，并在失败信息里带上已捕获的 span 名称，便于下次一眼看出是「没建立」还是「名字变了」。 2. **合并信号语义**：让 fixture 的 `entered` 改在「请求已进入被测代码且 span 已建立」之后才发出（例如由被测路径上的 hook/一次性哨兵触发），断言时就不存在这个窗口。 3. **收窄抢占窗口**：确认是调度时序后，可把该测试固定到单线程 runtime（`#[tokio::test(flavor = "current_thread")]`），或在释放 fixture 前先让出执行权。 ## 验收 1. 本地连续 20 次 `cargo test -p platform-llm --lib`（默认并行）全绿。 2. CI 上「AI game creator shell Rust crates」job 不再出现该偶发失败（连续若干次 run 观察）。 ## 相关（同类偶发，未在本 issue 处理） - run 2906（master `a07bff85`）job「AI game creator shell Rust lane 1/2」：`src/command_exec.rs:3409` 的测试在 shard 跑满 200.1s 后失败（`[rust-shards] shard 1/4 FAILED ... in 200.1s`）——同类时间敏感/超时脆弱，建议单独跟踪。

suzmii added the Kind/Testing Kind/Bug

Priority

Medium

3

labels 2026-09-24 18:09:27 +08:00

Sign in to join this conversation.

1 Participants

Notifications

Due Date

No due date set.

Dependencies

No dependencies set.

Reference: GenarrativeAI/Genarrative#512