关闭钩子跑了两次-SIGTERM 出现两个主人的那次排查

每次部署,Sentry 都会收到同一条错误:Transaction already closed。这是 Prisma 在事务已经关闭之后还想执行查询,于是抛出 P2028 崩掉的错误。对用户其实没有任何影响-BullMQ 的重试机制立刻在另一个任务里把它补成功了,完成日志也没有断档。但只要部署和流量重叠,这个问题就会悄悄复发。追查这条错误的过程中,我发现我们服务器的关闭钩子其实每次都被执行了两遍。

第一幕:数据库在任务结束前先死了

把出错时间和 CloudWatch 日志对上之后,时间线严丝合缝。滚动部署给旧任务发送了 SIGTERM。6 秒后 app.close() 开始清理,Prisma 引擎关闭了事务。紧接着,还在运行中的 asset-processing 任务里的 updateMany 在一个已经关闭的事务上执行,于是以 P2028 失败。当时正好有用户在连续上传音频,部署那一刻恰好有活跃任务,那个任务的查询就这样被牺牲了。

根源在于关闭顺序。NestJS 关闭时会按固定顺序调用生命周期钩子。问题是,关闭 BullMQ worker 和断开 Prisma 连接处在同一个关闭阶段(onApplicationShutdown)。在同一个阶段内,模块的注册顺序决定了执行顺序,而恰好 Prisma 先断开,还在处理任务的 worker 的查询就无处可去了。

修复方向很清楚:把 worker 挪到更早的阶段关闭。NestJS 的关闭钩子是分阶段的,beforeApplicationShutdown 会比任何模块的 onApplicationShutdown 都更早完成。于是我写了一个服务,专门在这个更早的阶段里找出所有 worker 并 drain(等待活跃任务结束)。

@Injectable()
export class WorkerDrainService implements BeforeApplicationShutdown {
  constructor(private readonly discovery: DiscoveryService) {}

  async beforeApplicationShutdown() {
    // 找出所有已注册的 WorkerHost,等待其活跃任务结束。
    // 这个阶段会比 Prisma 断开所在的 onApplicationShutdown 更早结束。
    const workers = this.discovery
      .getProviders()
      .filter((p) => p.instance instanceof WorkerHost);
    await Promise.all(workers.map((w) => w.instance.worker.close()));
  }
}

Worker.close() 重复调用也会返回同一个 promise,所以不会和原有的关闭 worker 的代码冲突;在没有 Redis 的环境里也只会静默地什么都不做。就算部署和任务重叠,现在也会先等任务结束,数据库才会关闭。加上单元测试后我提了 PR。到这里为止,还只是一次普通的顺序 bug 修复。

第二幕:SIGTERM 竟然有两个主人

反转出现在审查阶段。审这个修复的同事把整条关闭路径又过了一遍,提了一个问题:SIGTERM 到底是谁在处理?

一查,主人竟然有两个。main.ts 里分别有这样两行:

// ① 把关闭信号交给 Nest 自己处理(不带参数调用时,SIGTERM、SIGINT 都会注册)
app.enableShutdownHooks();

// ② 同时又把关闭交给了 http-graceful-shutdown 库
setupGracefulShutdown(server, {
  onShutdown: async () => {
    await app.close(); // 这里会执行完整的生命周期钩子
  },
});

两边都在捕获 SIGTERM。Node 收到信号时,会把所有注册的监听器按顺序全部调用,彼此并不等待对方完成。于是真实的 SIGTERM 到来的那一刻,会发生这样的事:Nest 注册的监听器根本不等 HTTP 排空,就立刻执行了一遍和 app.close() 一模一样的关闭序列。与此同时,http-graceful-shutdown 按自己的方式排空 HTTP 连接后,又在 onShutdown 里再一次调用了 app.close()。关闭钩子就这样被执行了两遍。

单靠推理无法确认,于是我又翻出生产环境的关闭日志。证据都在。SIGTERM 被记录下来的 20 毫秒之后,HTTP 连接还没排空,onModuleDestroy 就已经开始了;SpeechService 和 QueueMonitorService 的关闭钩子日志都各出现了两次。之所以没有酿成事故,唯一的原因是每个服务的钩子都写得即使被调用两次也是安全的(idempotent)。正是这份防御性写法,让"执行了两次"没有变成故障,而只是留下了一点日志异味-而这点异味最终帮我们抓到了 bug。

删掉一行代码

修复方案就是删掉一行。

// main.ts
- app.enableShutdownHooks();

去掉 enableShutdownHooks() 之后,SIGTERM 的主人就只剩下 http-graceful-shutdown 一个。没有任何损失,因为它的 onShutdown 调用的 app.close() 本来就会执行完整的生命周期钩子。唯一的变化是:钩子不再执行两次,而是只执行一次,并且是在 HTTP 排空之后才执行。

改动越小,越需要实测。我在构建好的服务器上真的发了一次 SIGTERM,亲眼确认了整个序列。

Received SIGTERM → health check 503 → HTTP connections closed
→ shutdown hooks run only once, after HTTP close
→ Drained 56/56 BullMQ workers in 211ms → shutdown completed → clean exit

原本在生产环境里、于 HTTP 排空之前被执行两次的钩子,现在只在排空之后执行一次。这次验证是和第一幕里的 worker drain 修复合在一起做的,所以也顺带确认了两个修复合并运行后的整体行为。

这里还记录了一个陷阱:在 NODE_ENV=development 下,http-graceful-shutdown 会直接走立即退出的模式,根本不会进入 graceful 路径,所以这次验证在开发模式下无法复现。我把 NODE_ENV=staging 配上一个占位密钥,让它走和生产环境相同的路径,才做成了这次实测。验证关闭路径时,首先要确认验证环境本身是否真的会走这条路径。

从这次关闭代码里学到的

这次事故的教训,超出了"关闭序列"这个狭窄的场景。

一个信号只能有一个主人。 一旦接入了 graceful shutdown 库,就不应该同时打开框架自带的关闭钩子自动注册功能。两边一旦同时捕获同一个 SIGTERM,关闭序列就会悄无声息地被执行两次。引入新工具时,要先搞清楚它会成为哪个信号、哪个事件的主人,以及现有代码里是否已经有人在捕获同一个东西。

关闭也是有顺序的。 负责清理某个资源的代码,应该在所有依赖它的工作都结束之后才运行。数据库要等使用它的任务结束之后才能关闭,而要做到这一点,就必须把任务的排空放到更早的阶段。框架把关闭钩子划分成不同阶段,不是摆设,就是用来表达这种顺序的。

防御性代码能替你争取时间。 如果关闭钩子没有被写成"重复调用也安全",这个 bug 暴露出来的就不会是日志异味,而会是一次实实在在的数据事故。正是因为钩子写得幂等,才扛住了被执行两次这件事,让我们能从日志里发现问题,而不是从事故报告里发现它。如果当初笃定钩子"只会执行一次"而不做防御,这个故事的结局会糟糕得多。