作为一个Node.js开发者，线上出Bug是常有的事。大部分Bug都比较容易定位，看看日志、复现一下，很快就能找到原因。但是有一次性能问题让我印象特别深刻，整整排查了一夜才解决。

那天是个周三，本来是个普通的工作日。晚上十点多，我正准备睡觉，手机突然响了，是运维同事打来的，说线上的Node.js服务出现了异常，CPU使用率飙升到了百分之百，接口响应时间从原来的几十毫秒变成了好几秒，用户已经开始投诉了。

我一下子就清醒了，赶紧打开电脑，开始了漫长的排查之夜。

一、问题现象

先说说问题的具体现象。

我们的这个Node.js服务是一个API网关，负责转发请求、鉴权、日志记录等功能，每天的请求量大概在几百万级。服务部署在四台服务器上，每台是8核16G的配置，用PM2的集群模式启动了8个进程。平时运行得很稳定，CPU使用率在百分之三十左右，内存使用也很正常。

那天晚上九点半左右，监控系统开始告警，CPU使用率突然飙升。我登录监控面板一看，四台服务器的CPU都跑到了百分之九十以上，其中有两台直接到了百分之百。接口的平均响应时间从原来的五十毫秒左右涨到了三秒多，P99更是达到了十几秒。错误率也上升了，主要是超时错误。

奇怪的是，那天并没有发布新版本，也没有做什么配置变更，流量也和平常差不多，没有突然的流量高峰。服务就这么毫无征兆地出问题了。

第一反应是重启服务。我先重启了一台服务器上的所有进程，重启之后CPU确实降下来了，响应时间也恢复了正常。但是好景不长，大概过了二十分钟，CPU又开始慢慢上升，最后又回到了百分之百。看来重启只能暂时缓解，不能根本解决问题。

于是我决定，先把流量切到其他服务上，让这台服务器保持故障状态，方便我排查问题。然后开始了漫长的调试过程。

二、排查思路和过程

遇到性能问题，我的排查思路一般是：先看监控指标，确定是CPU问题还是内存问题还是I/O问题；然后用工具分析具体是哪里出了问题；最后根据分析结果定位根因并修复。

第一步：确认问题类型

我先看了服务器的各项指标。CPU使用率确实很高，但是内存使用还算正常，没有持续增长的趋势。磁盘I/O也正常，没有大量的读写。网络流量也和平常差不多，没有异常。

所以问题应该出在CPU上，是某个计算密集型的操作占用了大量的CPU时间，导致事件循环被阻塞，接口响应变慢。

但是问题来了，我们的服务是一个API网关，主要做的是I/O操作（转发请求、读写数据库、写日志等），应该没有什么计算密集型的操作啊。那CPU为什么会这么高呢？

第二步：用node --prof分析CPU使用

要找出CPU都花在哪里了，最直接的方法就是用Node.js内置的--prof工具来做性能分析。

我先在一台出问题的服务器上，用--prof参数重启了一个Node.js进程，让它运行几分钟，收集性能数据。然后用--prof-process参数来分析生成的v8.log文件，生成性能报告。

报告出来之后，我仔细看了一下各个函数的执行时间占比。结果让我很意外，占用CPU时间最多的不是我们的业务代码，而是一个叫gc的函数，也就是垃圾回收。垃圾回收占用了将近百分之四十的CPU时间！

这说明什么？说明V8引擎在频繁地进行垃圾回收。为什么会频繁垃圾回收呢？一般有两个原因：一是内存中创建了大量的临时对象，导致新生代空间很快被填满，触发频繁的Scavenge回收；二是内存泄漏，老生代空间不断增长，触发耗时的Mark-Sweep和Mark-Compact回收。

从监控上看，内存使用并没有持续增长，所以不太像是内存泄漏。那更可能是第一个原因：创建了大量的临时对象，导致频繁的新生代垃圾回收。

第三步：用Chrome DevTools分析内存

为了进一步确认，我用Chrome DevTools来分析内存使用情况。

