Node使用火焰图优化CPU爆涨

背景

话不多说，先上图，这是得到App静态资源更新服务的CPU使用率监控，可以看到7月2号到7月3号后，cpu使用率发生了爆涨，在八点的早高峰和下午六点的晚高峰，几乎可以把cpu打满。发现问题当机立断，升级配置将2核4g升级至4核8g，先保证服务稳定，我们再继续查问题。

下图是升级配置后的截图，所以看到的图已经温柔很多了，本人当时看到监控的时候，所有波峰都是打在红线以上的，虽然还没有引起报警，但是默默掏出小本本记下找时间查问题。

问题分析

因为有很明显的发生变化的时间点，直接能找到这一次的改动，经过一点点的代码级review，并没有发现变动的代码上有什么问题。作为一个小前端没遇到过这种问题呀，毫无头绪的我，把救世主锁定在了火焰图身上，想看一看到底什么地方耗时长到底cpu占用在了什么东西上。

火焰图

于是怎么生成火焰图成了我最大的难题，开始Google搜索，“如何生成火焰图” ，“node 火焰图”，“node cpu profiler”， “node flamegraph”。看来看去所有文章千篇一律，95%以上的文章都是如下解决方案。

1.Linux perf

参考文章：nodejs调试指南 perf + FlameGraph

Linux自带的系统性能分析工具，一堆功能我就不多说了，有兴趣的自己去看nodejs调试指南打开书的第一页。因为使用的局限性不是Linux的我，第一步apt install linux-tools-common都安不上，如果还要跑在虚拟机什么的上面是不是太麻烦了，方案一卒。

2.Node.js 自带的分析工具

参考文章：易于分析的 Node.js 应用程序 | Node.js

Node.js4.4.0开始，node本身就可以记录进程中V8引擎的性能信息(profiler)，只需要在启动的时候加上参数--prof。

Node自带的分析工具：

• 启动应用的时候，node需要带上—-prof参数

• 然后就会将性能相关信息收集到node运行目录下生成isolate-xxxxxxxxxxxxx-v8.log文件

• npm有一个包可以方便的直接将isolate文件转换成，html形式的火焰图GitHub - mapbox/flamebearer: Blazing fast flame graph tool for V8 and Node :fire:

• 完成以上步骤火焰图果不其然的跑了出来

可是仔细一看好像不是那么一回事，因为项目用的是egg框架，火焰图里的全部信息都是egg启动的东西啊，我长达五分钟的接口压测，一点都没有体现在火焰图上，一拍脑袋，想起来我用node --prof的形式收集到的性能数据都是egg主进程上的东西，而我们所有的接口全都打到了egg worker上去了，一点都没有收集到。顺便提一句egg提供了单进程模式RFC 增加单进程启动模式 · Issue #3180 · eggjs/egg · GitHub但还只是实验阶段。方案二又卒，好在我起码看到了一张图。

3.使用Dtrace收集性能数据

直接查到应用的pid直接对pid进行收集，然后也可以将收集到的数据制成火焰图，具体操作就不做赘述了，最后跑出来的图如下

全部是一些v8底层的东西，好像也没有我想要看的内容呀，方案三卒。

好了以上就是我Google出来的各种方案在我一一踩坑后全部以失败告终，其实也还有一些更简单的方案，例如直接接入alinode用阿里云的平台就好，一方面该项目没有接入阿里云，刚好用的node镜像又不是ali的，另一方面，如果可以在开发环境查出问题，不希望再通过上线去查问题。

方案四：v8-profiler

Node.js 是基于 V8 引擎的，V8 暴露了一些 profiler API，我们可以通过 v8-profiler 收集一些运行时的CPU和内存数据。

在安装v8-profiler的时候遇到了一些问题总是安装失败，并且得不到解决。不过好在有大神基于v8-profiler发布了v8-profiler-node8，下面是v8-profiler-node8的一段描述。

