Node.js 應用故障排查手冊 —— 雪崩型內存泄漏問題

摘要： 還有一些問題場景下下應用的內存泄漏很是嚴重和迅速，甚至於在咱們的告警系統感知以前就已經形成應用的 OOM 了，這時咱們來不及或者說根本沒辦法獲取到堆快照，所以就沒有辦法藉助於以前的辦法來分析爲何進程會內存泄漏到溢出進而 Crash 的緣由了。

楔子

實踐篇一中咱們也看到了一個比較典型的因爲開發者不當使用第三方庫，並且在配置信息中攜帶了三方庫自己使用不到的信息，致使了內存泄漏的案例，實際上相似這種相對緩慢的 Node.js 應用內存泄漏問題咱們老是能夠在合適的機會抓取堆快照進行分析，並且堆快照通常來講確實是分析內存泄漏問題的最佳手段。

可是還有一些問題場景下下應用的內存泄漏很是嚴重和迅速，甚至於在咱們的告警系統感知以前就已經形成應用的 OOM 了，這時咱們來不及或者說根本沒辦法獲取到堆快照，所以就沒有辦法藉助於以前的辦法來分析爲何進程會內存泄漏到溢出進而 Crash 的緣由了。這種問題場景實際上屬於線上 Node.js 應用內存問題的一個極端情況，本節將一樣從源自真實生產的一個案例來來給你們講解下如何處理這類極端內存異常。

本書首發在 Github，倉庫地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，雲棲社區會同步更新。

最小化復現代碼

一樣咱們由於例子的特殊性，咱們須要首先給出到你們生產案例的最小化復現代碼，建議讀者自行運行一番此代碼，這樣結合起來看下面的排查分析過程會更有收穫。最小復現代碼仍是基於 Egg.js，以下所示：

'use strict';
const Controller = require('egg').Controller;
const fs = require('fs');
const path = require('path');
const util = require('util');
const readFile = util.promisify(fs.readFile);

class DatabaseError extends Error {
  constructor(message, stack, sql) {
    super();
    this.name = 'SequelizeDatabaseError';
    this.message = message;
    this.stack = stack;
    this.sql = sql;
  }
}

class MemoryController extends Controller {
  async oom() {
    const { ctx } = this;
    let bigErrorMessage = await readFile(path.join(__dirname, 'resource/error.txt'));
    bigErrorMessage = bigErrorMessage.toString();
    const error = new DatabaseError(bigErrorMessage, bigErrorMessage, bigErrorMessage);
    ctx.logger.error(error);
    ctx.body = { ok: false };
  }
}

module.exports = MemoryController;

這裏咱們還須要在 app/controller/ 目錄下建立一個 resource 文件夾，而且在這個文件夾中添加一個 error.txt，這個 TXT 內容隨意，只要是一個能超過 100M 的很大的字符串便可。 

值得注意的是，其實這裏的問題已經在 egg-logger >= 1.7.1 的版本中修復了，因此要復現當時的情況，你還須要在 Demo 的根目錄執行如下的三條命令以恢復當時的版本情況：

rm -rf package-lock.json 
rm -rf node_modules/egg/egg-logger
npm install egg-logger@1.7.0

最後使用 npm run dev 啓動這個問題最小化復現的 Demo。

感知進程出現問題

這個案例下，實際上咱們的線上 Node.js 應用幾乎是觸發了這個 Bug 後瞬間內存溢出而後 Crash 的，而平臺預設的內存閾值告警，其實是由一個定時上報的邏輯構成，所以存在延時，也致使了這個案例下咱們沒法像 冗餘配置傳遞引起的內存溢出 問題那樣獲取到 Node.js 進程級別的內存超過預設閾值的告警。

那麼咱們如何來感知到這裏的錯誤的呢？這裏咱們的服務器配置過了 ulimit -c unlimited ，所以 Node.js 應用 Crash 的時候內核會自動生成核心轉儲文件，並且性能平臺目前也支持核心轉儲文件的生成預警，這一條規則目前也被放入了預設的快速添加告警規則中，能夠參考工具篇中 Node.js 性能平臺使用指南 - 配置合適的告警 一節，詳細的規則內容以下所示：

這裏須要注意的是，核心轉儲文件告警須要咱們在服務器上安裝的 Agenthub/Agentx 依賴的 Commandx 模塊的版本在 1.5.2 之上（包含），這一塊更詳細的信息也能夠看官方文檔 核心轉儲分析能力 一節。

問題排查過程

I. 分析棧信息

依靠上面提到的平臺提供的核心轉儲文件生成時給出的告警，咱們在收到報警短信時登陸控制檯，能夠看到 Coredump 文件列表出現了新生成的核心轉儲文件，繼續參照工具篇中 Node.js 性能平臺使用指南 - 核心轉儲分析 中給出的轉儲和 AliNode 定製分析的過程，咱們能夠看到以下的分析結果展現信息：

一樣咱們直接展開 JavaScript 棧信息查看應用 Crash 那一刻的棧信息：

截圖中忽略掉了 Native C/C++ 代碼的棧信息，這裏其實僅僅看 JavaScript 棧信息就能獲得結論了，經過翻閱比對出問題的 egg-logger@1.7.0 中 lib/utils.js 的代碼內容：

function formatError(err) {
  // ...
  // 這裏對 Error 對象的 key 和 value 調用 inspect 方法進行序列化
  const errProperties = Object.keys(err).map(key => inspect(key, err[key])).join('\n');
  // ...
}

// inspect 方法其實是調用 require('util').inspect 來對錯誤對象的 value 進行序列化
function inspect(key, value) {
  return `${key}: ${util.inspect(value, { breakLength: Infinity })}`;
}

這樣咱們就知道了線上 Node.js 應用在 Crash 的那一刻正在使用 require('util').inspect 對某個字符串進行序列化操做。

II. 可疑字符串

那麼這個序列化的動做到底是不是形成進程 Crash 的元兇呢？咱們接着來點擊 inspect 函數的參數來展開查看這個可疑的字符串的詳細信息，以下圖所示：

點擊紅框中的參數，獲得字符串的詳情頁面連接，以下圖所示：

再次點擊這裏的 detail 連接，既可在彈出的新頁面中看到這個可疑字符串的所有信息：

這裏能夠看到，這個正在被 util.inspect 的字符串大小高達 186.94 兆，顯然正是在序列化這麼大的字符串的時候，形成了線上 Node.js 應用的堆內存雪崩，幾乎在瞬間就內存溢出致使 Crash。

值得一提的是，咱們還能夠點擊上圖中的 + 號來在當前頁面展現更多的問題字符串內容：

也能夠在頁面上點擊 一鍵導出 按鈕下載問題完整的字符串：

畢竟對於這樣的問題來講，若是能抓到產生問題的元兇參數，起碼能更方便地進行本地復現。

III. 修復問題

那麼知道了緣由，其實修復此問題就比較簡單了，Egg-logger 官方是使用 circular-json 來替換掉原生的 util.inspect 序列化動做，而且增長序列化後的字符串最大隻保留 10000 個字符的限制，這樣就解決這種包含大字符串的錯誤對象在 Egg-logger 模塊中的序列化問題。

結尾

本節的給你們展示了對於線上 Node.js 應用出現瞬間 Crash 問題時的排查思路，而在最小化復現 Demo 對應的那個真實線上故障中，其實是拼接的 SQL 語句很是大，大小約爲 120M，所以首先致使數據庫操做失敗，接着數據庫操做失敗後輸出的 DatabaseError 對象實例上則原封不動地將問題 SQL 語句設置到屬性上，從而致使了 ctx.logger.error(error) 時堆內存的雪崩。

在 Node.js 性能平臺 提供的 核心轉儲告警 + 在線分析能力 的幫助下，此類沒法獲取到常規 CPU Profile 和堆快照等信息的進程無端崩潰問題也變得有跡可循了，實際上它做爲一種兜底分析手段，在很大程度上提高了開發者真正將 Node.js 運用到服務端生產環境中的信心。

---

本文做者：奕鈞

閱讀原文

本文爲雲棲社區原創內容，未經容許不得轉載。