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 狀態以及進行對應的優化,使得不改一行代碼提升項目性能變成了一件非常容易的事情。
原文鏈接
本文為云棲社區原創內容,未經允許不得轉載。
總結
以上是生活随笔為你收集整理的Node.js 应用故障排查手册 —— 综合性 GC 问题和优化的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 阿里云安全肖力:从RSA2019看安全技
- 下一篇: 物联网现状及落地难点