Based on [email protected], Solved the v8-profiler segment fault error in node-v8.x.v8-profiler-node8 provides node bindings for the v8 profiler and integration with node-inspector收集数据：简单的npm install v8-profiler-node8后，开始收集CPU profile，收集时长五分钟。

然后立即用ab压测，给服务压力，

收集完成后，得到一个cpuProfile文件，Chrome 自带了分析 CPU profile 日志的工具。打开 Chrome -> 调出开发者工具（DevTools） -> 单击右上角三个点的按钮 -> More tools -> JavaScript Profiler -> Load，加载刚才生成的 cpuprofile 文件。可以直接用chrome的性能分析直接读这个文件打开分析。

这里我要推荐一下 speedscope 一个根据cpuProfile生成火焰图的工具，他生成的火焰图，更清晰，还有leftHeavy模式，直接将CPU占用率最高的排在最左边，一目了然，快速的可以定位到问题。

根据火焰图解决问题

下面是该火焰图的leftHeavy模式

看火焰图的时候越图形越尖说明越正常，横条越长说明占用时间越长，从图中可以看到压测的五分钟里，CPU占用时间长达两分钟，其中绝大多数被红框中占据，来张大图

这个火焰图中是由上至下的调用顺序，一眼看过去没有我业务代码中出现的内容，再仔细一看，fetchDocs、Cursor.next、completeMany、Document.init这好像是mongo的东西呀，开心的像个傻子，赶快去搜源码。

从completeMany这里破案了，这是mongoose中的一个方法，作用是将查询到的结果进行包装，使结果中的每一个文档成为mongoose文档，使之可以继续使用mongoose提供的方法。如下相关源码。

completeMany方法会将传入的每一个docs通过 helpers.createModel变成一个mongoose Document，我们再来看一下是哪里调用的completeMany方法，发现在find方法中会判断options.lean是否等于true如果不等于true才会去调用completeMany方法去包装查询结果。

去文档上搜一下lean mongoose query lean 文档上说了如果使用了lean那么查询返回的将是一个javascript objects, not Mongoose Documents 。原话如下。

Documents returned from queries with theleanoption enabled are plain javascript objects, not Mongoose Documents . They have nosavemethod, getters/setters, virtuals, or other Mongoose features.

在文档中还提到了，lean精简模式，对于高性能只读的情况是非常有用的。

优化

回到问题上来，看到mongoose Document的问题，7月2号到7月3号后，为什么会突然导致CPU暴涨恍然大悟，自己之前review代码，看着代码没问题，但是忽略了这一个版本因为业务调整导致查询压力大大增加，可能是过去的好几倍这个问题。随即将查询改成精简模式。只需要如下很简单的几处修改即可。

那说到频繁的处理mongoose Document导致的性能问题，那其实还有一个优化点可以做，其实在查询的时候多多使用find的第二个参数projection去投影所需要返回的键，需要用什么就投影什么，不要一股脑把所有的键值一起返回了。处理完这一系列，重写在本地进行了一次同样的压测五分钟，出了一份火焰图，下面图1就是这五分钟期间的火焰图，图二就是经过speedscope解析过后的leftHeavy图，直接观察重灾区。

从图一的火焰图中，并不能看出明显的区别，但是一看到图二就知道我们的优化是有效果的，从最直观的，原本左侧红框中completeMany的部分直接没有了，然后cpu占用的总时长也由原本的接近两分钟直接降到了36s，优化效果还是十分明显的。上线观察几天看看效果

如图可以看到，cpu使用率在优化后得到了大大提升，并且稳定在了百分之十五以内。问题解决了，一切皆大欢喜，服务器降配一切回到正常。但这次故障也让我对诸如mongoos这样的ODM在使用时需要更加小心谨慎，他给我们带来了无限的便利的同时，可能也会因为一些额外的操作，让我们的服务承受额外的负担，正常情况下这一点性能差距不易察觉，然而到了高峰期，或者大型活动的时侯，可能就会因为这一点小坑，对服务造成更大的影响。

谨记。

关于本文作者：@Harlan原文：https://zhuanlan.zhihu.com/p/76250769

轻点在看，支持作者:heart: