生产环境偶现一个 BUG,几率非常低。但是自动化测试从来没有失败过,测试环境中也重现不了,当然,生产环境上也很难出现,但是一旦出现,几乎没有办法排查,因为一旦这个 BUG 发生,关联的现象是相关日志也没有打印出来。

分析


日志没有打印出来,也提供了相关线索。通过查看日志打印逻辑,看到有使用 JSON.stringify ,于是猜想是不是被打印的对象中存在循环引用,导致 JSON.stringify 崩溃。但是看了下被序列化的对象,只是一个发 HTTP 请求的 options ,而且详细查看 options 的赋值操作,只是一个 Plain Old JavaScript Object,按理说不会造成 JSON.stringify 崩溃才对。
image.png

这个 HTTP 请求使用了一个公共库,难道是这个公共库修改了 options ?非常不愿意这样设想,但还是去查看了这个公共库的源码,一看果然,它给 options 增加了一个 agent 属性:
image.png

为什么只是偶现?

没有进一步花时间调研,只是根据现象,可以断定在某些网络环境下,这个 httpAgent 或者 httpsAgent ,才会出现循环引用。而且,如果由于并不是所有该公共库的使用者,都会 JSON.stringify(options) ,所以,之前一直没有人发现和上报这个问题。

修复

在向这个公共库传入 options 前,拷贝一个副本,并在后续打印日志时,确保使用那个未受污染的副本。
image.png

教训

  • 不要修改入参!尤其是 API 的提供者,只能读取上游传来的参数,而不能修改入参。否则就会造成副作用,而且很难被发现。
  • **不要滥用 JSON.stringify **,大多数日志目的的变量打印,可以用 util.inspect 代替。