Node.js 應用故障排查手冊 —— 綜合性 GC 問題和優化

楔子

本章前面兩節生產案例分別側重於單一的 CPU 高和單一的內存問題，咱們也給你們詳細展現了問題的定位排查過程，那麼實際上還有一類相對更復雜的場景——它本質上是 V8 引擎的 GC 引起的問題。

簡單的給你們介紹下什麼是 GC，GC 其實是語言引擎實現的一種自動垃圾回收機制，它會在設定的條件觸發時（好比堆內存達到必定值）時查看當前堆上哪些對象已經再也不使用，而且將這些沒有再使用到的對象所佔據的空間釋放出來。許多的現代高級語言都實現了這一機制，來減輕程序員的心智負擔。

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

GC 帶來的問題

雖然上面介紹中現代語言的 GC 機制解放了程序員間接提高了開發效率，可是萬事萬物都存在利弊，底層的引擎引入 GC 後程序員無需再關注對象什麼時候釋放的問題，那麼相對來講程序員也就沒辦法實現對本身編寫的程序的精準控制，它帶來兩大問題：

• 代碼編寫問題引起的內存泄漏
• 程序執行的性能下降

內存泄漏問題咱們已經在上一節的生產案例中體驗了一下，那麼後者是怎麼回事呢？

其實理解起來也很簡單：本來一個程序所有的工做都是執行業務邏輯，可是存在了 GC 機制後，程序總會在必定的條件下耗費時間在掃描堆空間找出再也不使用的對象上，這樣就變相下降了程序執行業務邏輯的時間，從而形成了性能的降低，並且下降的性能和耗費在 GC 上的時間，換言之即 GC 的次數 * 每次 GC 耗費的時間成正比。

問題現象與原始分析

如今你們應該對 GC 有了一個比較總體的瞭解，這裏咱們能夠看下 GC 引起的問題在生產中的表現是什麼樣的。在這個案例中，表象首先是 Node.js 性能平臺 上監控到進程的 CPU 達到 100%，可是此時服務器負載其實並不大，QPS 只有 100 上下，咱們按照前面提到的處理 CPU 問題的步驟抓取 CPU Profile 進行分析能夠看到：

此次的問題顯然是 Garbage Collector 耗費的 CPU 太多了，也就是 GC 的問題。實際上絕大部分的 GC 機制引起的問題每每表象都是反映在 Node.js 進程的 CPU 上，而本質上這類問題能夠認爲是引擎的 GC 引發的問題，也能夠理解爲內存問題，咱們看下這類問題的產生流程：

• 堆內存不斷達到觸發 GC 動做的預設條件
• 進程不斷觸發 GC 操做
• 進程 CPU 飆高

並且 GC 問題不像以前的 ejs 模板渲染引起的問題，就算咱們在 CPU Profile 中能夠看到這部分的耗費，可是想要優化解決這個問題基本是無從下手的，幸運的是 Node.js 提供了（實際上是 V8 引擎提供的）一系列的啓動 Flag 可以輸出進程觸發 GC 動做時的相關日誌以供開發者進行分析：

• --trace_gc:一行日誌簡要描述每次 GC 時的時間、類型、堆大小變化和產生緣由
• --trace_gc_verbose: 結合 --trace_gc 一塊兒開啓的話會展現每次 GC 後每一個 V8 堆空間的詳細情況
• --trace_gc_nvp: 每一次 GC 的一些詳細鍵值對信息，包含 GC 類型，暫停時間，內存變化等信息

加粗的 Flag 意味着咱們須要在啓動應用前加上才能在運行時生效，這部分的日誌其實是一個文本格式，惋惜的是 Chrome devtools 原生並不支持 GC 日誌的解析和結果展現，所以須要你們獲取到之後進行對應的按行解析處理，固然咱們也可使用社區提供 v8-gc-log-parser 這個模塊直接進行解析處理，對這一塊有興趣的同窗能夠看 @joyeeCheung 在 JS Interactive 的分享: Are Your V8 Garbage Collection Logs Speaking To You?，這裏不詳細展開。

更好的 GC 日誌展現

雖然 Chrome devtools 並不能直接幫助咱們解析展現 GC 日誌的結果，可是 Node.js 性能平臺 其實給你們提供了更方便的動態獲取線上運行進程的 GC 狀態信息以及對應的結果展現，換言之，開發者無需在運行你的 Node.js 應用前開啓上面提到的那些 Flag 而仍然能夠在想要獲取到 GC 信息時經過控制檯拿到 3 分鐘內的 GC 數據。

