快速定位NodeJs线上问题 - 之火焰图篇-白红宇

0x01 背景

前段时间，公司监控群内报警，某个nodeJs项目 CPU 被打满，运维大哥快速重启解决，由于现场没有保留没定位到具体问题。2周后同样的报警又出来了，只能再次祭出重启大法，按照预期果然好了。但是这问题得解啊，总不能让运维老哥哥们写个脚本每两周就重启一次吧。

在定位问题时，发现了有个叫火焰图的工具可以帮助快速准确的定位问题，简直神器，不至于猜来猜去。但是在查找相关资料的时候，发现google到的信息基本都是6、7年前的文章。难道火焰图已经过时了吗，现在已经有更好的方式来定位问题了吗？带着这些疑问决定从根源了解下火焰图的由来。

0x02 火焰图在nodeJs中的发展历程

火焰图本身并不复杂。但是结合 Node.js 的发展历程，每个阶段生成火焰图的形式都有所不同，把我能搜集到的方式列出来，可以根据自己的实际情况进行选择。

1、大神发明了火焰图，并在 2011年12月正式对外发布。

2、紧接着在 2012年1月用DTrace来抓取node项目的profile并使用火焰图来分析性能。

同期 David Pacheco 又在npm上发布了一个可以统计火焰图的package，有兴趣可以看下他的源码实现，代码不多。

3、2013年的时候，Google发布了 Google Chrome’s performance analysis tool，就是我们常用的chrome浏览器中的profile收集工具。

4、2013年12月, V8添加了对 perf_events 的支持，允许使用 --perf-basic-prof 参数。支持版本为v0.11.13。使用方法如下：

# *~/node-v0.11.13-linux-x64/bin/node --perf-basic-prof hello.js &*[1] 31441# *ls -l /tmp/perf-31441.map*-rw-r--r-- 1 root root 81920 Sep 17 20:41 /tmp/perf-31441.map# *tail /tmp/perf-31441.map*14cec4db98a0 f Stub:BinaryOpICWithAllocationSiteStub(ADD_CreateAllocationMementos:String*Generic->String)14cec4db9920 f Stub:BinaryOpICWithAllocationSiteStub(ADD_CreateAllocationMementos:String*String->String)14cec4db99a0 f Stub:BinaryOpICWithAllocationSiteStub(ADD_CreateAllocationMementos:String*Smi->String)14cec4db9a20 22c LazyCompile:~nextTick node.js:38914cec4db9cc0 156 Stub:KeyedLoadElementStub14cec4db9e80 22 KeyedLoadIC:14cec4db9f20 22 KeyedLoadIC:14cec4db9fc0 56 Stub:DoubleToIStub14cec4dba080 10c Stub:KeyedStoreElementStub复制代码

5、2016年，Node 决定将 Chrome 浏览器的"开发者工具"作为官方的调试工具，使得 Node 脚本也可以使用图形界面调试，这大大方便了开发者。可以参考。

$ node --inspect app.js$ node --inspect-brk=9229 app.js复制代码

这个方法截止目前为止应该是比较方便的抓取方式，本文后面对该方法会有一个详细的介绍。

6、 2016年，ebay 发表了一篇文章，介绍了他们使用 v8-profiler 生成 Node.js 火焰图的过程：

目前 v8-profiler 作者应该已经弃坑，可以使用的 v8-profiler-next，支持 Node v4.x ~ v10.x版本。

7、2017年底，阿里云发布了alinode这个性能分析利器，我们有幸成为第一批使用者，为之后的几次重大活动提功力强有力的保障。

使用alinode可以很方便的一键抓取线上 cpu profile 并进行性能分析。

8、 2018年8月，诞生了一个好用的火焰图分析工具 ,支持3种分析模式，下面有对这个工具详细介绍。

0x03 火焰图的含义

上面已经大致了解了nodeJs里面火焰图的历史。下面来说说如何看懂一张火焰图吧，下图是我们真实项目中的一次压测时抓取的数据。

火焰图基本含义：（来源：）

每一个小块代表了一个函数在栈中的位置（即一个栈帧）。

y 轴表示调用栈，每一层都是一个函数。调用栈越深，火焰就越高，顶部就是正在执行的函数，下方都是它的父函数。

x 轴表示抽样数，如果一个函数在 x 轴占据的宽度越宽，就表示它被抽到的次数多，即执行的时间长。注意，x 轴不代表时间，而是所有的调用栈合并后，按字母顺序排列的。

小块的宽度代表 CPU 的使用时间，或者说相对于父函数而言使用 CPU 的比例（基于所有样例），越宽则代表占用 CPU 的时间越长，或者使用 CPU 很频繁。如果一个函数在顶层占据的宽度最大，就表示该函数可能存在性能问题。

0x04 案例分析

根据上一环节对火焰图的定义，结合上图的压测数据，已经标注出三个优先级最高，可能存在问题的地方：

图中问题1：是Axios中的 request 方法，在顶层占用宽度最大，楼层最高。所以需要优先排查。

图中问题2：是Axios中的transformResponse 方法，后来看了源码，该函数的作用是如果response中为String类型时，会进行JSON.parse()操作。

图中问题3：是nunjucks模板引擎渲染页面时，进行序列化的方法。

结合实际情况，下图为该问题发生时大致的效果（因为现场图没有保存下来，下面是后来压测模拟的效果）

CPU使用率飙升，已经达到100%，服务几乎被压死。但当时qps并不高，只是直接压了有问题的接口。

TCP链接的 TIME_WAIT 也在持续增长。

根据上面分析，猜测应该是图中问题1的地方所导致的。从代码中定位到确实是我们内部framework中对axios统一封装的 fetch 方法没有处理好导致。问题2、3虽然有优化空间，但不是导致CPU飙升的根源所在。修改后压测数据终于恢复正常。

0x05 最佳实践

上面火焰图历史的部分已经介绍了很多种抓取火焰图的方法，但是很多方法上手难度较高，有的需要侵入代码进行改造。

1、收集

NodeJs v6.3.0+ 推荐使用 --inspect 来抓取，并且使用 chrome-devtools:// 来分析。

运行node时添加--inspect 参数

node --inspect app.js复制代码

打开chrome浏览器，直接输入 chrome://inspect ，如下图的地方选择 inspect。

点击start后就可以对node项目进行压测了。

压测成功后，保存 CPU-xx.cpuprofile cpuprofile文件到本地。

2、分析

推荐使用来分析火焰图的趋势，打开官网，选择刚才本地保存的文件，支持在线分析也可以安装speedscope到本地。它支持三种模式：

Time Order 模式：默认按照时间顺序排列；

Left Heavy 模式：会把最宽的堆栈放在最左侧，依次往右排列，便于快速定位问题；

1. Sandwich 模式：可以看到每个函数的相关的时间；

3、验证

优化后，配合（红蓝火焰图）分析前后两次profile的趋势变化。