Node程序debug小记

有时候,所见并不是所得,有些包,你需要去翻他的源码才知道为什么会这样。

背景

今天调试一个程序,用到了一个很久之前的NPM包,名为formstream,用来将form表单数据转换为流的形式进行接口调用时的数据传递。

这是一个几年前的项目,所以使用的是Generator+co实现的异步流程。

其中有这样一个功能,从某处获取一些图片URL,并将URL以及一些其他的常规参数组装到一起,调用另外的一个服务,将数据发送过去。

大致是这样的代码:

const co = require('co') const moment = require('moment') const urllib = require('urllib') const Formstream = require('formstream') function * main () { const imageUrlList = [ 'img1', 'img2', 'img3', ] // 实例化 form 表单对象 const form = new Formstream() // 常规参数 form.field('timestamp', moment().unix()) // 将图片 URL 拼接到 form 表单中 imageUrlList.forEach(imgUrl => { form.field('image', imgUrl) }) const options = { method: 'POST', // 生成对应的 headers 参数 headers: form.headers(), // 告诉 urllib,我们通过流的方式进行传递数据,并指定流对象 stream: form } // 发送请求 const result = yield urllib.request(url, options) // 输出结果 console.log(result) } co(main)

也算是一个比较清晰的逻辑,这样的代码也正常运行了一段时间。

如果没有什么意外,这段代码可能还会在这里安静的躺很多年。
但是,现实总是残酷的,因为一些不可抗拒因素,必须要去调整这个逻辑。
之前调用接口传递的是图片URL地址,现在要改为直接上传二进制数据。

所以需求很简单,就是将之前的URL下载,拿到buffer,然后将buffer传到formstream实例中即可。
大致是这样的操作:

- imageUrlList.forEach(imgUrl => { - form.field('image', imgUrl) - }) + let imageUrlResults = yield Promise.all(imageUrlList.map(imgUrl => + urllib.request(url) + )) + + imageUrlResults = imageUrlResults.filter(img => img && img.status === 200).map(img => img.data) + + imageUrlResults.forEach(imgBuffer => { + form.buffer('image', imgBuffer) + })

下载图片 -> 过滤空数据 -> 拼接到form中去,代码看起来毫无问题。

不过在执行的时候,却出现了一个令人头大的问题。
最终调用yield urllib.request(url, options)的时候,提示接口超时了,起初还以为是网络问题,于是多执行了几次,发现还是这样,开始意识到,应该是刚才的代码改动引发的bug。

开始 debug 定位引发 bug 的代码

我习惯的调试方式,是先用最原始的方式,,看有哪些代码修改。
因为代码都有版本控制,所以大多数编辑器都可以很直观的看到有什么代码修改,即使编辑器中无法看到,也可以在命令行中通过git diff来查看修改。

这次的改动就是新增的一个批量下载逻辑,以及URL改为Buffer。
先用最简单粗暴的方式来确认是这些代码影响的,注释掉新增的代码,还原老代码
结果果然是可以正常执行了,那么我们就可以断定bug就是由这些代码所导致的。

逐步还原错误代码

上边那个方式只是一个rollback,帮助确定了大致的范围。
接下来就是要缩小错误代码的范围。
一般代码改动大的时候,会有多个函数的声明,那么就按照顺序逐个解开注释,来查看运行的效果。
这次因为是比较小的逻辑调整,所以直接在一个函数中实现。
那么很简单的,在保证程序正常运行的前提下,我们就按照代码语句一行行的释放。

很幸运,在第一行代码的注释被打开后就复现了bug,也就是那一行yield Promsie.all(XXX)。
但是这个语句实际上也可以继续进行拆分,为了排除是urllib的问题,我将该行代码换为一个最基础的Promise对象:yield Promise.resolve(1)。
结果令我很吃惊,这么一个简单的Promise执行也会导致下边的请求超时。

当前的部分代码状态:

const form = new Formstream() form.field('timestamp', moment().unix()) yield Promise.resolve(1) const options = { method: 'POST', headers: form.headers(), stream: form } // 超时 const result = yield urllib.request(url, options)

再缩小了范围以后,进一步进行排查。
目前所剩下的代码已经不错了,唯一可能会导致请求超时的情况,可能就是发请求时的那些options参数了。
所以将options中的headers和stream都注释掉,再次执行程序后,果然可以正常访问接口(虽说会提示出错,因为必选的参数没有传递)。

那么目前我们可以得到一个结论:formstream实例+Promise调用会导致这个问题。

冷静、忏悔

接下来要做的就是深呼吸,冷静,让心率恢复平稳再进行下一步的工作。
在我得到上边的结论之后,第一时间是崩溃的,因为导致这个bug的环境还是有些复杂的,涉及到了三个第三方包,co、formstream和urllib。
而直观的去看代码,自己写的逻辑其实是很少的,所以难免会在心中开始抱怨,觉得是第三方包在搞我。
但这时候要切记「程序员修炼之道」中的一句话:

"Select" Isn't Broken
“Select” 没有问题

所以一定要在内心告诉自己:“你所用的包都是经过了N久时间的洗礼,一定是一个很稳健的包,这个bug一定是你的问题”。

分析问题

内容版权声明:除非注明,否则皆为本站原创文章。

转载注明出处:https://www.heiqu.com/zgwxsz.html