對應在這個案例中，咱們能夠進入平臺的應用實例詳情頁面，找到 GC 耗費特別大的進程，而後點擊 GC Trace 抓取 GC 數據：

這裏默認會抓取 3 分鐘的對應進程的 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 來提高應用性能。

優化新生代 GC

經過平臺提供的 GC 數據抓取和結果分析，咱們知道能夠去嘗試優化新生代的 GC 來達到提高應用性能的目的，而新生代的空間觸發 GC 的條件又是其空間被佔滿，那麼新生代的空間大小由 Flag --max-semi-space-size 控制，默認爲 16MB，所以咱們天然能夠想到要能夠經過調整默認的 Semi space 的值來進行優化。

這裏須要注意的是， 控制新生代空間的 Flag 在不一樣的 Node.js 版本下並非同樣的，你們具體能夠查看當前的版原本進行確認使用。

在這個案例中，顯然是默認的 16M 相對當前的應用來講顯得比較小，致使 Scavenge 過於頻繁，咱們首先嚐試經過啓動時增長 --max-semi-space-size=64 這個 Flag 來將默認的新生代使用到的空間大小從 16M 的值增大爲 64M，而且在流量比較大並且進程 CPU 很高時抓取 CPU Profile 觀察效果：

調整後能夠看到 Garbage collector 階段 CPU 耗費佔比降低到 7% 左右，再抓取 GC Trace 並觀察其展現結果確認是否是 Scavenge 階段的耗費降低了：

顯然，Semi space 調大爲 64M 後，Scavenge 次數從近 1000 次下降到 294 次，可是這種情況下每次的 Scavenge 回收耗時沒有明顯增長，仍是在 50 ~ 60ms 之間波動，所以 3 分鐘的 GC 追蹤總的停頓時間從 48s 降低到 12s，相對應的，業務的 QPS 提高了約 10% 左右。

那麼若是咱們經過 --max-semi-space-size 這個 Flag 來繼續調大新生代使用到的空間，是否是能夠進一步優化這個應用的性能呢？此時嘗試 --max-semi-space-size=128 來從 64M 調大到 128M，在進程 CPU 很高時繼續抓取 CPU Profile 來查看效果：

此時 Garbage collector 耗費降低相比上面的設置爲 64M 並非很明顯，GC 耗費降低佔比不到 1%，一樣咱們來抓取並觀察下 GC Trace 的結果來查看具體的緣由：

很明顯，形成相比設置爲 64M 時 GC 佔比提高不大的緣由是：雖然此時進一步調大了 Semi space 至 128M，而且 Scavenge 回收的次數確實從 294 次降低到 145 次，可是每次算法回收耗時近乎翻倍了，所以總收益並不明顯。

按照這個思路，咱們再使用 --max-semi-space-size=256 來將新生代使用的空間進一步增大到 256M 再來進行最後一次的觀察：

這裏和調整爲 128M 時是相似的狀況： 3 分鐘內 Scavenge 次數從 294 次降低到 72 次，可是相對的每次算法回收耗時波動到了 150ms 左右，所以總體性能並無顯著提高。

藉助於性能平臺的 GC 數據抓取和結果展現，經過以上的幾回嘗試改進 Semi space 的值後，咱們能夠看到從默認的 16M 設置到 64M 時，Node 應用的總體 GC 性能是有顯著提高的，而且反映到壓測 QPS 上大約提高了 10%；可是進一步將 Semi space 增大到 128M 和 256M 時，收益確並不明顯，並且 Semi space 自己也是做用於新生代對象快速內存分配，自己不宜設置的過大，所以此次優化最終選取對此項目 最優的運行時 Semi space 的值爲 64M。

結尾

在本生產案例中，咱們首先能夠看到，項目使用的三方庫其實也並不老是在全部場景下都不會有 Bug 的（實際上這是不可能的），所以在遇到三方庫的問題時咱們要勇於去從源碼的層面來對問題進行深刻的分析。

最後實際上在生產環境下經過 GC 方面的運行時調優來提高咱們的項目性能是一種你們不那麼經常使用的方式，這也有很大一部分緣由是應用運行時 GC 狀態自己不直接暴露給開發者。經過上面這個客戶案例，咱們能夠看到藉助於 Node.js 性能平臺，實時感知 Node 應用 GC 狀態以及進行對應的優化，使得不改一行代碼提高項目性能變成了一件很是容易的事情。

---

本文做者：奕鈞

閱讀原文

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