fix(core): 插件 init/start 超时守卫在 race 落定时被清除 —— 进程不再空转 startupTimeout (#4813)

[os-zhuang]

Fixes #4813

initPluginWithTimeout() / startPluginWithTimeout() 各自 setTimeout armed 一根超时守卫,然后把它扔了。插件赢下 race 之后那根定时器既没 clearTimeout 也没 unref(),带着 ref 一直挂到 startupTimeout 走完 —— 每个进程在活干完之后还要空转整整一个 startupTimeout。

两处守卫合并成一个私有 helper raceStartupTimeout(),在 finally 里 clearTimeout。startupTimeout 的取值一个都没动。

为什么是 clearTimeout 而不是 unref() —— 我验证过再决定的

issue 提到「finally { clearTimeout(t) } 比 unref() 更彻底」,并猜测理由是 unref 的定时器仍会触发那个 reject,产生一个无人处理的 rejection。这个猜测是错的,我实测否定了它 —— Promise.race 会给每个 arm 都挂上 handler,所以输掉的 timeout promise 后来 reject 时是被处理过的,不会有 unhandledRejection:

process.on('unhandledRejection', r => console.log('UNHANDLED:', String(r)));
const work = Promise.resolve('done');
const guard = new Promise((_, reject) => {
  setTimeout(() => reject(new Error('guard fired')), 300).unref();
});
await Promise.race([work, guard]);
setTimeout(() => console.log('still alive at 600ms'), 600);
// → race settled: done
// → still alive at 600ms          ← 没有 UNHANDLED

真正的理由是另一条,而且更硬:unref() 让定时器不再钉住事件循环,同时也让它不再是一个守卫。

// 一个永不 settle 的 hook,守卫用 unref():
const never = new Promise(() => {});
const guard = new Promise((_, reject) => {
  const t = setTimeout(() => reject(new Error('start timeout after 500ms')), 500);
  if (t.unref) t.unref();                       // shutdown() 的写法
});
try { await Promise.race([never, guard]); }
catch (e) { console.log('GUARD FIRED:', e.message); }
console.log('after await');

实际输出:什么都没打印,Node 直接退出(exit 13,unsettled top-level await)。守卫从来没有触发,超时被静默吞掉。若 hook 永不 settle 且没有别的东西撑着事件循环,unref() 的守卫就是个摆设 —— 这正是它要防的那种故障。

所以正确语义是:守卫在 race 未决期间保持 ref'd(它必须能触发),在 race 落定的那一刻被回收。finally { clearTimeout(guard) } 恰好表达这个,unref() 表达不了。

关于「保持同一种写法」:shutdown() 自己那处 if (t.unref) t.unref(); 本 PR 没有动 —— issue 的边界写明只碰这两个守卫,而且改它会在一个边缘情形上改变行为(shutdown 卡死且事件循环空转时,现在静默退出 0,改成 clear 后会触发 Shutdown timeout exceeded → process.exit(1))。那是一个独立的判断,不该搭本 PR 的车。理由与取舍写在 raceStartupTimeout() 的 doc comment 里,下一个读到 shutdown() 的人能看到两种写法各自的适用面。

验收:真实 CLI,同一个构建链,唯一差别是本改动

cd examples/app-crm
OS_DATABASE_URL="file:/tmp/t.db" node ../../packages/cli/bin/run.js migrate recorded-by --json

	墙钟
修复前	122.4s
修复后	3.1s

两次 JSON 与 ✅ Graceful shutdown complete 都在 ~3 秒出现;后面那 119 秒纯粹是 8 根孤儿定时器钉着事件循环。(为了拿到干净的 before,我把 kernel.ts stash 掉、只重建 @objectstack/core、跑同一条命令,再还原 —— 所以这一对数字之间没有别的变量。)

测试:钉的是「定时器不再把进程钉住」,不是「代码里调了 clearTimeout」

后者是同义反复,任何重构都能满足它而照旧漏定时器。新增 4 条,前 3 条修复前全红:

AssertionError: expected 3 to be 1     ← leaves no ref'd timer behind after the plugin wins the race
AssertionError: expected 11 to be 3    ← reclaims one guard per lifecycle hook, for every plugin
AssertionError: expected 2 to be +0    ← schedules no pending timer once bootstrap has settled
Test Files  1 failed (1)
     Tests  3 failed | 1 passed | 31 skipped (35)

• getActiveResourcesInfo() 探针(issue 自己的思路)。它只报告当前正在维持事件循环存活的资源,正是「进程为什么不退出」这个问题的直接答案。1 个插件 ⇒ 修前多出 2 根(init + start);4 个插件 ⇒ 修前多出 8 根,与 issue 里 probe 抓到的 8 ref'd timers still alive 一模一样。断言的是 delta 为 0,不是绝对值。
• 假定时器那条是用来区分半修的:getActiveResourcesInfo() 不计 unref'd 定时器,所以只有它无法分辨「守卫被回收了」和「守卫只是被摘下了循环」;vi.getTimerCount() 两者都计,unref() 方案过不了这一条。
• 第 4 条是反向配对:插件输掉 race 时守卫照旧触发(Plugin hanging-plugin init timeout after 50ms)。回收守卫不等于解除守卫 —— 没有这条,「把两个 setTimeout 删掉」也能让前 3 条变绿。

@objectstack/core     28 files /  462 tests passed
@objectstack/runtime  80 files / 1092 tests passed
@objectstack/cli      67 files /  585 tests passed
tsc --noEmit (core)   120 errors — 与改动前 baseline 完全相同,本 PR 新增 0

@objectstack/core 没有 typecheck script,走 check-type-check-coverage.mjs 的 DEBT 棘轮,所以我按「改动前/改动后同一条命令」测了两次而不是只看绝对数。中途 helper 的形参一度写成 Promise< T > 而多出 2 个 TS2345 —— Plugin 契约允许同步 hook(init/start 返回 void | Promise< void >),已改为 T | PromiseLike< T >,回到 baseline。

⚠️ 本 PR 改变了 #4747 那条路径的时序 —— 请连带读这一段

#4747 已经独立修好了(PR #4815,127f09125,已在 main 上),修的是生命周期契约那一侧:ObjectQLPlugin 的关停逻辑从内核根本不调用的 stop() 挪到 destroy(),bootSchemaStack().shutdown() 从 (runtime as any).stop?.() 改走 kernel.shutdown()。所以本 PR 不会掩盖 #4747 —— 它已经不是靠时序活着的了。

但这件事仍然值得写下来,因为本 PR 确实会让 #4747 的现象即使在未修状态下也不再复现:#4551 的巡检首次 sweep 排在启动后 60 秒,而正是这 120 秒空转把一次性 CLI 进程留到了 60 秒定时器触发。修好之后进程 3 秒就退出,那条巡检路径不再被触发。假如 #4815 没有先落地,本 PR 会让一个真实缺陷「看起来消失了」而根因原封不动。#4813 与 #4747 必须各自被各自的修复关闭,这是其中一半。

推而广之:只要这些守卫还在漏,任何「启动后 N 秒才做的事」都会在一个自以为已经结束的进程里醒来 —— 反过来,修好之后,任何依赖「进程反正还活着」的周期性工作都会失去那个隐式的宽限期。目前仓里只有 ADR-0057 巡检这一处踩到,已由 #4815 从正确的一侧解决。

超范围产出(未在本 PR 修)

• os migrate 成功时退出码是随机非零值(208/171/176/163/62…),--version / --help 却干净退出 0 #4873(新开,未认领):os migrate 成功时退出码是随机非零值。这是我为了拿 before/after 数字才看清的:issue 内核的插件 init/start 超时守卫定时器从不清除也不 unref —— 每个进程在工作结束后还要空转 startupTimeout(CLI 挂 ~120s 才退出) #4813 把不稳定退出码(214/238)归因于「挂太久被外部杀掉」,这个归因是错的 —— 修复后没有任何东西杀它,它 3 秒自行退出,退出码依旧随机(实测 62 / 169 / 208 / 171 / 176;修复前是 163)。同一个 bin/run.js 的 --version / --help 干净退出 0,所以问题在 bootSchemaStack 系子命令的退出路径上。对按退出码判断成败的 CI 是直接的假失败,且因为随机而无法特判兜底。
• packages/core/src/health-monitor.ts:315 的 timeout() 是同一个漏法:setTimeout(() => reject(...), ms) 进 Promise.race(:112 的健康检查),赢下 race 之后同样不清除。它今天没造成 内核的插件 init/start 超时守卫定时器从不清除也不 unref —— 每个进程在工作结束后还要空转 startupTimeout(CLI 挂 ~120s 才退出) #4813 的现象,因为健康监控不在 bootstrap 路径上启动;但它是同一个形状,应当用同一个 helper 收编。issue 的边界写明只碰 kernel.ts 的两个守卫,故本 PR 未动 —— 如果维护者希望一并收,我可以在同一条分支上补。

🤖 Generated with Claude Code

https://claude.ai/code/session_015Br2xsJsczFsTR9bvbh2Ny

---

Generated by Claude Code

[vercel]

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

1 Skipped Deployment

Project	Deployment	Actions	Updated (UTC)
objectstack	Ignored		Aug 3, 2026 11:38am

[github-actions]

📓 Docs Drift Check

This PR changes 1 package(s): @objectstack/core.

23 hand-written doc(s) reference the affected code and may need an implementation-accuracy re-verification:

• content/docs/ai/actions-as-tools.mdx (via @objectstack/core)
• content/docs/ai/knowledge-rag.mdx (via @objectstack/core)
• content/docs/ai/natural-language-queries.mdx (via @objectstack/core)
• content/docs/automation/webhooks.mdx (via @objectstack/core)
• content/docs/concepts/north-star.mdx (via packages/core)
• content/docs/deployment/migration-from-objectql.mdx (via @objectstack/core)
• content/docs/kernel/contracts/index.mdx (via @objectstack/core)
• content/docs/kernel/runtime-services/examples.mdx (via @objectstack/core)
• content/docs/kernel/services-checklist.mdx (via @objectstack/core)
• content/docs/kernel/services.mdx (via @objectstack/core)
• content/docs/permissions/authentication.mdx (via @objectstack/core)
• content/docs/permissions/authorization.mdx (via packages/core)
• content/docs/plugins/anatomy.mdx (via @objectstack/core)
• content/docs/plugins/development.mdx (via @objectstack/core)
• content/docs/plugins/index.mdx (via @objectstack/core)
• content/docs/plugins/packages.mdx (via @objectstack/core)
• content/docs/protocol/kernel/config-resolution.mdx (via @objectstack/core)
• content/docs/protocol/kernel/index.mdx (via @objectstack/core)
• content/docs/protocol/kernel/lifecycle.mdx (via @objectstack/core)
• content/docs/protocol/kernel/plugin-spec.mdx (via @objectstack/core)
• content/docs/releases/implementation-status.mdx (via @objectstack/core)
• content/docs/releases/v12.mdx (via @objectstack/core)
• content/docs/releases/v15.mdx (via @objectstack/core)

Advisory only. To re-verify, run the docs-accuracy-audit workflow scoped to these files:
node scripts/docs-audit/affected-docs.mjs origin/main → pass the list as args.docs.

[os-zhuang]

复核通过 —— ACCEPT

⏳ 标 ready + 入队要等 GraphQL 配额重置(约 12:16),届时立即执行。复核结论先行。

1. 它证伪了我在派发文里给的理由,并给出了更硬的一条

我写的是:「倾向 clearTimeout,因为 unref 的定时器仍会在事件循环还活着时触发那个 reject,产生一个无人处理的 rejection。这一点值得你自己验证后再定。」

dev 验证了,我的理由不成立 —— Promise.race 给每个 arm 都挂了 handler,不会有 unhandledRejection。但它找到的真实理由比我的强得多:

unref() 让定时器不再钉住事件循环的同时,也让它不再是一个守卫 —— hook 永不 settle 且事件循环空转时,Node 会在定时器触发前直接退出,超时被静默吞掉(实测 exit 13,什么都没打印)。

这正是本仓一直在关的那类缺陷:一个在最需要它的场景里静默失效的守卫。unref() 会让「插件卡死」从「50ms 后报超时」变成「进程无声退出」。我的理由是对的结论配了个错的论据,它的是对的结论配了对的论据 —— 这个差别很重要,因为下一个人会读理由。

shutdown() 那处既有的 unref() 按 issue 边界未动,而且把「为什么那里可以、这里不行」写进了 helper 的 doc comment。两种写法并存时,把各自适用面写下来,这一步做对了。

2. 测试钉的是可观察后果,而且专门防住了「半修」

我要求「给出一条能在修复前失败的测试,并附上修复前的失败输出」。给到的是:

AssertionError: expected 3 to be 1       // 1 插件 ⇒ 多出 2 根
AssertionError: expected 11 to be 3      // 4 插件 ⇒ 多出 8 根
AssertionError: expected 2 to be +0      // 假定时器
Test Files 1 failed (1) / Tests 3 failed | 1 passed | 31 skipped (35)

4 插件 ⇒ 多出 8 根与 issue probe 的 8 ref'd timers still alive 完全吻合。

两处设计值得点名:

• vi.getTimerCount() 那条计入 unref'd 定时器,专门用来区分「守卫被回收」与「守卫只是被摘下事件循环」—— 一个 unref() 的半修方案过不了它。
• 第 4 条是反向配对:插件输掉 race 时守卫照旧触发(Plugin hanging-plugin init timeout after 50ms)—— 防止「把两个 setTimeout 直接删掉」也能让前 3 条变绿。

只测「代码里调了 clearTimeout」是同义反复,这份测试没有落进去。

3. 真实 CLI 的单变量实验

PRE-FIX   EXIT=163  WALL=122.361963641s
POST-FIX  EXIT=62   WALL=3.652354232s

为拿干净的 before,把 kernel.ts stash 掉、只重建 @objectstack/core、跑同一条命令再还原 —— 唯一变量就是那个文件。这比「改前改后各跑一次」严谨。

4. ⭐ 派发时我最担心的那件事,回答得完整

我要求核实 #4747 是否已独立修复,理由是:修好本单后 #4747 的现象会因进程提前退出而不再复现,但根因没动 —— 别让一个真实缺陷因时序变了被误认为已解决。

回答:

#4747 已由 PR #4815(127f09125,已在 main)独立修好,修在生命周期契约一侧(ObjectQLPlugin 的关停从内核根本不调的 stop() 挪到 destroy();bootSchemaStack().shutdown() 从 (runtime as any).stop?.() 改走 kernel.shutdown()),因此本 PR 不会掩盖它。
但本 PR 确实会让 #4747 的现象即使在未修状态下也不再复现……若 #4815 未先落地,本 PR 会让一个真实缺陷「看起来消失了」而根因原封不动。

两件事都说了:结论(安全)与反事实(若顺序反过来会怎样)。第二句才是这条要求真正想要的东西 —— 它把一个只在特定合并顺序下才安全的判断,变成了写下来的知识。

---

两条范围外发现

#4873 —— 它又纠正了 issue 正文的一处归因错误(我写的)。 我把不稳定退出码归给「挂太久被外部杀掉」。实测:修好挂起后没有任何东西杀它、3 秒自行退出,退出码依旧随机(62/169/208/171/176)。同一个 bin/run.js 的 --version/--help 干净退出 0,问题在 bootSchemaStack 系子命令的退出路径上。本 PR 不修它,正确。

#4875 —— 同一个漏法的第三个实例。 HealthMonitor.timeout()(health-monitor.ts:315,调用点 :112)赢下 race 后同样不清除。今天不发作只因健康监控不在 bootstrap 路径上启动;一旦接进宿主并周期性调用,孤儿定时器会持续累积,比 #4813 更糟(本单是一次性 120 秒,那个是无界增长)。

关于那个开放问题(helper 该不该提成共享工具)

dev 推荐 A(提到 packages/core/src/utils/ 共用),理由是「同一形状的第三个实例,而正确写法有一个反直觉的关键点(必须 clearTimeout 而非 unref),这种知识散落在 N 份复制里必然退化 —— 下一个复制它的人只会看到 setTimeout(reject) 而看不到理由」。

我同意这个判断,而且它与本 PR 第 1 点是同一个论证:理由比代码更容易丢失。但按 issue 边界,本 PR 正确地没有自行推广 —— 收编范围属 #4875 的裁定,已记录在那里。

---

Generated by Claude Code