我用--inspect参数启动了一个Node.js进程，然后用Chrome连接上去。在DevTools的Memory面板中，我录制了一段时间的内存分配情况，看看哪些操作在频繁地分配内存。

录制结果出来之后，我发现了一个可疑的地方。有一个函数在频繁地创建字符串对象，而且每次创建的字符串都很大。这个函数是我们自己写的，叫formatLog，用来格式化日志信息。

我赶紧去看这个函数的代码。看完之后，我倒吸一口凉气，问题可能就出在这里。

这个函数的代码大概是这样的：

function formatLog(log) {
    let result = '';
    for (let key in log) {
        result += key + ': ' + log[key] + ', ';
    }
    return result;
}

看起来很简单，就是把日志对象格式化成字符串。但是问题在于，这个函数用了字符串拼接（+=）。在JavaScript中，字符串是不可变的，每次+=操作都会创建一个新的字符串对象，原来的字符串就变成了垃圾，等待回收。

如果日志对象只有几个属性，那还好，不会有太大问题。但是我们的日志对象包含了很多字段，有请求头、响应头、请求体、响应体、用户信息、时间戳等等，加起来有几十个属性。每次格式化日志，都要执行几十次字符串拼接，创建几十个中间字符串对象。

而我们的服务是API网关，每个请求都要记录日志，每天几百万个请求，每个请求都要调用这个formatLog函数。这就意味着，每秒都要创建几十万个临时字符串对象！这些对象很快就把新生代空间填满了，V8不得不频繁地进行垃圾回收，而垃圾回收是需要占用CPU时间的，这就导致了CPU使用率飙升。

第四步：验证猜想

找到可疑的代码之后，我需要验证一下，是不是这个函数导致的问题。

我先在测试环境复现了这个问题。用压测工具模拟线上的流量，跑了一段时间之后，测试环境的CPU也开始升高了。用--prof分析，果然垃圾回收占用了大量的CPU时间。

然后我修改了formatLog函数，把字符串拼接改成了用数组的join方法：

function formatLog(log) {
    const parts = [];
    for (let key in log) {
        parts.push(key + ': ' + log[key]);
    }
    return parts.join(', ');
}

修改之后，重新压测。奇迹发生了，CPU使用率直接降了一半多，从原来的百分之八十多降到了百分之三十左右。再用--prof分析，垃圾回收的时间占比从百分之四十降到了百分之五左右。

果然就是这个函数的问题！

第五步：为什么之前没有问题

但是这里有个疑问，这个formatLog函数已经存在很久了，为什么之前一直没有问题，偏偏这天晚上出问题了呢？

我去查了一下代码提交记录，发现这个函数确实很久没有改过了。那为什么之前没问题呢？

后来我想明白了，是因为日志量增加了。虽然那天没有发布新版本，但是业务在增长，请求量在慢慢增加。之前每天的请求量是两三百万，最近涨到了四五百万。日志量也跟着翻倍了，formatLog函数的调用次数也翻倍了。之前的调用量还在系统能承受的范围内，所以没有明显的问题。但是当调用量超过某个阈值之后，频繁的垃圾回收就导致了CPU飙升，问题就爆发了。

这也解释了为什么重启之后能好一会儿。重启之后，内存是空的，需要一段时间才能积累足够多的临时对象触发频繁的垃圾回收。等积累到一定程度，问题就又出现了。

想明白这一点之后，我不禁感慨，性能问题有时候就是这样，它不会在你写代码的时候出现，而是在系统运行到某个临界点的时候突然爆发。作为开发者，我们不能只关注功能是否正常，还要关注代码的性能，特别是那些会被频繁调用的核心路径上的代码。

三、修复和优化

确认了问题之后，我先把修改后的代码部署到了线上。部署之后，CPU使用率很快就降下来了，响应时间也恢复了正常。一场线上故障终于解决了。

但是事情还没有结束。这次故障暴露了我们代码中的很多问题，需要做一次全面的优化，避免类似的问题再次发生。

