Node.js 应用故障排查手册 —— 综合性 GC 问题和优化

楔子

本章前面两节生产案例分别侧重于单一的 CPU 高和单一的内存问题，咱们也给你们详细展现了问题的定位排查过程，那么实际上还有一类相对更复杂的场景——它本质上是 V8 引擎的 GC 引起的问题。

简单的给你们介绍下什么是 GC，GC 其实是语言引擎实现的一种自动垃圾回收机制，它会在设定的条件触发时（好比堆内存达到必定值）时查看当前堆上哪些对象已经再也不使用，而且将这些没有再使用到的对象所占据的空间释放出来。许多的现代高级语言都实现了这一机制，来减轻程序员的心智负担。

本书首发在 Github，仓库地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，云栖社区会同步更新。

GC 带来的问题

虽然上面介绍中现代语言的 GC 机制解放了程序员间接提高了开发效率，可是万事万物都存在利弊，底层的引擎引入 GC 后程序员无需再关注对象什么时候释放的问题，那么相对来讲程序员也就没办法实现对本身编写的程序的精准控制，它带来两大问题：

• 代码编写问题引起的内存泄漏
• 程序执行的性能下降

内存泄漏问题咱们已经在上一节的生产案例中体验了一下，那么后者是怎么回事呢？

其实理解起来也很简单：本来一个程序所有的工做都是执行业务逻辑，可是存在了 GC 机制后，程序总会在必定的条件下耗费时间在扫描堆空间找出再也不使用的对象上，这样就变相下降了程序执行业务逻辑的时间，从而形成了性能的降低，并且下降的性能和耗费在 GC 上的时间，换言之即 GC 的次数 * 每次 GC 耗费的时间成正比。

问题现象与原始分析

如今你们应该对 GC 有了一个比较总体的了解，这里咱们能够看下 GC 引起的问题在生产中的表现是什么样的。在这个案例中，表象首先是 Node.js 性能平台 上监控到进程的 CPU 达到 100%，可是此时服务器负载其实并不大，QPS 只有 100 上下，咱们按照前面提到的处理 CPU 问题的步骤抓取 CPU Profile 进行分析能够看到：

此次的问题显然是 Garbage Collector 耗费的 CPU 太多了，也就是 GC 的问题。实际上绝大部分的 GC 机制引起的问题每每表象都是反映在 Node.js 进程的 CPU 上，而本质上这类问题能够认为是引擎的 GC 引发的问题，也能够理解为内存问题，咱们看下这类问题的产生流程：

• 堆内存不断达到触发 GC 动做的预设条件
• 进程不断触发 GC 操做
• 进程 CPU 飙高

并且 GC 问题不像以前的 ejs 模板渲染引起的问题，就算咱们在 CPU Profile 中能够看到这部分的耗费，可是想要优化解决这个问题基本是无从下手的，幸运的是 Node.js 提供了（实际上是 V8 引擎提供的）一系列的启动 Flag 可以输出进程触发 GC 动做时的相关日志以供开发者进行分析：

• --trace_gc:一行日志简要描述每次 GC 时的时间、类型、堆大小变化和产生缘由
• --trace_gc_verbose: 结合 --trace_gc 一块儿开启的话会展现每次 GC 后每一个 V8 堆空间的详细情况
• --trace_gc_nvp: 每一次 GC 的一些详细键值对信息，包含 GC 类型，暂停时间，内存变化等信息

加粗的 Flag 意味着咱们须要在启动应用前加上才能在运行时生效，这部分的日志其实是一个文本格式，惋惜的是 Chrome devtools 原生并不支持 GC 日志的解析和结果展现，所以须要你们获取到之后进行对应的按行解析处理，固然咱们也可使用社区提供 v8-gc-log-parser 这个模块直接进行解析处理，对这一块有兴趣的同窗能够看 @joyeeCheung 在 JS Interactive 的分享: Are Your V8 Garbage Collection Logs Speaking To You?，这里不详细展开。

更好的 GC 日志展现

虽然 Chrome devtools 并不能直接帮助咱们解析展现 GC 日志的结果，可是 Node.js 性能平台 其实给你们提供了更方便的动态获取线上运行进程的 GC 状态信息以及对应的结果展现，换言之，开发者无需在运行你的 Node.js 应用前开启上面提到的那些 Flag 而仍然能够在想要获取到 GC 信息时经过控制台拿到 3 分钟内的 GC 数据。

对应在这个案例中，咱们能够进入平台的应用实例详情页面，找到 GC 耗费特别大的进程，而后点击 GC Trace 抓取 GC 数据：

这里默认会抓取 3 分钟的对应进程的 GC 日志信息，等到结束后生成的文件会显示在 文件 页面：

此时点击 转储 便可上传到云端以供在线分析展现了，以下图所示：

最后点击这里的 分析 按钮，便可看到 AliNode 定制后的 GC 信息分析结果的展示：

结果展现中，能够比较方便的看到问题进程的 GC 具体次数，GC 类型以及每次 GC  的耗费时间等信息，方便咱们进一步的分析定位。好比此次问题的 GC Trace 结果分析图中，咱们能够看到红圈起来的几个重要信息：

