Node.js 应用故障排查手册 —— 类死循环致使进程阻塞

类死循环致使进程阻塞

楔子

在实践篇一中咱们看到了两个表象都是和 CPU 相关的生产问题，它们基本也是咱们在线上可能遇到的这一类问题的典型案例，而实际上这两个案例也存在一个共同点：咱们能够经过 Node.js 性能平台 导出进程对应的 CPU Profile 信息来进行分析定位问题，可是实际在线上的一些极端状况下，咱们遇到的故障是没有办法经过轻量的 V8 引擎暴露的 CPU Profile 接口（仅部分定制的 AliNode runtime 版本支持，详见下文）来获取足够的进程状态信息进行分析的，此时咱们又回到了一筹莫展的状态。

本章节将从一个生产环境下 Node.js 应用出现进程级别阻塞致使的再也不提供服务的问题场景来给你们展现下如何处理这类相对极端的应用故障。

本书首发在 Github，仓库地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，云栖社区会同步更新。

最小化复现代码

这个例子稍微有些特殊，咱们首先给出生产案例的最小化复现代码，有兴趣的同窗能够亲自运行一番，这样结合下文的此类问题的排查过程，能更加清晰的看到咱们面对这样的问题时的排查思路，问题最小代码以下，基于 Egg.js ：

'use strict';
const Controller = require('egg').Controller;

class RegexpController extends Controller {
  async long() {
    const { ctx } = this;
    // str 模拟用户输入的问题字符串
    let str = '<br/>                                             ' +
      '           早餐后自由活动，于指定时间集合自行办理退房手续。';
    str += '<br/>                                      <br/>' +
      '                                        <br/>           ' +
      '                         <br/>';
    str += '                                    <br/>' +
      '                                                        ' +
      '                                                        ' +
      '        <br/>';
    str += '                                                <br/>                                                                                                                <br/>';
    str += '                                                     ' +
      '                                                        ' +
      '       根据船班时间，自行前往暹粒机场，返回中国。<br/>';
    str += '如需送机服务，需增长280/每单。<br/>';
    const r = str.replace(/(^(\s*?<br[\s\/]*?>\*?)+|(\s*?<br[\s\/]*?>\s*?)+?$)/igm, '');
    ctx.body = r;
  }
}

module.exports = RegexpController;

问题应用状态

其实这个例子对应的问题场景可能不少 Node.js 开发者都遇到过，它很是有意思，咱们首先来看下出现这类故障时咱们的 Node.js 应用的状态。当咱们收到在平台配置的 CPU 告警信息后，登陆性能平台进入对应的告警应用找到出问题的 CPU 很是高的进程：而后点击 数据趋势 按钮查看此进程当前的状态信息：

能够看到进程的 CPU 使用率曲线一直处于近乎 100% 的状态，此时进程再也不响应其他的请求，并且咱们经过跳板机进入生产环境又能够看到进程实际上是存活的，并无挂掉，此时基本上能够判断：此 Node.js 进程由于在执行某个同步函数处于阻塞状态，且一直卡在此同步函数的执行上。

Node.js 的设计运行模式就是单主线程，并发靠的是底层实现的一整套异步 I/O 和事件循环的调度。简单的说，具体到事件循环中的某一次，若是咱们在执行须要很长时间的同步函数（好比须要循环执行好久才能跳出的 while 循环），那么整个事件循环都会阻塞在这里等待其结束后才能进入下一次，这就是不推荐你们在非初始化的逻辑中使用诸如 fs.readFileSync 等同步方法的缘由。

排查方法

这样的问题其实很是难以排查，缘由在于咱们没办法知道什么样的用户输入形成了这样的阻塞，因此本地几乎没法复现问题。幸运的是，性能平台目前有不止一种解决办法处理这种类死循环的问题，咱们来详细看下。

I. CPU Profile

这个分析方法能够说是咱们的老朋友了，由于类死循环的问题本质上也是 CPU 高的问题，所以咱们只要对问题进程抓取 CPU Profile，就能看到当前卡在哪一个函数了。须要注意的是，进程假死状态下是没法直接使用 V8 引擎提供的抓取 CPU Profile 文件的接口，所以工具篇章节的 正确打开 Chrome devtools 一节中提到的 v8-profiler 这样的第三方模块是没法正常工做的。

不过定制过的 AliNode runtime 采用了必定的方法规避了这个问题，然而遗憾的是依旧并非全部的 AliNode runtime 版本都支持在类死循环状态下抓取 CPU Profile，这里实际上对你们使用的 Runtime 版本有要求：

• AliNode V3 版本须要 >= v3.11.4
• AliNode V4 版本须要 >= v4.2.1
• AliNode V1 和 V2 版本不支持

若是你的线上 AliNode runtime 版本刚好符合需求，那么能够按照前面 Node.js 性能平台使用指南 提到的那样，对问题进程抓取 3 分钟的 CPU Profile，而且使用 AliNode 定制的火焰图分析：

这里能够看到，抓取到的问题进程 3 分钟的 CPU 所有耗费在 long 函数里面的 replace 方法上，这和咱们提供的最小化复现代码一致，所以能够判断 long 函数内的正则存在问题进行修复。

II. 诊断报告

诊断报告也是 AliNode 定制的一项导出更多更详细的 Node.js 进程当前状态的能力，导出的信息也包含当前的 JavaScript 代码执行栈以及一些其它进程与系统信息。它与 CPU Profile 的区别主要在两个地方：

• 诊断报告主要针对此刻进程状态的导出，CPU Profile 则是一段时间内的 JavaScript 代码执行状态
• 诊断报告除了此刻 JavaScript 调用栈信息，还包含了 Native C/C++ 栈信息、Libuv 句柄和部分操做系统信息

当咱们的进程处于假死状态时，显然不论是一段时间内仍是此时此刻的 JavaScript 执行情况，必然都是卡在咱们代码中的某个函数上，所以咱们可使用诊断报告来处理这样的问题，固然诊断报告功能一样也对 AliNode runtime 版本有所要求：

• AliNode V2 版本须要 >= v2.5.2
• AliNode V3 版本须要 >= v3.11.8
• AliNode V4 版本须要 >= v4.3.0
• AliNode V1 版本不支持
• 且要求：Agenthub/Egg-alinode 依赖的 Commandx 版本 >= v1.5.3

若是你使用的 AliNode runtime 版本符合要求，便可进入平台应用对应的实例信息页面，选中问题进程：

而后点击 诊断报告 便可生成此刻问题进程的状态信息报告：

诊断报告虽然包含了不少的进程和系统信息，可是其自己是一个相对轻量的操做，故而很快就会结束，此时继续点击 转储 按钮将生成的诊断报告上传至云端以供在线分析展现：

继续点击 分析 按钮查看 AliNode 定制的分析功能，展现结果以下：

结果页面上面的概览信息比较简单，咱们来看下 JavaScript 栈 页面的内容，这里显然也告诉咱们当前的 JS 函数卡在 long 方法里面，而且比 CPU Profile 更加详细的是还带上了具体阻塞在 long 方法的哪一行，对比咱们提供给你们的最小复现代码其实就是执行 str.replace 这一行，也就是问题的正则匹配操做所在的地方。

III. 核心转储分析

其实不少朋友看到这里会有疑惑：既然 CPU Profile 分析和诊断报告已经可以找到问题所在了，为何咱们还要继续介绍相对比较重的核心转储分析功能呢？

其实道理也很简单，不论是类死循环状态下的 CPU Profile 抓取仍是诊断报告功能的使用，都对问题进程的 AliNode runtime 版本有所要求，并且更重要的是，这两种方法咱们都只能获取到问题正则的代码位置，可是咱们没法知道什么样的用户输入在执行这样的正则时会触发进程阻塞的问题，这会给咱们分析和给出针对性的处理形成困扰。所以，这里最后给你们介绍对 AliNode runtime 版本没有任何要求，且能拿到更精准信息的核心转储分析功能。

首先按照预备章节的核心转储一节中提到的 手动生成 Core dump 文件的方法，咱们对问题进程进行 sudo gcore <pid> 的方式获取到核心转储文件，而后在平台的详情页面，将鼠标移动到左边 Tab 栏目的 文件 按钮上，能够看到 Coredump 文件 的按钮：


点击后能够进入 Core dump 文件列表页，而后点击上方的 上传 按钮进行核心转储文件的上传操做：


这里须要注意的是，请将 Core dump 文件以 .core 结尾重命名，而对应的 Node 可执行文件以 .node 结尾重命名，推荐的命名方式为 <os info>-<alinode/node>-<version>.node，方便之后回顾，好比 centos7-alinode-v4.7.2.node 这种。最后 Core dump 文件和 Node 可执行文件之间必须是 一一对应 的关系。这里一一对应指的是：这份 Core dump 文件必须是由这个 Node 可执行文件启动的进程生成的，若是这二者没有一一对应，分析结果每每是无效信息。

由于 Core dump 文件通常来讲都比较大，因此上传会比较慢，耐心等待至上传完毕后，咱们就可使用 AliNode 定制的核心转储文件分析功能进行分析了，点击 分析 按钮便可：

此时咱们在新打开的分析结果页面能够看到以下的分析结果展现信息：

这个页面的各项含义在工具篇的 Node.js 性能平台使用指南的 [最佳实践——核心转储分析]() 一节已经解释过，这里再也不赘述，这里直接展开 JavaScript 栈信息：

这里能够看到获得的结论和前面的 CPU Profile 分析以及诊断报告分析一致，都能定位到提供的最小复现代码中的 long 方法中的异常正则匹配，可是核心转储文件分析比前面二者多了致使当前 Node.js 进程产生问题的异常字符串：  "<br/> 早餐后自由活动，于指定时间集合自行办理退房手续。<br/> <br/> <br/> <br/> <br/> <br/> <br/> <br/> 根据船班时间，自行前往暹粒机场，返回中国。<br/>如需送机服务，需增长280/每单。<br/>" ，有了这个触发正则执行异常的问题字符串，咱们不管是构造本地复现样例仍是进一步分析都有了重要的信息依靠。

分析问题

上一节中咱们采用了 Node.js 性能平台提供的三种不一样的方式分析定位到了线上应用处于假死状态的缘由，这里来简单的解释下为何字符串的正则匹配会形成类死循环的状态，它实际上异常的用户输入触发了 正则表达式灾难性的回溯，会致使执行时间要耗费几年甚至几十年，显然不论是那种状况，单主工做线程的模型会致使咱们的 Node.js 应用处于假死状态，即进程依旧存活，可是却再也不处理新的请求。

关于正则回溯的缘由有兴趣的同窗能够参见 当心别落入正则回溯陷阱 一文。

结尾

其实这类正则回溯引起的进程级别阻塞问题，本质上都是因为不可控的用户输入引起的，而 Node.js 应用又每每做为 Web 应用直接面向一线客户，无时不刻地处理千奇百怪的用户请求，所以更容易触发这样的问题。

类似的问题其实还有一些代码逻辑中诸如 while 循环的跳出条件在一些状况下失效，致使 Node.js 应用阻塞在循环中。以前咱们就算知道是进程阻塞也难以方便的定位到具体的问题代码以及产生问题的输入，如今借助于 Node.js 性能平台 提供的核心转储分析能力，相信你们能够比较容易地来解决这样的问题。

原文连接 本文为云栖社区原创内容，未经容许不得转载。