优化一：全面检查字符串拼接

这次的问题是字符串拼接导致的，那代码中是不是还有其他地方也有类似的问题呢？我对整个项目的代码做了一次全面的检查，搜索所有的+=字符串拼接操作。

果然，除了formatLog函数，还有好几个地方也有类似的问题。比如有一个生成HTML的函数，也是用字符串拼接的方式构建HTML字符串；还有一个生成CSV导出文件的函数，也是逐行拼接。

我把这些地方都改成了数组join的方式，或者用模板字符串。模板字符串虽然也是创建新字符串，但是比+=拼接要高效一些，因为V8对模板字符串有优化。

改完之后，又做了一次压测，CPU使用率又降了一些，整体性能提升了不少。

优化二：优化日志系统

这次的问题本质上是日志量太大导致的。虽然修复了字符串拼接的问题，但是日志系统本身也需要优化。

我们原来的日志是同步写入文件的，每个请求都要写一条日志，而且日志内容很详细，包含了请求和响应的完整信息。这不仅有性能问题，还占用了大量的磁盘空间。

我们对日志系统做了以下优化：

  1. 异步写入：把同步写文件改成异步写，用一个队列来缓冲日志，批量写入，减少I/O操作。
  2. 日志分级：区分访问日志和错误日志，访问日志只记录关键信息，错误日志才记录详细的请求响应信息。
  3. 采样：对于正常的访问日志，只采样记录一部分，比如百分之十，不需要每个请求都记。
  4. 日志轮转：设置日志文件的大小和保留时间，自动清理旧日志，避免磁盘被占满。

优化之后，日志系统的性能提升了很多，磁盘占用也大大减少了。

优化三：增加性能监控和告警

这次故障是运维先发现的，然后才通知我。作为开发者，我们应该有更主动的性能监控，在问题刚出现的时候就能发现，而不是等用户投诉了才知道。

我们增加了以下监控指标：

  1. 事件循环延迟：监控事件循环的延迟时间，如果延迟超过阈值就告警。事件循环延迟是Node.js性能的关键指标，延迟高说明有阻塞操作。
  2. 垃圾回收时间和频率：监控每次垃圾回收的时间和频率，如果垃圾回收过于频繁或者耗时过长，就告警。
  3. CPU和内存使用率：这个本来就有，但是增加了更细粒度的监控，按进程来监控。
  4. 接口响应时间和错误率：按接口维度监控，能快速定位是哪个接口出了问题。

有了这些监控之后，我们就能在问题刚出现的时候就发现，及时处理，避免小问题演变成大故障。

优化四：代码审查中增加性能检查

这次的问题其实在代码审查的时候就应该被发现。字符串拼接在循环中使用，是一个很常见的性能反模式。但是我们之前的代码审查只关注功能是否正确、代码风格是否规范，没有关注性能问题。

我们在代码审查的checklist中增加了性能检查项，包括：

  • 循环中是否有字符串拼接
  • 是否有同步的I/O操作
  • 是否有不必要的重复计算
  • 是否有内存泄漏的风险
  • 是否有阻塞事件循环的操作

每次提交代码，审查者都要检查这些项。这样就能在代码合并之前就发现性能问题，避免问题流到线上。

四、踩过的坑和经验教训

这次排查过程中，我也踩了不少坑，积累了一些经验教训。

坑一：重启大法不是万能的

遇到线上问题，第一反应往往是重启。重启确实能解决很多问题，比如内存泄漏、进程卡死等。但是重启不是万能的，对于这种因为代码逻辑导致的性能问题，重启只能暂时缓解，过一会儿问题又会出现。而且频繁重启会影响用户体验，也会让我们失去排查问题的现场。

正确的做法是：如果问题不严重，可以先保留现场，排查问题；如果问题很严重，影响了核心功能，可以先重启恢复服务，同时在测试环境复现问题进行排查。不要一上来就重启所有服务，那样就什么线索都没了。