• GC 总暂停时间高达 47.8s，大头是 Scavenge
• 3min 的 GC 追踪日志里面，总共进行了 988 次的 Scavenge 回收
• 每次 Scavenge 耗时均值在 50 ~ 60ms 之间

从这些解困中咱们能够看到这次 GC 案例的问题点集中在 Scavenge 回收阶段，即新生代的内存回收。那么经过翻阅 V8 的 Scavenge 回收逻辑能够知道，这个阶段触发回收的条件是：Semi space allocation failed。

这样就能够推测，咱们的应用在压测期间应该是在新生代频繁生成了大量的小对象，致使默认的 Semi space 老是处于很快被填满从而触发 Flip 的状态，这才会出如今 GC 追踪期间这么多的 Scavenge 回收和对应的 CPU 耗费，这样这个问题就变为如何去优化新生代的 GC 来提高应用性能。

优化新生代 GC

经过平台提供的 GC 数据抓取和结果分析，咱们知道能够去尝试优化新生代的 GC 来达到提高应用性能的目的，而新生代的空间触发 GC 的条件又是其空间被占满，那么新生代的空间大小由 Flag --max-semi-space-size 控制，默认为 16MB，所以咱们天然能够想到要能够经过调整默认的 Semi space 的值来进行优化。

这里须要注意的是， 控制新生代空间的 Flag 在不一样的 Node.js 版本下并非同样的，你们具体能够查看当前的版原本进行确认使用。

在这个案例中，显然是默认的 16M 相对当前的应用来讲显得比较小，致使 Scavenge 过于频繁，咱们首先尝试经过启动时增长 --max-semi-space-size=64 这个 Flag 来将默认的新生代使用到的空间大小从 16M 的值增大为 64M，而且在流量比较大并且进程 CPU 很高时抓取 CPU Profile 观察效果：

调整后能够看到 Garbage collector 阶段 CPU 耗费占比降低到 7% 左右，再抓取 GC Trace 并观察其展现结果确认是否是 Scavenge 阶段的耗费降低了：

显然，Semi space 调大为 64M 后，Scavenge 次数从近 1000 次下降到 294 次，可是这种情况下每次的 Scavenge 回收耗时没有明显增长，仍是在 50 ~ 60ms 之间波动，所以 3 分钟的 GC 追踪总的停顿时间从 48s 降低到 12s，相对应的，业务的 QPS 提高了约 10% 左右。

那么若是咱们经过 --max-semi-space-size 这个 Flag 来继续调大新生代使用到的空间，是否是能够进一步优化这个应用的性能呢？此时尝试 --max-semi-space-size=128 来从 64M 调大到 128M，在进程 CPU 很高时继续抓取 CPU Profile 来查看效果：

此时 Garbage collector 耗费降低相比上面的设置为 64M 并非很明显，GC 耗费降低占比不到 1%，一样咱们来抓取并观察下 GC Trace 的结果来查看具体的缘由：

很明显，形成相比设置为 64M 时 GC 占比提高不大的缘由是：虽然此时进一步调大了 Semi space 至 128M，而且 Scavenge 回收的次数确实从 294 次降低到 145 次，可是每次算法回收耗时近乎翻倍了，所以总收益并不明显。

按照这个思路，咱们再使用 --max-semi-space-size=256 来将新生代使用的空间进一步增大到 256M 再来进行最后一次的观察：

这里和调整为 128M 时是相似的状况： 3 分钟内 Scavenge 次数从 294 次降低到 72 次，可是相对的每次算法回收耗时波动到了 150ms 左右，所以总体性能并无显著提高。

借助于性能平台的 GC 数据抓取和结果展现，经过以上的几回尝试改进 Semi space 的值后，咱们能够看到从默认的 16M 设置到 64M 时，Node 应用的总体 GC 性能是有显著提高的，而且反映到压测 QPS 上大约提高了 10%；可是进一步将 Semi space 增大到 128M 和 256M 时，收益确并不明显，并且 Semi space 自己也是做用于新生代对象快速内存分配，自己不宜设置的过大，所以此次优化最终选取对此项目 最优的运行时 Semi space 的值为 64M。

结尾

在本生产案例中，咱们首先能够看到，项目使用的三方库其实也并不老是在全部场景下都不会有 Bug 的（实际上这是不可能的），所以在遇到三方库的问题时咱们要勇于去从源码的层面来对问题进行深刻的分析。

最后实际上在生产环境下经过 GC 方面的运行时调优来提高咱们的项目性能是一种你们不那么经常使用的方式，这也有很大一部分缘由是应用运行时 GC 状态自己不直接暴露给开发者。经过上面这个客户案例，咱们能够看到借助于 Node.js 性能平台，实时感知 Node 应用 GC 状态以及进行对应的优化，使得不改一行代码提高项目性能变成了一件很是容易的事情。

---

本文做者：奕钧

阅读原文

本文为云栖社区原创内容，未经容许不得转载。