Why NextWhy Next
返回列表
💻 开发阅读约 6 分钟

测试一片绿,通知却从来没发出去过一次

往队列里塞任务的代码从上线第一天起就每次都失败。错误被吞掉了,测试靠 mock 一直是绿的。一个冒号悄悄干掉三个功能的故事。

核心摘要

BullMQ 禁止自定义 jobId 里出现冒号。违反这条规则的入队代码从第一天起 100% 失败,但失败被 catch 吞掉了,没有人知道通知功能已经死了。测试用纯 mock 替换了队列,从不执行真正的校验,所以一直是绿的。同样的缺陷还藏在另外两个队列里,其中一个无症状运行了 12 天。修复的路上又冒出第二个陷阱 - 固定 jobId 在已完成任务的哈希还留在 Redis 里时,会不报错地忽略重新入队,悄悄杀死重试契约。

目录

Slack 里弹出了一条 500 报警。错误信息很陌生:Error: Custom Id cannot contain :。管理员给用户提问登记答复的 API 正在挂掉,堆栈指向 BullMQ 的 Job.validateOptions

到这里还是一份普通的 bug 报告。这个故事变得不普通,是在找到原因之后。抛出这个错误的代码并不是当天部署改动的,而是从功能上线的第一天起,每一次都在失败,100%。也就是说,这个队列本该发出的推送通知,从来没有发出去过,一次都没有。而这段时间里,测试全是绿的。

原因只有一个字符

出问题的代码长这样。这是提问被回答后,把给用户发推送的任务塞进队列的地方。

await this.queue.add(ANSWER_NOTIFY_JOB_NAME, data, {
  jobId: `answer-notify:${data.questionId}`, // ← 就是这个冒号
});

为了避免同一个问题被入队两次,给了自定义 jobId,但分隔符用了冒号。BullMQ 用冒号拼接 Redis 键,所以禁止自定义 jobId 里出现冒号。以 v5 为准,精确条件是:jobId 含有冒号,且按冒号切分后不是正好 3 段,就抛错。3 段的例外是给旧版 repeatable 任务格式留的口子,所以 answer-notify:123 这种 2 段的必然撞上 Custom Id cannot contain :。顺带一提,纯数字 jobId 也会被 Custom Id cannot be integers 拒绝,所以把前缀删掉也不是答案。

代码库里其他几十处队列全都用的连字符,只有这一个文件用了冒号。

bug 第一天就在了,为什么今天才炸

修复只要一行:把冒号换成连字符。有意思的问题在别处。一直在失败的代码,为什么之前一直安静,今天才变成 500?

功能刚上线时,入队代码是这样包着的。

try {
  await this.queue.add(/* ... */);
  return true;
} catch (err) {
  this.logger.error("enqueue failed", err);
  return false; // ← 失败在这里消失
}

失败被记进日志,然后返回 false。调用方从不检查返回值。于是每次抛出的异常每次都被吞掉,API 返回 200,只有通知悄悄蒸发。

后来同一天合并的一个提交改变了这份契约。意图是:入队失败就别吞,抛出去,让事务里写下的"已回答"标记回滚,可以重试。方向完全正确的改动。就在那一刻,一直在失败的入队第一次发出了声音。500 不是那个提交制造的 bug,而是原本就在的 bug 第一次发出的惨叫。

这就是吞错误的代码的代价。信号消失了,bug 原地不动,还顺手带走一整个功能。

测试为什么是绿的

这个队列是有测试的。调用入队方法,检查 queue.add 是否以正确的参数被调用,很常见的那种 spec。而那个测试里的 queue.add,是一个无条件成功的 mock。

真实 BullMQ 的 add 会校验 jobId 并拒绝冒号。mock 的 add 什么都收。mock 比真实契约宽松多少,测试就把多少在现实中绝对通不过的输入放行成了绿色。mock 和真实契约不一致时,绿色的测试担保的不是活着的代码,而是死掉的代码。

修复时先补上了这个洞。把队列 mock 的 add 改成会跑 BullMQ 真正的 Job.validateOptions。这个函数是不需要 Redis 的纯校验,可以直接放进测试。然后用变异测试确认这道防线是真防线:把冒号改回去,看到测试正好在那个点变红,才提交。如果把 bug 改回去测试还是绿的,那这个测试等于不存在。

不止一处

如果在这里停下,就只修了一半。同样的错误出现在一处,很可能也在别处。我定义了缺陷的"类别" - 含冒号的自定义 jobId - 对代码库做了全量排查,还挂上多个评审代理交叉验证。又找出了两处。

