博文开始前,先贴下本文目录, 次要篇幅在第二局部:如何定位。
前言(背景)
外部管理系统,Node.js我的项目线上运行始终稳固、失常, 某天开始应用人员反馈系统拜访卡顿,同时对应服务器呈现CPU 占用 95% ~ 120%过高的钉钉告警,超过100%是因为对应Linux服务器是多核, 呈现后1~5分钟后失常,偶发呈现,这次问题持续时间较长,参考、浏览了不少文章,写个博文记录、总结下。
问题呈现 ~ 解决工夫 2021.07.21 ~ 2021.08.01
先说下外部零碎技术架构,前端React, 后端NodeJS框架Egg.js(Koa2封装)。所以监控定位时有些 NodeJs 库不适宜接入,这个第二局部具体讲。
如何定位
Node我的项目接入性能监控平台
NodeJs我的项目呈现CPU占用100%以上时,登录对应服务器命令行 top -c
查看以后服务器哪个过程占用CPU最高!
对于偶发场景,不可能始终开着终端,且呈现问题了没有监控告警,无奈晓得呈现问题的具体工夫,不不便定位解决问题。
所以须要接入性能监控平台,具体可看 如何接入Node监控平台 – alinode , 咱们是外部服务器部署了aliNode,操作界面差不多。接入胜利后,呈现CPU过高时有以下图表:
当然也有其余 Node.js 插件能实现相似的监控,具体参考: NodeJs调试指南, 接入胜利后次要看两项: 火焰图
和 GC Trace(垃圾回收跟踪)
火焰图
火焰图(Flame Graph)大家应该听过,它能够将 CPU 的应用状况可视化,使咱们直观地理解到程序的性能瓶颈。咱们通常要联合操作系统的性能剖析工具(profiling tracer)应用火焰图,常见的操作系统的性能剖析工具如下:
Linux:perf, eBPF, SystemTap, and ktap。
Solaris, illumos, FreeBSD:DTrace。
Mac OS X:DTrace and Instruments。
Windows:Xperf.exe。
如果未接入NodeJs性能监控, 得在服务器(个别是Linux)装置以上剖析工具;
接入NodeJs性能监控后能一键导出 火焰图
, 了解火焰图网上很多教程, 例如: 疾速定位NodeJs线上问题 – 之火焰图篇
实践上通过火焰图
能具体定位到具体是哪一行代码导致CPU 过高。
然而,这边实际发现火焰图两问题:
1)时效性不够
例如 Node性能监控上 “抓取性能数据” – 生成火焰图, 生成的是 最近5分钟 的火焰图, 呈现问题(看到钉钉告警)再下来“抓取”生成的 可能是失常运行代码的火焰图
。
2)无奈定位到具体代码
即便CPU过高问题继续很久, “抓取”的是异样运行状态下的火焰图
,也有可能发现生成的图不对劲,无奈与咱们业务代码锲合,这边就遇到生成的火焰图
无奈定位到具体代码(-_-||。
不同我的项目不一样,或者 火焰图
能帮忙大家定位到具体代码。
顺便说下,Node性能监控平台个别能导出 火焰图
文件, 导出的文件名如: u-c3979add-7db3-4365-b1ed-9a2556b6a320-u-x-cpuprofile-4012-20210730-241648.cpuprofile
, 在 Chrome 上可导入:
GC Trace(垃圾回收跟踪)
Node 底层V8引擎的垃圾回收个别跟内存相干,为什么CPU过高要看 垃圾回收跟踪数据?
因为 NodeJs 内存泄露
会导致超过 V8引擎 垃圾回收最大内存(1.4G),进而重启 V8 GC 导致 CPU 100%。
默认状况下,32位零碎新生代内存大小为16MB,老生代内存大小为700MB,64位零碎下,新生代内存大小为32MB,老生代内存大小为1.4GB。
当然可批改 V8 垃圾回收最大内存上限值:
# node在启动时能够传递参数来调整限度内存大小。以下形式就调整了node的应用内存
node --max-old-space-size=1700 // 单位是MB
node --max_semi_space_size=1024 // 单位是KB
以下截图内容 引自Node.js 利用故障排查手册, 思考脱敏就不必外部监控零碎截图。
!
Node性能监控平台, 默认会抓取 5 分钟的对应过程的 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 来晋升利用性能。
这里可能有同学看不懂 Scavenge GC
和 Mark-sweep GC
。
具体到业务代码来说 Scavenge GC
就是一些占用内存比拟小的长期变量 回收解决。
而 Mark-sweep GC
是占用内存小的全局变量 或 占用内存大的长期变量 回收解决。
总的来说, 只有呈现 GC Trace(垃圾回收跟踪)
工夫过长, 个别都是 内存泄露
导致超过 V8引擎 垃圾回收最大内存(1.4G)进而重启 V8 GC 导致 CPU 100%。
具体看 深入浅出Node(第五章内存管制) – 微信读书, 国内最经典的NodeJS书籍《深入浅出Node》尽管是2013年12月1日出版,但对于 V8引擎垃圾回收机制 内容放当初也不过时,V8引擎 官网最近对于垃圾回收机制更新(2019 – V8 引擎官网:GC算法更新 )内容根本没变,只是Mark-sweep GC
阶段增加了三优化机制。
这边场景,察看到 GC Trace
相干数据失常, 所以排除 内存泄露
导致CPU过高。
独自服务器部署
通过 火焰图
和 GC Trace
还是无奈定位到具体代码怎么办?每天都会呈现 2 ~ 3次, 狐疑是服务器其余服务影响, 也思考到须要 多台服务器 来重现模仿问题。
所以跟运维申请全新的一台服务器,配置能够低一些, 次要用于排除烦扰。
在新服务器部署代码后, 将拜访域名 独自 映射到新服务器, 而后持续察看 是否呈现 CPU 飙高状况。 论断是 新服务器运行的代码 还是呈现 CPU 占用 100%以上状况:
当然独自服务器的 CPU 趋势 更加的直观, 失常运行CPU 占用率为 1 ~ 5%。
拜访日志增加
为什么 域名只映射到这台新服务器?次要不便增加、查看日志, 多台服务器的话用户拜访记录太扩散,徒增剖析、整顿日志 工夫老本。
EggJs日志 API 可记录 用户每次拜访的页面, 或二级页面弹层时加载数据 等 API数据申请;
在 中间件 增加记录拜访日志代码, 动态文件申请疏忽。
// app -> middleware -> init.ts
if (!reqPath.includes('/public/')) {
ctx.logger.warn('reqPath:', reqPath);
}
增加胜利后日志中,蕴含 “WARN”就是用户拜访历史记录:
备注: 增加用户历史拜访后,日志体积会增大,咱们外部零碎拜访的人不多,每天大略产生 3M 日志数据, 可思考增加定时清理日志脚本,每天定时清理。
egg 定时工作API,对应清理日志脚本:
import { Subscription } from 'egg';
import * as fs from 'fs';
import * as child_process from 'child_process';
const CLEAR_WHITE_LIST = ['common-error.log', 'my_app-web.log']; // 保留日志白名单
class ClearLogs extends Subscription {
static get schedule() {
return {
cron: '0 30 7 * * *', // 每天查看一次
type: 'worker', // 每台机器,随机指定某个过程进行执行定时工作
// immediate: true, // 为true时,启动时间接执行
};
}
/**
* subscribe 是真正定时工作执行时被运行的函数
*/
async subscribe() {
const { ctx } = this;
ctx.logger.info('开始清理日志!');
this.clearLog();
}
async clearLog() {
const { ctx } = this;
const loggerPath = ctx.app.config.logger.dir; // eg: /home/webserver/logs/logger/flat_cms/prod
ctx.logger.info('loggerPath: ', loggerPath);
const twoCount = (count: number) => {
return count < 10 ? '0' + count : count.toString();
};
// 删除文件、文件夹
const unlinkFile = (logNameList: string[], subDirPath: string) => {
// console.log('保留文件列表 - logNameList: ', logNameList);
const subFiles = fs.readdirSync(subDirPath);
subFiles.forEach(fileName => {
const filePath = `${subDirPath}/${fileName}`;
const state = fs.statSync(filePath);
if (state.isFile()) {
if (!logNameList.includes(fileName)) {
fs.unlinkSync(filePath);
// console.log('删除文件:', fileName);
}
} else if (state.isDirectory()) {
const workerProcess = child_process.exec(`rm -rf ${filePath}`,
(error:any) => {
if (error) {
ctx.logger.info('删除文件夹异样 Error code: ' + error.code)
}
});
workerProcess.on('exit', function (code) {
ctx.logger.info('子过程已退出,退出码 ' + code);
})
}
});
};
// 获取最近三天 日志文件
const logNameList: string[] = [];
CLEAR_WHITE_LIST.forEach((logPath)=> {
logNameList.push(logPath); // eg: common-error.log
});
[ new Date(Date.now() - 3600 * 1000 * 24 * 2), new Date(Date.now() - 3600 * 1000 * 24), new Date() ].forEach(timeObj => {
const logSuffix = `${timeObj.getFullYear()}-${twoCount(timeObj.getMonth() + 1)}-${twoCount(timeObj.getDate())}`; // 简略日期解决,不必moment模块
CLEAR_WHITE_LIST.forEach((logPath)=> {
const logName = `${logPath}.${logSuffix}`; // eg: common-error.log.2021-03-06
logNameList.push(logName);
});
});
unlinkFile(logNameList, loggerPath);
ctx.logger.info('清理日志完结!');
}
}
module.exports = ClearLogs;
CPU趋势、历史记录 剖析和定位
接入NodeJS性能监控后, CPU过高时有钉钉告警, 而后通过 CPU趋势图可定位到 CPU 占用过高前 分钟 级别的细粒度信息, 例如:确定 2021.07.29 17:30 ~ 2021.07.29 17:32 这段时间内CPU异样。
联合这段时间内用户拜访历史, 可整顿放大范畴,晓得拜访了哪些页面、申请了哪些API接口导致CPU过高。
一次可能看不出,每次呈现整顿一份日志记录, 多份数据比照可进一步放大拜访哪些页面导致CPU过高问题范畴。
复现问题
有了日志比照,可模仿拜访页面,同时登陆服务器运行指令: top -c
察看CPU运行状况,拜访上述整顿呈现CPU过高时 1 ~ 2分钟内的每一路由 模仿复现问题。
备注: NodeJS 性能监控平台查看 CPU 运行数据会有肯定延时, 还是间接登录服务器指令查看更实时!
通过模仿拜访定位到拜访某路由导致 CPU过高!
因为部署了多台服务器, 确定拜访某路由能重现后, 可间接 IP 拜访旧服务器代码,而后雷同形式最终确认!
拜访某路由时,其余服务器 NodeJs性能监控平台 CPU 状况。(几个尖刺是调试确认时的截图)
定位思路小总结
总的来说定位问题 是以下四步骤:
- 剖析
火焰图
, 试图依据火焰图
定位到具体代码; - 剖析
GC Trace
, 判断是否 代码内存泄露
导致CPU 过高; - 独自服务器部署,排除烦扰,确定是否业务代码导致CPU占用率高, 增加每个路由(页面路由、API申请路由)的日志(日志定时清理);
- 通过比照 CPU 飙高前 2~ 3分钟内申请的页面, 找出对应页面、二级页面等 进行拜访 察看 对应服务器CPU占用值。
解决问题
以上确定了具体路由后, 就能深刻其业务代码(100~200行)查看起因。
最终定位是某个二级弹层申请数据(API路由)时,如果该业务数据满足某一条件时,会将做全表查问, 对 十多万数据进行遍历解决
导致CPU飙高!藏的很深!
起因:历史代码没思考性能, 有全表查问逻辑, 当然一开始业务表数据 几千条数据
不会触发,随着业务演进,数据量减少至 十万级别
就呈现CPU飙升100%状况!
小总结
本文次要分享 Node.js 我的项目运行时呈现 CPU 飙升 100% 时, 排查、定位 到具体业务代码的思路。 比照网上各种总结帖, CPU 过高问题起因很多, 本文提供一种定位思路。有其余更好办法请评论区补充~
参考博文
- node过程cpu 100%问题排查
- NodeJs调试指南
- 唯快不破让NodeJs更快一些
- 深入浅出Node(第五章内存管制) – 微信读书
- V8 引擎垃圾回收与内存调配
- 2019 – V8 引擎官网:GC算法更新
- Node.js 利用故障排查手册
- Node.js 调试指南
发表回复