开始博文前，请贴上本文内容，主要空间在第二部分：如何定位。前言（背景）内部管理系统，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的开源版本——Easy-Monitor3.0，操作界面类似。连接成功后，CPU过高时出现下图：当然还有其他的Node。RecyclingTracking）火焰图（FlameGraph）大家应该都听说过，它可以将CPU的使用情况可视化，让我们直观的了解程序的性能瓶颈。我们通常将火焰图与操作系统的profilingtracer结合使用。常见的操作系统性能分析工具有：Linux：perf、eBPF、SystemTap、ktap。Solaris、illumos、FreeBSD：DTrace。MacOSX：DTrace和仪器。Windows：Xperf.exe。如果没有连接NodeJs性能监控，必须在服务器上安装以上分析工具（一般是linux）；连接NodeJs性能监控后，可以一键导出火焰图，了解网上很多关于火焰图的教程，例如：快速定位NodeJs在线问题-火焰图理论上可以通过火焰图来定位具体线路导致CPU过高的代码。但是我在实践中发现火焰图有两个问题：1）时效性??不够。比如Node性能监控上的“抓取性能数据”——生成火焰图，生成的火焰图是最近5分钟，有问题（见钉钉告警）上去“抓取”生成火焰图那可能是正常运行的代码。2）无法定位具体代码即使CPU过高问题持续时间长，“抓”到的是异常运行状态下的火焰图，有可能发现生成的图不对并且无法与我们的业务代码保持一致。这里遇到生成的火焰图无法定位到具体代码(-_-||。不同的项目不一样，或许火焰图可以帮你定位到具体的代码。对了，Node性能监控平台一般都可以导出火焰图graph文件，导出的文件名称如：u-c3979add-7db3-4365-b1ed-9a2556b6a320-u-x-cpuprofile-4012-20210730-241648.cpuprofile，可以在Chrome上导入：GCTrace（垃圾回收跟踪）ThegarbageNode底层V8引擎的collection一般都是和内存相关的，为什么CPU过高还要看垃圾回收跟踪数据？因为NodeJs内存泄露会导致最大内存（1.4G）的垃圾回收V8引擎要超标，再重启V8GC会导致CPU占用100%，默认32位系统新生代内存大小为16MB，老年代内存大小为700MB。在64位系统下，新生代内存大小为32MB，老年代内存大小为1.4GB。当然，V8垃圾回收的最大内存限制是可以修改的：#node可以在启动时通过参数来调整限制的内存大小。下面的方法调整node节点使用的内存--max-old-space-size=1700//单位是MBnode--max_semi_space_size=1024//单位是KBjs应用排查手册，不对内部监控系统截图考虑脱敏。!Node性能监控平台默认会抓取对应进程5分钟的GC日志信息，结束后会在文件页面显示生成的文件：此时点击dump上传到云端进行在线分析并显示，如下图所示：最后点击这里的分析按钮，可以看到AliNode自定义的GC信息分析结果的显示：在结果显示中，可以方便的看到具体的GC次数，GC类型，以及问题进程的每次GC耗时等信息，方便我们进一步分析定位。比如在这个问题的GCTrace结果分析图中，我们可以看到红色圈出的几个重要信息：GC总停顿时间高达47.8s，GCtrace日志中主要部分为Scavenge3min，其中一共进行了988次Scavenge收集，平均每次Scavenge花费的时间在50到60ms之间。从这些解决方案中我们可以看出，本次GC案例的问题集中在Scavenge回收阶段，即新生代的内存回收。那么通过阅读V8的Scavenge回收逻辑，我们可以知道这个阶段触发回收的条件是：Semispaceallocationfailed。这样可以推测，我们的应用在压测的时候应该会频繁的在新生代中产生大量的小对象，导致默认的Semi空间一直处于被快速填充的状态，从而触发Flip，这样就会GC中出现了这么多的scavengecollections以及跟踪期间相应的CPU消耗，问题就变成了如何优化新一代GC以提高应用程序性能。这里有些同学可能不太理解ScavengeGC和Mark-sweepGC。具体到业务代码上，ScavengeGC就是对一些占用内存比较小的临时变量的回收。Mark-sweepGC是全局变量占用内存小或者是临时变量占用内存大。一般来说，只要GCTrace（garbagecollectiontrace）出现的时间过长，一般都是内存泄漏导致V8引擎垃圾回收的最大内存（1.4G）超过而重启V8GC以导致100%CPU。详见Node深入浅出（第五章内存控制）-微信阅读，国内最经典的NodeJS书籍《深入浅出Node》虽然是2013年12月1日出版的，但是关于V8引擎垃圾回收机制的内容是现在还没有过时，V8引擎最近官方对垃圾回收机制的更新（2019-V8引擎官方：GC算法更新）基本没变，只是在Mark-sweepGC阶段增加了三个优化机制。该场景观察GCTrace相关数据正常，排除内存泄漏导致CPU占用过高。单机部署无法通过火焰图和GCTrace定位到具体代码怎么办？它每天发生2到3次。怀疑是受服务器其他服务影响，也考虑需要多台服务器才能重现模拟问题。所以跟运维申请新的服务器，配置可以低一些，主要是排除干扰。代码部署到新服务器后，将访问域名单独映射到新服务器，然后继续观察是否出现CPU秒杀。结论是在新服务器上运行的代码仍然占用了100%以上的CPU：当然单台服务器的CPU趋势更直观，正常运行时CPU占用率在1%~5%。添加访问日志为什么域名只映射到这台新服务器？主要是方便添加和查看日志。如果有多台服务器，用户访问记录过于分散，会增加分析和整理日志的时间成本。EggJslogAPI可以记录用户每次访问的页面，或者二级页面弹出时加载的数据等API数据请求；在中间件中添加记录访问日志代码，忽略静态文件请求。//app->middleware->init.tsif(!reqPath.includes('/public/')){ctx.logger.warn('reqPath:',reqPath);}添加成功后，日志中包含“WARN"为用户访问历史：备注：添加用户历史访问后，日志量会增加。我们内部系统访问的人不多，每天产生3M左右的日志数据。可以考虑增加一个定时日志清理脚本，每天定时清理。egg定时任务接口，对应清理日志脚本：import{Subscription}from'egg';import*asfsfrom'fs';import*aschild_processfrom'child_process';constCLEAR_WHITE_LIST=['common-error.log','my_app-web.log'];//保留日志白名单classClearLogsextendsSubscription{staticgetschedule(){return{cron:'0307***',//每天检查一次type:'worker',//对每台机器，随机指定某个进程执行定时任务//immediate:true,//为true时，启动时直接执行};}/***subscribe是真正的定时任务执行时运行的函数*/asyncsubscribe(){const{ctx}=this;ctx.logger.info('开始清空日志！');这个.clearLog();}asyncclearLog(){const{ctx}=this;constloggerPath=ctx.app.config.logger.dir;//例如：/home/webserver/logs/logger/flat_cms/prodctx.logger.info('loggerPath:',loggerPath);consttwoCount=(count:number)=>{返回计数<10?'0'+计数：count.toString();};//删除文件和文件夹constunlinkFile=(logNameList:string[],subDirPath:string)=>{//console.log('保留文件列表-logNameList:',logNameList);constsubFiles=fs.readdirSync(subDirPath);subFiles.forEach(fileName=>{constfilePath=`${subDirPath}/${fileName}`;conststate=fs.statSync(filePath);if(state.isFile()){if(!logNameList.includes(fileName)){fs.unlinkSync(filePath);//console.log('删除文件:',fileName);}}elseif(state.isDirectory()){constworkerProcess=child_process.exec(`rm-rf${filePath}`,(error:any)=>{if(error){ctx.logger.info('错误代码:'+error.code)}});workerProcess.on('exit',function(code){ctx.logger.info('子进程已经退出，退出码'+code);})}});};//获取最近三天的日志文件constlogNameList:string[]=[];CLEAR_WHITE_LIST.forEach((logPath)=>{logNameList.push(logPath);//例如：common-erro日志});[newDate(Date.now()-3600*1000*24*2),newDate(Date.now()-3600*1000*24),newDate()].forEach(timeObj=>{constlogSuffix=`${timeObj.getFullYear()}-${twoCount(timeObj.getMonth()+1)}-${twoCount(timeObj.getDate())}`;//简单的日期处理，不用momentmoduleCLEAR_WHITE_LIST.forEach((logPath)=>{constlogName=`${logPath}.${logSuffix}`;//例如：common-error.log.2021-03-06logNameList.push(logName);});});unlinkFile(logNameList,loggerPath);ctx.logger.info('清空日志结束！');}}module.exports=ClearLogs;将高CPU的业务代码添加到超时日志中，往往请求时间也长，可以在Egg.js的最后一个中间件中添加如下代码打印超时接口日志：/*app->middleware->errCatch.ts自定义中间件：错误处理模块*/import{Context}from'egg';'usestrict';exportdefaultfunctionerrHandler():any{returnasync(ctx:Context,next:()=>Promise
