记-Nodejs埋点服务-定位cpu瓶颈

538 阅读2分钟

1. 定位cpu瓶颈代码

定位nodejs cpu 性能瓶颈,有好多方法。目的都是为了拿到个火焰图,我试了个遍做个小总结

关于火焰图: 如何读懂火焰图?- 阮一峰, 我的经验就是检查火焰图的大平层,即那些高耗时的函数。Nodejs 是对密集型函数是否敏感的语言,因为cpu密集型计算会阻塞事件循环, 致命的影响QPS,解决干掉那些高cpu 耗时的密集型函数对QPS的提升至关重要

1.1 v8-profiler

裂墙推荐: www.speedscope.app/

// 这里使用@hyj1991 base v8-profile(官方不再维护) const profiler = require('v8-profiler-node8'); 
const fs = require('fs');
const profileTime = 60 * 000 const delay = 30 * 000  setTimeout(function () {
    console.log('start profile');
    profiler.startProfiling('CPU profile');
    setTimeout(function () {
      const profile = profiler.stopProfiling();
      console.log('end profile');
      profile.export()
        .pipe(fs.createWriteStream(`cpuprofile-${Date.now()}.cpuprofile`))
        .on('finish', () => profile.delete())
    }, profileTime)
  }, delay)
  
// 压测 // ab -t 300 -c 10 "http://localhost:8030/golden/stat?xxxx" // 当前路径下生成 cpuprofile-1578464113338-v8.cpuprofile

当前路径下生成 cpuprofile-1578464113338-v8.cpuprofile, 那么如何分析呢?

使用 Chrome DevTools

打开Chrome -> 打开开发者工具 -> 点击右上角三个点按钮 -> More tools -> JavaScript Profiler -> Load,加载刚生成的 cpuprofile 文件

img

img

使用Speedscopewww.speedscope.app/

  • 打开网站Speedscope,加载刚生成的 cpuprofile 文件
  • 它支持Chrome DevTools 里的 按时间线显示、按比重上到下排序显示
  • 它支持Left Heavy 统计所有时间线,将占比重的放左侧,且仍然保留火焰图的分析能力,简直太棒了
    img

通过这张图,我们很快很方便知道了我们服务里业务逻辑耗时的部分

  • 8% CPU 花在了这个函数,lib/golden.js 每个请求使用了 ua-device这个模块, 来根据 req.headers['user-agent'] 获取移动设备的各种型号, 里面6000多行,各种正则匹配、提取。以下代码占比了整个服务 8% 的耗时
const UA = require('ua-device')
// origin 端上报的设备型号 var uaObj = new UA(req.headers['user-agent'])
var os_type = origin.ot || uaObj.os.name var os_version = origin.ov || uaObj.os.version

因为99.9%的流量端上报都会带上该设备的型号和版本,故这 8%cpu 密集型计算6000行代码是不必要的。

即使端上不上报,我们后台统计设备需要如此详细多样的设备数不? 如果不必要我们可以自己写个几十行代码统计下业务主流关系的设备和版本代替这个库, 做如下修改即可

const UA = require('ua-device')
if (!origin.ot || !origin.ov) { // 绝大大大部分流量不需要这 8% cpu的密集型计算    var uaObj = new UA(req.headers['user-agent'])
}
var os_type = origin.ot || uaObj.os.name var os_version = origin.ov || uaObj.os.version
  • 4% CPU 花在了这个函数 ,lib/golden.js
var timer = new Date()
var sendData = {
 logtime: +timer,
 jsonMsg: {
    // formatDate 这个公用函数中使用了正则来支持个性化formate yyyy-MM-dd hh:mm:ss     server_time: utils.formatDate(timer) 
 }
}

我们在看看背后的查询这个server_time 有用么? 如下图可见本身logtime 这个字段根据规范背后会自动被formate成期望格式,故server_time字段可移除,

img

另外一个问题,我们自己的 utils.formatDate耗时正常么,有优化空间不? 是不是都这么慢?然后拿官方dateformat 简单写了个性能测试,对比了下

# debug 跑 dateformat 10000 count spend 108 ms
utils.formatDate 10000 count spend 879 ms

# 非degbug 跑 dateformat 10000 count spend 116 ms
utils.formatDate 10000 count spend 62 ms

