一次Node.js的性能问题排查

前几天,我们发现了一个性能问题,当数据量过大时,由于请求超时,导致我们的web应用的某个页面数据加载不出来。这篇文章用来记录下当时的排查过程,以及一些思考。

初步定位问题

通过查看请求日志,我们定位到了Node的某个接口。一开始,我们认为是MySQL的IO耗时过长导致的,但是通过查看MySQL的慢日志并没有发现相关的查询语句,从而排除了MySQL查询的因素。

由于当数据量过大时,才出现的这个问题,所以我们将怀疑点转移到了嵌套的2层for循环中。通过在测试环境进行打点输出执行时间,发现确实是这2层for循环导致的,在数据量过大时,消耗了将近20s。我们知道Node不擅长做CPU密集型计算,所以在循环里面并没有做复杂的计算逻辑,只是一些判断和object的拆解、组合,为什么会消耗这么长的时间呢?

定位问题细节

为了方便测试,我将数据导了一份到本地,然后在本地写了一个sample来进行测试和进一步定位。通过WebStorm自带的V8 profiling工具,执行并分析了这段代码。下面是V8 profiling log的分析图:

WX20180118-115135.png

通过这张图片可以看出来,cpu耗时最高的是lodash中的名为copyObject的方法。逐个检查代码中用到了lodash的地方,最终定位到了_.defaults方法。由于我们object的key是固定的,所以我们将_.defaults方法去掉了,直接赋值给object的相应key,像下面这样:

1
2
3
4
5
const res = {
'key1': object.key1 || source1.key1 || source2.key1,
'key2': object.key2 || source1.key2 || source2.key2,
'key3': object.key3 || source1.key3 || source2.key3,
}

修改后,我们成功使该接口的请求时间降低到了8~9s。

进一步优化

其实,8~9s的耗时也是无法接受的。当然优化要一步一步地来,接下来我们准备做的方案就是将数据拆分返回,类似分页查询那样,这样的话,每个接口的请求耗时都比较小,只不过前端需要多发送几次请求而已。

思考 —— defaults方法剖析

问题虽然解决了,但是秉着一颗与源码死磕到底的心,我还是想去源码里面看看到底是什么消耗了过多的CPU时间。下面是defaults方法的源码

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
function defaults(object, ...sources) {
object = Object(object)
sources.forEach((source) => {
if (source != null) {
source = Object(source)
for (const key in source) {
const value = object[key]
if (value === undefined ||
(eq(value, objectProto[key]) && !hasOwnProperty.call(object, key))) {
object[key] = source[key]
}
}
}
})
return object
}

可以看到,首先他为了防止传入的数据不是object,而分别对object,source调用了Object()方法。然后用forEach()方法循环sources这个object数组。接着循环source中的每一个key,查看校验object中有没有该key值,如果没有,则赋值:object[key] = source[key]

可优化点:

  • object()方法在我们的使用场景下,没有必要,因为传入的必然是object。
  • forEach()方法的执行效率,比普通的for(let i = 0; i < arr.length; i ++)要低不少。
  • (eq(value, objectProto[key]) && !hasOwnProperty.call(object, key))这一部分的判断,在我们的使用场景下,也没有必要。

总结

最后,作为一个完备、全面的第三方库来说,适应各种情况的输入值并做完整的参数校验是很有必要的。所以当你需要使用某个第三方库的时候,不妨想一想是否有必要,是否可以直接用更简单直接的方式实现。有时候,最直接的方式,也许是最快的 :)。

当前网速较慢或者你使用的浏览器不支持博客特定功能,请尝试刷新或换用Chrome、Firefox等现代浏览器