一处是把用户上传的语音转写成文字的队列。jobId: "stt:${id}"。这边错误还在被吞,连 500 都没有。一查,从 12 天前开始,转写任务一条都没进过队列。语音文件正常保存,失败只留在日志里,用户界面上的文字永远是空的。彻底的无症状。

另一处是预约日程的通知邮件队列。jobId 是冒号分隔的 4 段,提醒邮件和取消通知全都根本进不了队列。

三个队列的 producer 统一成了一个公用的 jobId 构建函数:用连字符拼接,混进冒号就替换掉,纯数字直接拒绝。为了防止复发,还加了一条只精确命中"jobId 里出现冒号字面量"这个模式的 lint 规则。已有的 50 多处连字符 jobId 没有强行迁移到新构建函数。repeatable 任务的 jobId 一变,cron 就有重复注册的风险,所以选择只瞄准缺陷类别本身。

第二个陷阱:固定 jobId 悄悄杀死重试

故事到这里结束就好了,但评审验证时又冒出一个更根本的问题。冒号修好之后,answer-notify-123 这样的固定 jobId 就活了过来,而这个固定 jobId 本身,和同一天立下的重试契约是矛盾的。

当 Redis 里还留着同一个 jobId 的任务哈希时,BullMQ 会不报任何错地忽略新的 add,返回已有的 jobId。这个行为是验证者读到 BullMQ 的 Lua 脚本才确认的。而这个队列配置了 removeOnComplete: { count: 100 },刚完成的任务哈希会原样留着。两者叠加就是这样的场景:通知任务失败了一次。按契约回滚"已回答"标记,管理员重试。新的入队撞上残留的任务哈希,什么都不做,却像成功一样返回。通知永远发不出去,而这一次既没有错误也没有 DLQ。

把吞失败的 catch 删掉之后,库自带的去重接管了同一个位置。最终这个队列干脆去掉了自定义 jobId。防重复发送挪到了消费端:processor 用条件更新原子地抢占"通知已发送"标记。任务就算进来两次,也只有先抢到标记的那一边会发推送。

如果你在用自定义 jobId 防重复,同时又有失败后重新入队的设计,值得检查一下这两个机制会不会互相残杀。可能就是我们这种"重试悄悄变成 no-op"的组合。

损失有多大

死了 12 天的功能,听起来损失惨重,实测结果却不是。答复通知因为该功能还没在生产环境真正投入使用,丢失为 0。邮件队列涉及的都是已经过去的日程,没有需要补发的对象。真正要追回的是 2 条没转写的语音。用留存的语音文件重新转写,恢复完成。

运气好。而这种运气不会重复。如果是正在使用中的功能,12 天的通知和转写会原样蒸发,而且任务从一开始就没在队列里创建过,靠部署什么都追不回来。写回填脚本是次要的。我判断,本质要修的是"一个死掉的功能死了 12 天没人知道"这件事本身。于是转写失败不再只留在日志里,而是上报到报警频道;答复通知路径改成了跟事务一起提交的 outbox,让"数据库里记了成功、任务却不存在"这种状态本身不再可能出现。

留下了什么

这次事件里比代码活得更久的三件事。

第一,catch 里只记日志然后正常返回的代码,会让一条 100% 失败的路径没有任何人察觉。要吞,至少得配上统计失败的指标或报警;没有的话,抛出去更好。抛出的错误吵,但会被修好;被吞的错误能活 12 天。

第二,mock 必须和真实契约一样严格。在无条件成功的 mock 之上,任何输入都不会被校验。库里有纯校验函数就让 mock 跑起来,再确认把 bug 改回去时测试会变红,这才是防线。

第三,缺陷要按类别抓。同一个代码库里,同一个错误不会只发生一次。找到一个,就定义出类别做全量排查,再用 lint 规则或公用构建函数把这个类别彻底挡在门外。做到这一步,一次发现才算值回票价。

常见问题

BullMQ 报 'Custom Id cannot contain :' 错误,为什么?

BullMQ v5 禁止自定义 jobId 里出现冒号,因为冒号是它拼接 Redis 键时用的分隔符。准确的条件是 'jobId 含有冒号,且按冒号切分后不是正好 3 段',3 段的例外是为了兼容旧版 repeatable 任务格式。纯数字的 jobId 也会被 'Custom Id cannot be integers' 拒绝。分隔符请用连字符。

用了 mock 的测试为什么抓不到这种 bug?

当 mock 的行为和真实实现的契约不一致时,测试实际上是在为已经死掉的代码盖绿章。把队列的 add 换成无条件成功的 mock,库的输入校验就完全不会执行,一个永远会被拒绝的 jobId 也能通过测试。至少要让 mock 跑一遍库真正的校验函数,再确认把 bug 改回去时测试会变红(变异测试),这才算得上防线。

相关文章

0 条评论