不知道为啥 不同跑的方式有这么大差距,相关逻辑里没有任何日志等区别调试环境的内容,难道用到的原生函数底层有debug的区别,待进一步探索

1.2 perf

nodejs官方中文文档: nodejs.org/zh-cn/docs/…

# node app.js # 执行 ab 压测 请求服务 # ps -ef  找出 node pid , 特别是cluster 执行,找到其中一个worker perf record -F 99 -p <pid> -g -- sleep 30 # 上面输出 perf.data  处理输出perfs.out perf script > perfs.out
npm i -g stackvis
stackvis perf < perfs.out > flamegraph.htm
# 输出火焰图 flamegraph.html

问题

  • perf 是linux 上工具,本地mac 无法使用,需要登录测试环境,预发环境
  • 生成火焰图在预发环境,无法下载访问,npm i puer -g , 工程路径执行puer 启动静态服务来访问预发环境的火焰图
  • 在生成的火焰图,由于数量太大,函数文字各种重叠无法正常查看,故此路就探索到此

1.3 使用 Node.js 内置的探查器

nodejs官方中文文档: nodejs.org/zh-cn/docs/…

# 启动服务 NODE_ENV=production node --prof app.js
# 对服务热处理 curl -X GET "http://localhost:8080/newUser?username=matt&password=password" # 进行压测 ab -k -c 20 -n 250 "http://localhost:8080/auth?username=matt&password=password" # -k Use HTTP KeepAlive feature # -c Number of multiple requests to make at a time 并发数 # -n Number of requests to perform 总请求数 # -t 总压测时间 秒 # 你能获得当前服务,在当前环境的一个qps量 # 上面在当前目录路径下,产生了刻度文件xxx-v8.log # 通过nodejs 自带的处理文件进行转换统计为可阅读文件 node --prof-process isolate-0xnnnnnnnnnnnn-v8.log > processed.txt
 [Summary]:
   ticks  total  nonlib   name
     25 6.1%    6.2%  JavaScript
    341 83.6%   84.6%  C++      14 3.4%    3.5%  GC
      5 1.2%          Shared libraries
     37 9.1%          Unaccounted
 [JavaScript]:
   ticks  total  nonlib   name
      2 0.5%    0.5%  Function: ~fs.readFileSync fs.js:548:27
      ...

问题

# install flamebearer (Node v8.5+ required) $ npm install -g flamebearer
# profile your app $ node --prof app.js
# generate flamegraph.html from a V8 log and open it in the browser $ node --prof-process --preprocess -j isolate*.log | flamebearer
# 立马生成了火焰图
  • 分析结果文件里一眼望过去没有什么业务代码函数,更多的是c++、原生js函数,不好定位问题
  • 如何控制时间,貌似node --prof-process 启动后就已经开始 对node代码进行分析了,这个时候压测未开始
  • 如何指定分析特定进程pid,对应egg默认cluster 启动,分析的应该是不干业务逻辑的主进程,我们服务是基于egg 封装的框架degg实现的,故此路就探索到此

1.4 Alinode

alinode官方文档

  • 创建 App ID 和 App Secret
# 安装版本管理工具 tnvm,安装过程出错参考:https://github.com/aliyun-node/tnvm wget -O- https://raw.githubusercontent.com/aliyun-node/tnvm/master/install.sh | bash source ~/.bashrc
# tnvm ls-remote alinode 查看需要的版本 tnvm install alinode-v3.11.4 # 安装需要的版本 tnvm use alinode-v3.11.4 # 使用需要的版本 npm install @alicloud/agenthub -g # 安装 agenthub
  • 本地启动agenthub
// aliconfig.json
{
  "appid": "xxxx",                         
  "secret": "xxxx" }
agenthub start aliconfig.json
  • 本地启动服务
ENABLE_NODE_LOG=YES node demo.js  #环境变量必要 # 进行 ab 压测

img

问题

  • 依赖alinode
  • 后台分析不开源,数据需要上报
  • 其他功能全面

1.5 NodeX 性能分析平台 (对内)

我们NodeX FT在公司内部搭建的Nodejs性能分析平台 nodex.xiaojukeji.com/monitor

接入文档: xingyun.xiaojukeji.com/docs/nodex#…

img

作者:陈钦辉【 滴滴出行资深软件开发工程师】