背景
近期，为了评估服务性能，测试同学对关键业务接口进行了压测，单台NodeJS服务开启3个进程的情况下，QPS最高达320多。为了确认服务是否还有优化空间，我们使用阿里云的 NodeJS性能平台 对服务进行分析，定位了服务的瓶颈，并在阿里云的同学帮助下采取了相应的措施，优化了服务的性能。
问题排查与分析
Step1 获取与分析CPU Profile
当我们以400并发量，对单一业务接口进行压测，发现QPS为320时，服务器CPU被打满。为了找到是什么原因导致CPU达到了性能瓶颈，我们使用了阿里云的「NodeJS性能平台」，抓取了压测时的 CPU Profile 信息。
CPU Profile
经过分析，我们发现 _tickDomainCallback 和 garbage collector 在CPU占比很大，其中 _tickDomainCallback占了50%多，GC 也占了27%的比例。通过展开 _tickDomainCallback 里的内容，发现CPU占比高的逻辑主要是TypeORM 和4处业务逻辑。
_tickDomainCallback 展开信息
Step2 排查数据库性能
当我们看到TypeORM时，我们以为是数据库消费不过来（生产与消费能力不匹配，Query队列产生大量堆积），导致TypeORM消耗大量CPU资源。后来，我们进行了第二次压测，并在服务器CPU打满时获取了RDS的性能分析报告。报告显示：
- 数据库CPU使用了15%的资源
- 平均查询响应速度小于15ms
- 无慢查询记录
- 无死锁记录
因此，我们排除了RDS导致TypeORM消耗CPU资源。我们推测可能与TypeORM本身的代码有关，我们使用了一个非常早期的TypeORM版本（v0.0.11）。阿里云的同学推荐我们升级TypeORM的版本试试，看看会不会有所改善。但是最新的TypeORM版本与早期的版本API已经发生了变化，无法进行平滑升级。因此，放弃了对TypeORM优化。
Step3 排查业务逻辑代码
我们将可能影响性能的业务代码进行了Review，发现优化空间并不是很大，代码本身已经经过了精简和优化。无法进行进一步提升，我们将优化重点放在了占比高达27%的 GC 上。
Step4 GC 信息抓取与分析
为了获得详细的GC信息，我们再次进行了压测，并获取了 GC Trace 信息。结果如下图：
GC Trace
从图中，我们可以获取到一些重要信息：
- GC时间占比为26.87%
- 3分钟内，GC暂时时间为47.8s，且scavenge占了大多数
- 平均GC暂停时间为50~60ms
根据这些信息，我们可以得出 scavenge 非常频繁，导致了CPU资源的占用。
scavenge 发生在新生代的内存回收阶段，这个阶段触发条件是， semi space allocation failed(半空间分配失败)。可以推测出，压测期间我们的代码逻辑频繁的生成大量的小对象，导致 semi space很快被分配满，从而导致了 scavenge 回收和CPU资源的占用。既然这样，我们可不可通过调整 semi space（半空间）的大小，减少GC的次数来优化对CPU的占用。
Step5 GC 调优与测试
NodeJS在64位系统上，默认的semi space大小为16M。
我们将 semi space 进行了3次调整，分别设为64M、128M、256M，对不同值情况下的服务进行了压测并获取了对应 GC Trace 和 CPU Profile。
修改 semi space 方法
对于普通node服务：
node index.js --max_semi_space_size=64
对于PM2启动的服务，在pm2的config文件中添加:
node_args: '--max_semi_space_size=64',
1) 64M
将 semi space 修改为64M，并进行线上压测，获取压测时的 GC Trace 和 CPU Profile信息：
GC Profile信息
CPU Profile
对比修改前的数据，我们发现：
- GC的CPU占比从27.5%下降到了7.14%；
- 3分钟内GC次数，从1008次降到了312次。其中，Scavenge的次数从988次下降到了294次；
- GC时间，从原来的47.7s下降到了11.8s
- GC平均暂停时间在40ms左右
GC时间从47.7s下降到了11.8s，相应的，QPS提升了10%。
2) 128M
将 semi space 调整到128M，得到的 GC Trace 和 CPU Profile信息：
GC Trace
CPU Profile
对比64M时的数据，我们可以发现：
- 与64M时GC次相比，GC次数从312下降到了145；
- Scavenge算法回收时间，增加了1倍。从平均50ms涨到了100ms；
- Mark-sweep的次数没有发生变化
- CPU占比略微下降，从7.14降到了6.71
可以看出，将 semi space从64M调整到了128M，性能并没有很大的提升。相反，Scavenge算法回收时间几乎增长了一倍。
3) 256M
将 semi space 调整到256M，得到的 GC Trace 和 CPU Profile信息：
GC Trace
CPU Profile
可以观察到：
- 与128M时相比，GC次数下降了一倍
- 但是Scavenge回收的时间，波动到了150ms。
- CPU占比，也略微下降了一点，降到了5.99
可以看出，将 semi space调整到了 256M，性能并没有显著提升，且增加了 Scavenge 的回收时间。
小结
将 semi space 从16M调整到64M时，GC的CPU占比从27.5%下降到了7.14%，Scavenge算法平均回收耗时减少，QPS提升了10%。继续调大 semi space，性能并没有显著提升，且Scavenge算法回收时间增加。semi space本身用于新生代对象快速分配，不适合调整过大。因此，semi space 设置为64M较为合适。
总结
通过将semi space调大，触发 Scavenge算法回收的概率降低，GC的次数也随之减少。且 Scavenge算法回收内存的时间也较为合理，因而可以降低GC在CPU中的占比。
本文主要介绍了线上服务的性能瓶颈的排查与GC调优，并没有介绍V8 垃圾回收机制的原理。推荐感兴趣的同学，阅读朴灵老师的《深入浅出Node.js》中关于《V8的垃圾回收机制》一节。其中，详细了介绍了V8用到的各种算法，非常有助于理解性能调优的原理。
最后，感谢一下阿里的奕钧同学，在他的帮助下，帮我解决了问题。
网友评论