Skip to content

test: 修掉 3 个对主机负载和文件锁敏感的测试断言(Windows CI 偶发假红) - #3152

Merged
ranxianglei merged 2 commits into
masterfrom
2026-10-14_fix-3147-ci-flaky-tests
Oct 14, 2026
Merged

ranxianglei merged 2 commits into
masterfrom
2026-10-14_fix-3147-ci-flaky-tests

Conversation

@ranxianglei

Copy link
Copy Markdown
Owner

Closes #3147

修什么

三个测试的断言对 Windows CI runner 的「主机负载 / 文件锁」过于敏感:runner 高负载或 AV/索引器活跃时表现为假红(按 #3029 设计,具体断言失败不自动重试,需人工 rerun)。三者都是既有脆弱点被当天 runner 抖动打穿,与 #3145 内容无关(已核对其 diff:仅 CI 分片脚本)。

三处修法(全部测试层,零服务端语义改动)

A. fork-nudge-deadzone — 日志读竞态
原实现在响应返回后立即一次性 readFileSync(bili.log),与 logger 的异步追加流(src/logger.ts createWriteStream)竞态——负载高时响应先于日志落盘返回。改为有界轮询(5s 上限、50ms 间隔)等子会话 nudge 行出现;写流保序,nudge 行可见则同请求更早的行(含任何 preflight warn)必可见,负向断言(doesNotMatch preflight compressing)保持 sound。牙口不变:行为真回归时轮询超时照样 fail。

B. storage-engine-proofs / golden-storage-drive — teardown EPERM(#2908 族复发)

  • scratch 目录从 os.tmpdir()(Windows 即 %TEMP%\golden-<wire>-*,AV/索引器热路径,且被 c=4 全部 leg 共享互相抬升外部锁概率)挪到 <repo>/tmp/golden-drive/(gitignored 工作区本地路径)。机制层面:预算放宽(test(windows): driveWire golden-harness 清理期 index.db EBUSY 复发(#2799 族,#2808 后残留) #2908)已被两次复发证明治标,离开热路径才是源头。
  • teardown 清理降级 best-effort:所有断言先于清理完成,外部锁即使超出 ~9.8s rmrf 阶梯也只 console.warn + 留 inert gitignored 残留,不再把绿 run 打成红;模块下次 import 时清扫 >6h 残留。
  • 根因部分(本地验证时发现):startServer 无条件配置 tee logger,其文件流在整个进程生命周期指向 tmp 树内——删除后任何后续 log 行都会触发 getStream() 的孤儿 inode 检测并 REOPEN 被删路径,在 rmrf 中途复活目录树(test: teardown rmSync ENOTEMPTY race — most test cleanups lack retry options (CI ubuntu-latest Node 22 flake) #1646/release v0.1.180 #1910 ENOTEMPTY/EBUSY 竞态族;本地观察到的残留 billion-context/bili.log 即此产物)。现 rmrf 前执行 store.cancelAll() + closeLogger() + configureLogger("off")(同步调用、无交错窗口),切断全部进程内复活路径。残留观察:极端情况下 persist 管线内部异步 writer 仍可能复活单个 session 文件(~14KB,inert)——由 best-effort+sweep 设计吸收;不为此动 src/persist.ts 生产路径。

C. preflight-hold — 绝对墙钟余量
原断言 tHeaderMs < SLOW_MS(1500ms) 是绝对上界——负载下事件循环 stall 几百 ms 就吃光固定余量(本次实测 1724ms),但行为本身正确(#568 early-commit 成立)。stream 与 non-stream JSON 两腿均改为相对不变量(断言消息本来就在说的):头必须早于 mock 汇总调用的实际完成时刻到达——mock 在回调内记录真实完成时间戳(同进程时钟,与 timedPost 的 t0 直接可比)。牙口核对:#568 若回归(不再 early-commit),头在流结束才到、必然晚于汇总完成 → 照样抓得住。下界 tEndMs >= SLOW_MS 不动。

行为变更披露(旧 → 新)

位置 旧 新 原因
A 日志读取 一次性 readFileSync,缺行立即 fail 有界轮询 ≤5s,超时 fail 消刷盘竞态假红;牙口不变
B scratch 位置 os.tmpdir()/golden-<wire>-* <repo>/tmp/golden-drive/<wire>-*(gitignored) 离开 %TEMP% AV 热路径
B 清理失败 throw → 整腿红 console.warn + inert 残留(>6h 自动扫) 断言先于清理;外部锁时长不可控
B 清理前置 无 cancelAll+closeLogger+configureLogger("off") 切断 logger/store 进程内复活竞态(#1646/#1910 族)
C 头上界 绝对 <1500ms 相对 <实测汇总完成时刻 均匀 stall 不再吃余量;真回归仍被抓

验证

rebased head 096931d9c(master 42881c6,含 #3145):typecheck clean;定向本地 fork-nudge-deadzone 3/3、preflight-hold 4/4、tmp-rm 6/6(ladder pin 未动)、storage-engine-proofs 12/12、golden-storage-render 5/5(golden 摘要稳定,tests/golden/* 零变更;后两者在 rebase 前运行,rebase 窗口的 master 新提交只新增 tests/storage-save-path.test.ts,不触碰本 PR 文件及其依赖)。全量判定交远程 CI。Windows EPERM 本地无法复现(Linux 无 AV 争用),最终确认看后续若干 win-latest leg 是否还复发。

A: fork-nudge-deadzone lane proof read bili.log once via readFileSync right
   after the response returned, racing the logger's async append stream
   (src/logger.ts createWriteStream) — under a loaded Windows runner the nudge
   line had not flushed yet and the assertion false-red'd. Bounded poll (5s,
   50ms ticks) until the session's nudge line lands; write-order keeps the
   negative assertion sound. Teeth unchanged (timeout fails the same way).
B: golden-storage driveWire scratch moved out of os.tmpdir() into the
   gitignored workspace-local tmp/golden-drive/ — on Windows hosted runners
   %TEMP% is an AV/indexer hot path shared by all c=4 legs, and external
   locks there repeatedly outlasted the ~9.8s rmrf ladder (#2908 family).
   Teardown cleanup is now best-effort (warn + inert leftover, swept >6h old
   on next import) since every assertion precedes it. Root-cause part: the
   tee logger (configured unconditionally by startServer) held a file stream
   into the deleted tree — any later log line made getStream() reopen the
   orphaned path and resurrect the tree mid-rmrf (#1646/#1910 race class);
   closeLogger()+configureLogger("off")+store.cancelAll() now run before
   rmrf so no in-process writer can recreate it.
C: preflight-hold asserted an absolute wall-clock bound (tHeaderMs < SLOW_MS
   = 1500ms) — a loaded runner stalls the event loop and eats the fixed
   margin while the behavior stays correct (observed 1724ms). Both stream
   and non-stream legs now assert the relative invariant the message always
   claimed: headers arrived BEFORE the mock's actual summarization completion
   (timestamped in-mock, same clock). A #568 regression (no early commit)
   lands headers at stream end, i.e. after summarization finished — still
   caught. Lower bound tEndMs >= SLOW_MS untouched.

Targeted local: fork-nudge-deadzone 3/3, preflight-hold 4/4,
storage-engine-proofs 12/12, golden-storage-render 5/5, tmp-rm 6/6,
typecheck clean. Full-suite verdict: remote CI.
@github-actions

github-actions Bot commented Oct 14, 2026 •

Copy link
Copy Markdown
Contributor

📦 Built Package Artifact

Branch: 2026-10-14_fix-3147-ci-flaky-tests (3cc42ef)

Option A — Install this exact build (recommended)

npm install -g billion-context@0.0.3595-pr.3152.d0a8d5f

This exact version is immutable and reproducible. The rolling pr tag tracks the newest test build across all PRs.

Option B — Download artifact

  1. Download the artifact from the Actions run
  2. Extract the tarball and install:
tar xzf billion-context-pr3152.tgz
npm install -g package

Install instructions are refreshed on each push.

@ranxianglei

Copy link
Copy Markdown
Owner Author

🤖 Powered by ework · qwen3.8-27b

(ai: vllm-qwen/qwen3.8-27b)

本 [PR] 是另一会话已完成的工作(#3147 floors 2–3),不重做。我独立拉取 head 3cc42efa4(已并入最新 master 3aeddc160,merge-base 即 master 头,base 新鲜、mergeable=true)逐文件审完:diff 共 3 个测试文件、+86/−8,零 src 改动,与描述一致。CI(head 上):29 项已过全绿 / 10 进行中 / 1 排队,尚无红(含 win-latest 分片)。

独立核对结论(对照源码验证,非复读 PR 描述):

  • A:logger 文件腿确为异步追加流(src/logger.ts createWriteStream(flags:"a") + 缓冲 s.write()),响应先于落盘返回的窗口真实存在;轮询读路径 join(h.dir,"billion-context","bili.log") 与 defaultLogFile()=stateDir()/bili.log(drive/fork 套件 XDG_STATE_HOME 指向该树)一致。负向断言 soundness 成立:preflight warn(若有)在同一请求流水线中先于 nudge 行落笔,追加流保序 ⇒ nudge 行可见则更早行必可见。牙口不变:真回归时轮询 5s 超时照样 fail。
  • B:根因机制实锤——startServer 无条件 configureLogger(opts.logFile ?? defaultLogFile())(src/server.ts:435),drive 套件的日志流整个进程生命周期指向 tmp 树;删除后任何 log 行走 getStream() 孤儿 inode 检测(src/logger.ts:193-203)+ openStream 的 mkdirSync(recursive)(src/logger.ts:153-154),确会在 rmrf 中途复活目录树(test: teardown rmSync ENOTEMPTY race — most test cleanups lack retry options (CI ubuntu-latest Node 22 flake) #1646/release v0.1.180 #1910 族)。三件套切断均同步无交错:SessionStore.cancelAll() 存在(src/persist.ts:1469);closeLogger() 先同步 detach 且 promise 无 reject 路径(fire-and-forget 安全);configureLogger("off") 同步清 logPath+stream。tmp-rm.ts 零改动(ladder pin 未动);tmp/ 在 .gitignore(line 7);>6h sweep 只按 mtime 删陈旧目录,并发在跑的新目录不受影响;唯一两个消费方(storage-engine-proofs / golden-storage-render)的下一次 driveWire 会经 startServer 重新配置 logger,"off" 无跨测试副作用。
  • C:SLOW_MS=1500 与下界 tEndMs >= SLOW_MS 未动;全文件 grep 确认 tHeaderMs 只出现在被改的两腿,429 Responses 腿本无绝对上界断言,无遗漏。牙口核对:Preflight compression holds the request with zero response bytes; client undici headersTimeout (default 300s) kills it -> repeated [preflight] summarization aborted: client disconnected 5-minute death loop, payload never forwarded #568 回归(不再 early-commit)时客户端不可能早于服务端 writeHead 收到字节,tHeaderMs >= summaryDoneMs - t0 恒成立,严格 < 在同毫秒边界也照样红。
  • 回归清点(触碰路径的既有行为):fork-nudge lane proof 的三个断言(nudge 存在 / dead-zone 签名消失 / 不落 preflight)全部保留,仅读取时机从「响应后立即」挪到「nudge 行落盘后」——严格更晚、视图严格更全,无弱化;golden 两套件的 wire/state digest 断言与归一化(<PORT>/<SID>)未触碰,tests/golden/* 零变更(diff 确认);preflight-hold 其余子测试(429 腿、keep-alive/内容断言)原文保留。
  • diff 整洁度:1 个内容 commit + 1 个 merge master commit,每行都与目的相关,无跑题文件、无空白重排。

结构化八问:

  1. 是什么问题:三个测试的断言把「runner 环境抖动」误判为「行为回归」——日志刷盘竞态、teardown 撞外部文件锁、绝对墙钟余量被吃光——表现为 Windows test 腿偶发假红 + 人工 rerun 成本。
  2. 什么原因导致的:根因层是测试假设 runner 永远空闲且无锁。A=异步刷盘与一次性读取之间无同步点;B=%TEMP% AV/索引器热路径 × c=4 共享,外部锁时长可超任何固定重试预算,test(windows): driveWire golden-harness 清理期 index.db EBUSY 复发(#2799 族,#2808 后残留) #2908 两次复发已证明放宽预算治标;另有进程内复活机制(logger/store 删除后 REOPEN 被删路径)使自持句柄类修复全部失效;C=固定余量对比均匀事件循环 stall。
  3. 影响范围与严重程度:仅 CI 效率(Windows 腿概率性假红、fleet 重跑成本);触发条件=runner 高负载/AV 活跃;ubuntu 基本不受影响。无产品影响,严重度=效率瑕疵。
  4. 怎么修复的:A 一次性读→有界轮询(≤5s/50ms tick);B scratch 挪出 %TEMP% 到 gitignored 工作区本地路径 + 清理降级 best-effort(warn+惰性残留+import 时扫 >6h)+ rmrf 前同步切断进程内复活源;C 绝对上界→相对不变量(mock 记录汇总调用真实完成时刻,断言头早于它到达)。
  5. 是否有回归问题:无。零服务端改动;golden digest 稳定;tmp-rm ladder 未动;preflight 下界及其余子测试保留;唯一语义变化(清理失败 throw→warn)为有意变更且已在 PR 披露旧→新。已知残留:极端情况下 persist 管线内部异步 writer 仍可能复活单个 ~14KB inert session 文件——由 best-effort+sweep 吸收,不动 src/persist.ts 生产路径,取舍合理。
  6. 是否破坏缓存:不涉及(纯测试 harness 路径)。
  7. 是否改了设计方向:无架构转向。B 的方向从「加大重试预算硬扛外部锁」转为「离开锁源 + 清理失败不再致命」,是疏不是堵;A/C 把断言从「对环境假设」改写为「对行为的不变量」,与 CI flake:test (windows-latest, 24) 单文件文件级失败:子测试零执行、异常被吞为 'test failed' #3029 的可归因哲学一致。
  8. 是否引入新配置:无新 env/config/CLI。唯一持久痕迹:gitignored 的 <repo>/tmp/golden-drive/(CI worktree 随 run 销毁,dev 机 >6h 自动扫)。

判定:审核通过,可合并——方向正确、机制经独立代码级验证成立、牙口不降、无回归;等 CI 全绿即可合。Windows EPERM 的最终确认留给后续若干 win-latest 腿观察(本地 Linux 无法复现,属预期)。

另发现一处非阻塞的同族残留,已按粒度规则记入 #3147 作后续清单项(同症状同机制域,不单独立项):tests/fork-nudge-deadzone.test.ts:36-37 的 testRoot 仍在 os.tmpdir() 且 teardown 用裸 rmSync(无重试阶梯),B 类外部锁打穿它的条件尚未出现但机制域相同。

@ranxianglei
ranxianglei merged commit 51aa9f1 into master Oct 14, 2026
40 checks passed
@github-actions

Copy link
Copy Markdown
Contributor

📦 Merged Build Published

This merge to master was published as 0.0.411-master.51aa9f1 (rolling master tag).

npm install -g billion-context@0.0.411-master.51aa9f1  # this exact build
npm install -g billion-context@master  # always the newest merged build

npm view billion-context@master prints the current version at any time.

@ranxianglei
ranxianglei deleted the 2026-10-14_fix-3147-ci-flaky-tests branch October 15, 2026 05:33
RodrigoHamuy pushed a commit to RodrigoHamuy/billion-context that referenced this pull request Oct 15, 2026
Replace the absolute 'tHeaderMs < SLOW_MS' (SLOW_MS=1500) wall-clock bound in the wire-exit early-commit tests with a relative invariant ('tHeaderMs < summaryDoneMs - t0', both timestamps on the same process clock). The absolute bound flakes under CI runner load whenever the event loop stalls >1500ms before the mock's summarization timer fires; the relative form is load-invariant and still catches a true regression (headers committed after summarization completes/fails). Mirrors the ranxianglei#3147-C fix already merged in preflight-hold.test.ts (ranxianglei#3152) and covers the residual instances in wire-exit-matrix.test.ts and wire-exit-gap-cells.test.ts surfaced by class scan.

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

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Windows CI 测试腿偶发假红:3 个测试的断言对主机负载和文件锁太敏感

1 participant