内核的插件 init/start 超时守卫定时器从不清除也不 unref —— 每个进程在工作结束后还要空转 startupTimeout(CLI 挂 ~120s 才退出)

[os-zhuang]

发现自 #4747 的实现过程。未认领。 与 #4747 是不同的 bug,但它正是 #4747 得以发生的前提条件。

现象

一条 os migrate 子命令的实际工作 3 秒就做完了(JSON 已输出、✅ Graceful shutdown complete 已打印),然后进程再挂 120 秒才被外部杀掉:

07:54:18.354   进程启动
07:54:21.556   ✅ Graceful shutdown complete     ← 活干完了
07:56:21.471   进程结束(被杀,退出码 214/238 不稳定)

原因

packages/core/src/kernel.ts 的两处超时守卫:

// initPluginWithTimeout(), ~L544
const initPromise = plugin.init(this.context);
const timeoutPromise = new Promise< void >((_, reject) => {
  setTimeout(() => {
    reject(new Error(`Plugin ${plugin.name} init timeout after ${timeout}ms`));
  }, timeout);
});
await Promise.race([initPromise, timeoutPromise]);

startPluginWithTimeout() 里是同一段。插件赢了这场 race 之后,那个 setTimeout 既没被 clearTimeout,也没被 unref() —— 它带着 ref 一直挂到 startupTimeout 走完。

ObjectQLPlugin.startupTimeout = 120_000,于是最长的那根定时器把进程钉住整整 120 秒。实测正是 8 根还带 ref 的 Timeout(4 个 init + 4 个 start):

[probe] 8 ref'ed timers still alive
[probe] setTimeout: at ObjectKernel.initPluginWithTimeout  (packages/core/dist/index.js:1855)
[probe] setTimeout: at ObjectKernel.startPluginWithTimeout (packages/core/dist/index.js:1891)

同一个文件里 shutdown() 自己的超时守卫已经做对了,连注释都写好了:

const t = setTimeout(() => { reject(new Error('Shutdown timeout exceeded')); }, this.config.shutdownTimeout);
// Don't let this timer keep the event loop alive
if (t.unref) t.unref();

修法就在隔壁 30 行。清除(finally { clearTimeout(t) })比 unref() 更彻底,两者都可以。

为什么值得修

1. 一次性 CLI 进程不退出。 os migrate / os meta resync 全家都是干完活挂 30–120 秒。脚本里串起来的 CI 步骤会白等,退出码还不稳定。
2. 这是 每个 os migrate 子命令关停时，悬空引用巡检都会把 sys_metadata / sys_view_definition 报成 unreadableObjects（连接已关闭） #4747 的使能条件。 isSystem 写入仍可产生悬空 lookup 引用——需要一条只报告不拦截的巡检（#4441 残留） #4551 巡检的首次 sweep 排在启动后 60 秒;一个干完活就退出的进程永远碰不到它。正是这 120 秒的空转把进程留到了 60 秒定时器触发,才让巡检在连接池已关之后跑起来。每个 os migrate 子命令关停时，悬空引用巡检都会把 sys_metadata / sys_view_definition 报成 unreadableObjects（连接已关闭） #4747 已从生命周期契约那一侧修好(关停真正到达 LifecycleService),不依赖本条;但只要这些定时器还在漏,任何「启动后 N 秒才做的事」都会在一个自以为已经结束的进程里醒来。
3. os serve 里同样漏,只是那里进程本来就长命,看不出来。

复现

cd examples/app-crm
time OS_DATABASE_URL="file:/tmp/t.db" node packages/cli/bin/run.js migrate recorded-by --json
# JSON 与 "Graceful shutdown complete" 在 ~3s 出现;进程 ~120s 后才结束

挂 handle 的证据:

// node --import ./probe.mjs packages/cli/bin/run.js migrate recorded-by
const t = setInterval(() => console.error(process.getActiveResourcesInfo()), 10000);
t.unref();

边界

• 只碰 packages/core/src/kernel.ts 的两个守卫。别顺手改 startupTimeout 的取值 —— 慢启动的插件需要那个上限,问题不在时长而在没人回收。
• 建议加一条测试:插件正常 init/start 之后,process.getActiveResourcesInfo() 里不应留下这些守卫定时器(或直接断言守卫定时器被 clear)。

Refs #4747。

[claude]

认领:PM 循环第 7 轮
会话:session_015Br2xsJsczFsTR9bvbh2Ny
分支:claude/issue-4813-kernel-timeout-guard-cleared
Worktree:objectstack-issue-4813

域:engine
文件面:packages/core/src/kernel.ts

并行批隔离:本轮同批的另三条落在互不相交的包 —— #4825 packages/metadata、#4813 packages/core、#4808 packages/plugins/plugin-auth、#4820 packages/services/service-analytics。⚠️ #4821(mergeByDimensions 分隔符)与 #4820 同文件,未同批派发,串到下一轮以避开撞车。

---

Generated by Claude Code