坑二：不要凭感觉猜测，要用数据说话

排查问题的时候，我一开始凭感觉猜测了很多原因，比如是不是被攻击了、是不是数据库出问题了、是不是第三方依赖有问题。花了很多时间去验证这些猜测，结果都不是。

后来我静下心来，用工具去分析，用数据说话，很快就找到了问题的根源。这让我明白，排查性能问题不能凭感觉，一定要用工具收集数据，根据数据来判断。Node.js提供了很多好用的性能分析工具，比如--prof、--inspect、clinic.js等，要善于利用这些工具。

坑三：注意Node.js版本差异

在排查过程中，我还遇到了一个小插曲。我在本地用Node.js 8.x测试的时候，字符串拼接的性能问题不是很明显。但是线上用的是Node.js 6.x，问题就很严重。后来查了一下，V8在不同版本中对字符串拼接的优化是不一样的，新版本的V8对+=拼接有一些优化，性能比旧版本好很多。

这提醒我们，在做性能测试的时候，一定要用和线上相同的Node.js版本，否则测试结果可能和线上不一致。同时，及时升级Node.js版本也能带来性能提升，新版本的V8引擎在性能上有很多优化。

坑四：小问题也可能导致大故障

这次的问题，说起来就是一个字符串拼接的小问题。代码很简单，看起来也没有什么错，功能完全正常。但是就是这么一个小问题，在高并发的场景下，导致了严重的线上故障。

这让我深刻认识到，在高并发系统中，没有小问题。任何一个小的性能问题，乘以几百万次的调用量，都会变成大问题。所以在写代码的时候，特别是写核心路径上的代码时，一定要考虑性能，不能只关注功能是否正确。

五、常用的Node.js性能分析工具

最后，总结一下我常用的Node.js性能分析工具，希望对大家有帮助。

1. node --prof / --prof-process

Node.js内置的性能分析工具，不需要安装额外的软件。用--prof启动应用，会生成v8.log文件，然后用--prof-process分析，生成性能报告，显示各个函数的执行时间占比。适合定位CPU占用高的问题。

2. node --inspect + Chrome DevTools

用--inspect启动应用，然后用Chrome浏览器连接，可以使用DevTools的各种功能。Memory面板可以分析内存使用、查找内存泄漏；Profiler面板可以录制CPU使用情况；Console面板可以执行代码调试。功能非常强大，适合深入分析各种性能问题。

3. clinic.js

NearForm开发的Node.js性能分析工具套件，包含clinic doctor（诊断健康状况）、clinic bubbleprof（分析异步延迟）、clinic flame（生成火焰图）三个工具。使用简单，界面友好，功能强大，是我最常用的性能分析工具。

4. 0x

专门生成火焰图的工具，使用简单，生成的火焰图是交互式的，可以放大缩小、搜索函数。如果你只需要火焰图，0x是一个很好的选择。

5. PM2监控

如果用PM2部署，可以用pm2 monit命令实时查看各个进程的CPU、内存使用情况，还可以查看日志。PM2还支持健康检查、自动重启等功能，是生产环境部署的好帮手。

结语

那次排查从晚上十点一直到第二天早上六点，整整八个小时。当我把修复后的代码部署上线，看到CPU使用率降下来、响应时间恢复正常的时候，虽然身体很疲惫，但是心里特别有成就感。

这次经历让我学到了很多。我不仅掌握了更多的Node.js性能调优技巧，更重要的是，我学会了如何系统性地排查问题，如何用数据和工具说话，而不是凭感觉猜测。我也更加深刻地认识到，在高并发系统中，代码质量和性能有多么重要。

作为开发者，我们写的每一行代码都可能运行在成千上万的服务器上，影响着无数用户。对代码负责，对性能负责，就是对用户负责。希望我的这次经历能给大家带来一些启发，在遇到类似问题的时候，能少走一些弯路，更快地找到问题所在。

夜还很长，Bug还会有，但是我们不怕。因为每一次排查Bug的过程，都是我们成长的过程。