探针提速:硬等待 → 条件轮询(+ 并行化)
2026-09-23 · 起因:老大要「改完必测、但测试太慢,要加速」 本轮共交付三件事:1硬等待改条件轮询 2e2e 第 5.5 节改夹具预置 3探针并行化。
一、结论先行
| 项 | 数据 |
|---|---|
| 全项目硬等待总量 | 274 处、静态合计 555.9 秒(9.3 分钟) |
| 其中最高频的单一值 | waitForTimeout(9000) —— 21 处 |
| 实测「真正需要」的时长 | 562 ms |
| 1 每轮白等 | 约 8.4 秒 × 18 个探针 ≈ 3.3 分钟(单探针实测最多 -66.9%) |
| 2 e2e 第 5.5 节 | 省 60.8 秒(-16.9%),且 读档 · 日志簿一并还原 由红转绿 |
3 并行化(--jobs 2,软渲染) | 8 个探针 157.1s → 110.8s(-29.5%),断言与串行逐条一致 |
4 渲染后端统一 + --jobs 4(最终方案) | 157.1s → 50.5s(3.11 倍),且假红归零 |
| 验证结果 | 断言逐项一致,出图正常(像素标准差 65~72) |
一句话:那 9000ms 里有 8.4 秒是纯白等 —— 因为写它的人(包括当初的我)以为要"等世界装配",但 started 置位时世界早就装配完了。
🔴 一条同等重要的负面结论(后经修正)
并行不是越多越好:8 个探针实测 --jobs 4(软渲染)反而 比串行还慢 23%, 并把原本通过的 probe_log_dock 压成假红(4/8 → 3/8)。原因:软渲染吃 CPU, 4 路争抢 ⇒ 单探针耗时暴涨(38s→184s)⇒ 探针内依赖超时的断言来不及满足。
但修正后结论是:--jobs 4 配上 硬件渲染(PROBE_RENDER=d3d11)后 50.5s、零假红 —— 所以不是"不能用 4 路",而是"4 路必须配硬件渲染"。 详见 docs/探针并行化.md。
二、核心发现:9000ms 为什么是白等
web/frontend/src/main.js 的真实顺序:
world.onProgress = ...;
const stats = await world.assemble(manifest); // 597 ← 资产全部加载完
...
world.start(); // 610 ← 渲染循环启动
window.__game.started = true; // 611 ← 探针等的就是这一行
await refreshMap();
new BattleLayer({...});
net.connect();
setTimeout(() => hud.showLoading(false), 260); // 658 ← 此时才是 #loading.done
started = true 在 await world.assemble() 之后 ⇒ 那一刻资产已全部加载完。
实测印证(measure_started_gap.cjs):
t(started) = 4902 ms
t(loading.done) = 5464 ms
两者间隔 = 562 ms ← 9000ms 里真正需要的部分
started 时资产 = {"loaded":55,"failed":0} ← 已全部就绪
done 后资产/面 = {"loaded":55,"failed":0,"tris":946736}
⇒ 白等约 8438 ms / 探针
三、实测对照(改动前后)
3.1 probe_camera_front.cjs —— 严格对照
| 总耗时 | 断言 | |
|---|---|---|
改前(started + 9000ms) | 16585 ms | 10 通过 / 0 失败 |
改后(waitGameReady) | 5495 ms | 10 通过 / 0 失败 |
-11090 ms(-66.9%),且每个数值逐项相同: Δny=0.00e+0、Δnx=0.00e+0、ndc 宽度=1.893、城墙 39 段、段范围 x∈[-25.8,25.8] …
3.2 probe_world_dims.cjs —— 改 3000ms 死等
| 总耗时 | 输出 | |
|---|---|---|
改前(waitForTimeout(3000)) | 9215 ms | — |
改后(等 lib.stats.loaded 稳定 3 拍) | 6419 ms | 相机 / stats / 各组建数全部一致 |
-2796 ms(-30%)。
3.3 _diag_layer_attrib.cjs —— 逐字节对照(用 git 取旧版)
| 总耗时 | 输出 | |
|---|---|---|
改前(git show HEAD:...) | 17289 ms | — |
改后(waitGameReady) | 10783 ms | diff 无任何差异 ✅ |
-6506 ms(-37.6%),输出逐字节一致。
📌 这次对照还有一个额外作用:该探针的输出全是 0("草色总数 0"), 一开始怀疑是我改坏的 —— 用旧版一跑发现也是 0 ⇒ 属既有状态,与改动无关。 这就是"逐项 diff"的价值:它既证明改动安全,也帮你排除误判。
3.4 shot_ground.cjs —— 出图探针专项验证
出图探针的注释原先写着「读档后立刻截图会拍到空白画布(shader 还在编译)」,所以必须单独验:
| 检查项 | 结果 |
|---|---|
| 贴图判据 | map=true 图幅=2048px ✅ |
| 出图 | G2_ground_wide.png 1440×900 · 1130 KB ✅ |
| 像素标准差 | R 66.3 / G 65.4 / B 71.7 ⇒ 画面有内容,非空白 ✅ |
waitGameReady 内含 1.2s 首帧稳定窗口,正好覆盖"shader 还在编译"那段。
四、改了哪些文件
3.5 e2e.cjs —— 三段对照
| 阶段 | 总耗时 | 通过数 | 失败条目 |
|---|---|---|---|
| 1 基线 | 359495 ms | 85 / 97 | 12 条 |
| 2 硬等待改条件轮询后 | 360456 ms | 85 / 97 | 12 条,一字不差 |
| 3 再叠加 B 方案(夹具预置任务日志) | 298669 ms | 88 / 99 | 11 条 |
2 vs 1:+961 ms(+0.3%,属运行波动)⇒ 硬等待这条路对 e2e 无收益(详见 §5.2)。 ✅ 但对照的真正价值是:12 条失败条目一字不差 ⇒ 这批改动对 e2e 零回归。
3 vs 1:省 60826 ms(-16.9%) —— 来自把第 5.5 节那个写错的等待预算 换成夹具预置(详见 §5.2.1)。同时 读档 · 日志簿一并还原 从红转绿。
📌 顺带看清了 e2e 失败的性质:剩下 11 条里多数是 「攒料改造·武器铺营造按钮可用 :: 60 秒内未备齐」「研究武学 :: 等了 45 秒仍攒不出资源」 ——不是等待预算不够,而是判据本来就不满足(资源按 tick 产出,确实攒不出来)。 属于「这个脚本的设计前提在当前的 4 秒/tick 节奏下已不成立」,与本轮改动无关。
四、改了哪些文件
4.1 新增通用能力:_auth.cjs 的 waitUntil
const { waitUntil } = require('./_auth.cjs');
// 语义:轮询 pred 直到为真或超时(判据抛错 = 尚未满足,继续轮询)
await waitUntil(() => page.evaluate(() => /* 某判据 */), 3000 /* = 原来写死的值 */);
🔴 使用铁律:timeout 就填原来那个写死的值。 ⇒ 新写法的最坏情况 == 旧写法的固定耗时,绝不会比原来更慢; 判据早满足则提前返回(提速);判据写对了还更稳(原硬等待在慢机器上可能不够)。
⚠️ 只替换「等状态」的等待,别动「让动画走一拍」的节奏等待(后者本来就该等满)。
4.2 批量改造的 18 个探针
统一把
await page.goto(URL, { waitUntil: 'load' });
await page.waitForFunction(() => window.__game?.started === true, { timeout: 60000 });
await page.waitForTimeout(9000);
换成
await page.goto(URL, { waitUntil: 'load' });
await waitGameReady(page);
| # | 文件 | # | 文件 |
|---|---|---|---|
| 1 | probe_camera_front.cjs | 10 | _shot_asset_check.cjs |
| 2 | probe_taijie.cjs | 11 | _shot_member_bar.cjs |
| 3 | shot_ground.cjs | 12 | _shot_props_persp.cjs |
| 4 | _diag_canvas_scan.cjs | 13 | _shot_realm_palette.cjs |
| 5 | _diag_ground_overlap.cjs | 14 | _shot_shanmen_wall.cjs |
| 6 | _diag_layer_attrib.cjs | 15 | _shot_shibanlu_persp.cjs |
| 7 | _diag_paving_leak.cjs | 16 | _shot_style_cmp.cjs |
| 8 | _diag_paving_tiles.cjs | 17 | _shot_taijie_close.cjs |
| 9 | _diag_paving_topdown.cjs | 18 | _diag_pixel_world.cjs |
4.3 其它
| 文件 | 改动 |
|---|---|
e2e.cjs | 5 处 waitForTimeout(900) → 条件轮询(武器铺/议事厅浮窗、Sign out登录后等登录页) |
probe_boot_time.cjs | 加 PROBE_RENDER 开关 + 自报实际 WebGL 渲染器(防"以为在测硬件、实则在测软件") |
probe_world_dims.cjs | 同加 PROBE_RENDER 开关 |
五、🔴 顺带挖到的两个真问题
5.1 e2e.cjs:1489 的等待预算不够(真 bug)
body: JSON.stringify({ type: 'start_task', template_id: 'escort_silver_easy', duration: 12 }),
await control('resume');
await page.waitForTimeout(16000); // ← 只等 16 秒
await control('pause');
balance.json的tick.seconds_per_tick = 4⇒duration: 12息 = 48 秒真实时间- 而后端
engine.py:1952是duration = max(10, ...)⇒ 最少也是 40 秒 - 实际只等 16 秒 ⇒ 任务必然未结算 ⇒ 后面「日志里有任务汇报」断言必然为红
这正是 _auth.cjs 文件头警告的那类坑:
这个油门老大已经调过两次(09-201→2、09-212→4)… 漏改一个的症状不是老实报红, 而是"等待预算不够 ⇒ 断言挂 ⇒ 看着像产品坏了"。
1489 就是那个漏改的。 ⇒ 已报告,未擅自改(改法涉及测试语义,见 §6.1 待定项)。
5.2 e2e.cjs 的真相:硬等待不是大头,但有一处「等待预算写错」
e2e 一轮 359 秒(6 分钟),其中硬等待静态合计仅 68.2 秒——大头是"等真实作品时间":
| 大等待 | 时长 | 性质 |
|---|---|---|
等武器铺竣工(WQ_TICKS=130) | ≈ 706 秒预算(130 息 = 520 秒) | 测试目的本身,不能省 |
| 等攒银两 | 30 轮 × 2.2 秒 ≈ 66 秒 | 同上(资源按 tick 产出) |
| 第 5.5 节等任务结算 | 16 秒(本应 48 秒) | 🔴 等待预算写错 |
⇒ 改硬等待只能省约 4.5 秒(1.3%)。
5.2.1 🔴 第 5.5 节:一个写错的等待预算(已按 B 方案修复)
{ type: 'start_task', template_id: 'escort_silver_easy', duration: 12 }
await control('resume');
await page.waitForTimeout(16000); // ← 只等 16 秒
await control('pause');
balance.json的tick.seconds_per_tick = 4⇒duration: 12息 = 48 秒真实时间- 后端
engine.py:1952还有duration = max(10, ...)兜底 ⇒ 最少 40 秒 - 16 < 40 ⇒ 这单从来没结算过
这正是 _auth.cjs 文件头警告的那类坑:
这个油门老大已经调过两次(09-201→2、09-212→4)… 漏改一个的症状不是老实报红, 而是"等待预算不够 ⇒ 断言挂 ⇒ 看着像产品坏了"。
⚠️ 修正一处我先前的误判:我起初说这会导致「日志里有任务汇报」恒定假红——不准确。 实测基线里那条是通过的(1 条(升级/营造 1 条)),因为同轮前面的征讨战斗也写了日志条目, 把它撑住了。所以那条断言并非恒红,而是脆弱(一旦征讨没有目标就会断)。
真正的受害者是下游那条:那个在途任务在第 6 节附近恰好结算, 于是 读档 · 日志簿一并还原 的"存档时条数 == 读回条数"被打破 ⇒ 基线报 2 条 → 3 条(红)。
修复(老大选的 B 方案):不再真接任务,改为夹具预置一条已结算的日志条目:
pause → POST save → injectTaskJournal(uid) → POST load
条目由后端真实的 Journal.add_task() 生成(web/tools/_fixture_task.py)—— 不手写结构,因为 line 字段由 task_line() 生成,手抄迟早与实现漂移。
效果:
| 项 | 基线 | 硬等待改后 | B 方案 |
|---|---|---|---|
| 总耗时 | 359495 ms | 360456 ms | 298669 ms(省 60.8 s · -16.9%) |
| 通过 | 85/97 | 85/97 | 88/99 |
| 失败条目 | 12 条 | 12 条(一字不差) | 11 条 |
读档 · 日志簿一并还原 | 2 条 → 3 条(红) | 同(红) | 1 条 → 1 条(绿) ✅ |
省下的 60.8 秒超出预估的 40 秒:因为过去那个在途任务还会在后续几节里持续 影响日志计数与浮窗内容,夹具的"已结算条目"把这些时序不确定性一次性消掉了。
5.2.2 e2e 要真正提速,得走「夹具预置」
e2e 剩下的时间(约 240 秒)几乎全在等真实作品时间:等武器铺竣工 520 秒档、 等攒银两。这些是测试目的本身(验"建造链路真的会竣工"),不能省。
⇒ 若要大幅压缩 e2e,唯一的路是把"真跑链路"换成"夹具预置状态", 但那会改变测试覆盖面(不再验建造链路),需老大权衡。 本次只做了 5.5 那一处(因为它本来就是写错的预算,不是"覆盖面的取舍")。
六、后续状态
6.1 ✅ e2e.cjs 第 5.5 节 —— 老大选 B,已实施
| 方案 | 结论 |
|---|---|
A 修正确性(duration 改 10 + 轮询等结算) | 未采用 |
| B 走夹具预置(已实施) | 省 60.8 秒,且 读档 · 日志簿一并还原 由红转绿 |
| C 先不动 | 未采用 |
新增文件: | 文件 | 作用 | |---|---| | web/tools/_fixture_task.py | 用后端真实的 Journal.add_task() 生成条目并写进存档 | | web/tools/_fixture.cjs#injectTaskJournal | Node 侧包装(照项目既有 execFileSync 先例) |
6.2 两个未改的 9000ms
| 文件 | 为什么没改 |
|---|---|
shot_grass.cjs | 注释是"读档后等 shader 编译/贴图解码",与 started 判据之间隔了别的逻辑,判据不明确 ⇒ 需单独看 |
probe_prod_tutorial.cjs | 9000ms 在"点踏入Jianghu"的重试循环里,语义是"等提交生效",需单独设计判据 |
6.3 ✅ 探针并行化 —— 已完成,见 docs/探针并行化.md
结论:实测 --jobs 2 是甜点(省 29.5%),--jobs 4 适得其反(更慢 + 引入假红)。 工具:web/tools/run_parallel.cjs(默认并发 2,Sign out码可当门禁)。
6.4 ✅ 探针渲染后端统一 —— 已完成(最大杠杆兑现)
62 个探针原先把软渲染参数写死在 args 里(三种写法),已全部统一到 _auth.cjs#mergeRenderArgs(不设 PROBE_RENDER 时原样返回 ⇒ 行为严格不变)。
最终收益(8 个定点探针,--suite core):
| 配置 | 墙钟 | 相对串行 | 假红 |
|---|---|---|---|
| 串行(软渲染) | 157.1 s | 1.00× | 无 |
| 软渲染 jobs 2 | 110.8 s | 1.42× | 无 |
| 软渲染 jobs 4 | 193.6 s | 0.81× | ❌ 有 |
PROBE_RENDER=d3d11 jobs 4 | 50.5 s | 3.11× | ✅ 无 |
⇒ 157.1 s → 50.5 s(3.11 倍),且假红归零。 详见 docs/探针并行化.md。
单跑也有收益:probe_task_cards 35987 → 27022 ms(-24.9%),断言逐条相同。
⚠️ 一个被推翻的假说值得记:我最初用"2 软 + 2 硬混跑"做对照,测得耗时几乎相同 (147 vs 146 s),一度判定"硬件渲染没用"。那是实验设计的错 —— 混着软渲染的探针仍在抢 CPU,把整组拖住。整组换成硬件后收益才显现(3.8 倍)。 ⇒ 教训:要测 A 的效果,就让整组都是 A,混合编组会把两类效应搅在一起。
6.5 剩余可优化项
| 目标 | 位置 | 说明 |
|---|---|---|
| 扩大 suite 覆盖面 | run_parallel.cjs | 目前只 8 个探针;可按模块分组(scene / ui / combat) |
probe_prod_tutorial | 62.5 s 大等待 | 未评估 |
| 274 处硬等待里的其余部分 | 全项目 | 需按 §4.1 的铁律逐个判断"等状态"还是"节奏" |
| 复用浏览器进程 + 登录态 | 每个 .cjs 各自冷启动 Chromium + 各自注册账号 | 每个可省 1~2 秒 |
七、复现与验证方法
# 严格对照(同一探针,改前/改后各跑一次,比对耗时 + 断言数值)
node web/tools/probe_camera_front.cjs http://127.0.0.1:8080/
# 验证「started → loading.done」的真实间隔
node D:/tools/fbu-test/measure_started_gap.cjs http://127.0.0.1:8080/
# 批量改造脚本(幂等;已改过的会报"三段式没匹配上",属正常)
python D:/tools/fbu-test/batch_9000.py
# 排查探针硬等待分布
for f in web/tools/*.cjs; do
n=$(grep -oE "waitForTimeout\([0-9]+\)" "$f" | grep -oE "[0-9]+" | awk '$1>=1000 {s+=$1} END {print s+0}')
[ "$n" -gt 0 ] && echo "$n $f"
done | sort -rn | head -15
八、附:测试号已清理
本轮跑探针累计产生大量 @example.com 测试号,已清理完毕:
| 项 | 清理前 | 清理后 |
|---|---|---|
| 账号 | 245 | 1(只剩 aowind@qq.com) |
| 存档 | 193 | 1 |
| 活跃会话 | 23 | 1 |
:8000 服务 | 运行 | 运行(已复核健康) |
python tools/clean_test_accounts.py # 先空跑看清单
python tools/clean_test_accounts.py --yes # 真清(停 :8000 → 清 → 启回)
⚠️ 两点须知:
- 该脚本会清掉历史上全部
@example.com号,真实号aowind@qq.com永不触碰。 - 它需要停/启
:8000⇒ 有真人玩家在线时别跑(本项目记忆里的纪律)。
本次执行时出现脚本文件头记载的「跑两遍」现象(输出"待删账号 0 个却删了 192 份存档") —— 那是正常的,按它的告诫,判据看盘上剩什么,不看它打印什么。