Skip to content

test(cli): 把 NDJSON e2e 的放行截止时间锚定到 device code 签发时刻 (#6855) - #6873

Merged
os-project-manager merged 1 commit into
mainfrom
claude/fix-cloud-login-ndjson-e2e-ordering
Aug 9, 2026
Merged

test(cli): 把 NDJSON e2e 的放行截止时间锚定到 device code 签发时刻 (#6855)#6873
os-project-manager merged 1 commit into
mainfrom
claude/fix-cloud-login-ndjson-e2e-ordering

Conversation

@os-project-manager

Copy link
Copy Markdown
Collaborator

Fixes #6855

结论先行:是 flaky,不是 main 坏了;是测试的锚点错了,产品行为正确

packages/cli/test/cloud-login-json-ndjson.e2e.test.ts:333releasedByDeadline 断言在合并队列里间歇变红,已先后踢出两个与该断言毫无关系的 PR:#6847(仅改 spec)与 #6835(仅改 docs)。

先测量,后动手。干净 origin/main @ 659526212 上:

场景 结果
串行 10 次(空载) 10 passed / 0 failed
并发 8 份(4 核容器,模拟队列争抢) 6 passed / 2 failed

两次失败的签名与 CI 完全一致 —— Tests 1 failed | 11 passed (12),唯一红的就是 :333。所以:不是 main 上的确定性失败,是负载下的竞态

根因:逃生阀计时器锚在 spawn 之前,于是它监督的是"启动快不快",而不是契约

RELEASE_DEADLINE_MS(20s)存在的目的,是让缓冲式实现以断言失败收场而不是把 suite 挂死。但它在 execFile 之前就已武装,于是 script(1) 启动 + tsx 对整棵 oclif 命令树的转译 + 模块加载全部被计入这 20s。空载实测(探针复刻 runCloudDeviceLogin,5 次):

区间 实测
spawn → 请求 device code(纯启动) 3423–3713 ms
device code 响应 → 记录可读(真正的契约窗口) 16–28 ms

99.4% 的旧预算花在契约管不着的启动上。启动只要慢 5.7 倍就耗尽 20s —— 对一个并发 84 个 task、跑满 11 分半的队列 runner 来说是常态。

把截止时间压到 1000ms(模拟"启动比预算还慢")即可稳定复现,而且复现结果本身就说明了失败消息是误诊:

releasedByDeadline: true      ← :333 变红
urlSeenAtMs:        3504      ← 记录仍然先到
authorizedAtMs:     4495      ← 授权仍然后到,契约完好
emitWindowMs:       19        ← 契约窗口毫发无损

记录确实早于授权到达 stdout。旧文案 “the device record never reached stdout early” 在这种情形下说的是错的。

改法:重新锚定,不是放宽超时

计时器改为在端点签发 device code 的那一刻才武装 —— 那是契约第一次可被观测的时刻,此后 CLI 手上已握有 verification URL,一个正确实现只需 ~20ms 就该把它写出去。

RELEASE_DEADLINE_MS 数值保持 20s 原样,这一点在 diff 里可直接核对:改的是预算度量什么,不是预算多大。重新锚定后余量从「20s 对 3.5s 启动」变成「20s 对 20ms 契约窗口」,约 1000 倍。

逃生阀语义完整保留:缓冲式实现依旧在 device code 签发后 20s 被判红,suite 不会挂死。CLI 若根本走不到设备流程,计时器不武装,该 run 随子进程退出结束,由既有断言指认缺失。

#6730 的契约断言仍然咬得住(反向验证,方向事先声明)

事先声明的预期方向:#6730 的缓冲式缺陷放回去,:333 必须依旧变红 —— 否则我只是把断言废掉了。

src/commands/cloud/login.ts:218 的早发限制退回 onDeviceCode: undefined(即 #6730 修好之前的缓冲形态)后:

Tests  5 failed | 7 passed (12)
AssertionError: the device record did not reach stdout within 20000ms of the CLI
receiving its device code — the buffered-emit regression this route was chosen to
prevent. ...: expected true to be false

红,且新文案准确指认了真实原因。产品文件随后已还原(git checkout --,diff 中不含任何 src/ 改动)。

修复后的负载复测

同一套并发 8 份配置(此前 2/8 红),跑两轮:

=== CONCURRENT x8 TWO ROUNDS (fixed): pass=16 fail=0 / 16 ===
:333 signature count: 0

门禁

门禁 结果
pnpm --filter @objectstack/cli test Test Files 98 passed (98) · Tests 1029 passed (1029)
pnpm --filter @objectstack/cli typecheck 通过(tsc --noEmit 无输出)
node scripts/check-nul-bytes.mjs OK (scanned 6398 tracked text file(s))

刻意没做的事

变更集

测试专属改动,不发布任何东西 → 无 changeset,加 skip-changeset


Generated by Claude Code

`cloud-login-json-ndjson.e2e.test.ts:333` 的 `releasedByDeadline` 断言在合并
队列里间歇性变红,已经先后把两个与之无关的 PR 踢出队列(#6847 仅改 spec、
#6835 仅改 docs)。

根因不是契约被破坏,而是逃生阀计时器的**锚点**错了:它在 `execFile` 之前
就已武装,于是 `script(1)` 启动、`tsx` 对整棵 oclif 命令树的转译、模块加载
全都被计入这份 20s 预算 —— 而这份预算存在的目的只是监督"设备记录必须尽早
落到 stdout"。空载实测:

| 区间 | 实测 |
|---|---|
| spawn → 请求 device code(纯启动) | 3423–3713 ms |
| device code 响应 → 记录可读(真正的契约窗口) | 16–28 ms |

即旧预算约 99.4% 花在契约管不着的启动上,启动只需慢 5.7 倍即可耗尽 20s ——
对一个并发 84 个 task、跑满 11 分半的队列 runner 来说完全是常态。

改法是把计时器改为在端点签发 device code 的那一刻才武装:那是契约第一次
可被观测的时刻,此后 CLI 手上已经握有 verification URL。`RELEASE_DEADLINE_MS`
数值保持 20s 不变 —— 这是**重新锚定**,不是放宽超时;重新锚定后被守护的窗口
从 ~3500ms 启动变成 ~20ms 契约窗口,余量约 1000 倍。

断言本身没有被削弱:反向验证把 `onDeviceCode` 限制退回 #6730 的缓冲式实现后,
该断言依旧变红(5 failed | 7 passed),因此 #6531/#6730 的"URL 先于授权"保证
仍然被咬住。顺带把断言消息改准确 —— 旧文案"never reached stdout early"在启动
超时的情形下是错误诊断。

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01F8q5J1MQyocgtNspb15fSn
@vercel

vercel Bot commented Aug 9, 2026

Copy link
Copy Markdown

The latest updates on your projects. Learn more about Vercel for GitHub.

1 Skipped Deployment
Project Deployment Actions Updated (UTC)
objectstack Ignored Ignored Aug 9, 2026 2:08am

Request Review

@github-actions github-actions Bot added the size/s label Aug 9, 2026
@os-project-manager os-project-manager added skip-changeset PR has no user-facing published change; bypasses the changeset gate and removed size/s labels Aug 9, 2026 — with Claude
@github-actions

github-actions Bot commented Aug 9, 2026

Copy link
Copy Markdown
Contributor

📓 Docs Drift Check

No hand-written docs reference the 0 changed package(s). ✅

@github-actions github-actions Bot added the tests label Aug 9, 2026

Copy link
Copy Markdown
Collaborator Author

追加:同一负载下的对照实验(修复前 12/12 红 vs 修复后 12/12 绿)

把并发从 8 提到 12(仍是 4 核容器),得到了比原描述更干净的一组对照 —— 同一台机器、同一条命令、只有测试文件版本不同:

测试文件版本 并发 12 结果 :333 签名
origin/main 原样(未修复) 0 passed / 12 failed 12/12
本 PR(重新锚定后) 12 passed / 0 failed 0/12

对照组用 git checkout origin/main -- <该测试文件> 取得,跑完即用 git checkout HEAD -- 还原(工作区现已干净,diff 仍只有这一个测试文件)。

为什么并发 12 是决定性的:此负载下每个子进程的实测墙钟约 25s(76.4s / 3 个子进程),已经超过旧的 20s 预算本身。也就是说旧锚点在这个负载下不是"可能翻车",而是必然翻车 —— 光启动就把预算耗尽了。而重新锚定后预算只覆盖 ~20ms 的发射窗口,同样的 25s 启动对它毫无影响,于是 12/12 全绿。

这组数字也顺带回答了"会不会只是把断言变迟钝了":如果断言被削弱,对照组不会红得这么彻底;而反向验证(把 onDeviceCode 退回缓冲形态)那一组依然是红的。断言仍然咬得住,咬的对象从"启动够不够快"换回了"记录有没有及早写出"。

修复后累计样本

负载 轮次 结果
并发 8 4 轮 32 passed / 0 failed
并发 12 1 轮 12 passed / 0 failed
合计 44 passed / 0 failed,:333 签名 0 次

Generated by Claude Code

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

Labels

skip-changeset PR has no user-facing published change; bypasses the changeset gate tests

Projects

None yet

2 participants