1. 程式人生 > >Node.js 應用故障排查手冊 —— 正確開啟 Chrome devtools

Node.js 應用故障排查手冊 —— 正確開啟 Chrome devtools

開發十年,就只剩下這套架構體系了! >>>   

楔子

前面的預備章節中我們大致瞭解瞭如何在伺服器上的 Node.js 應用出現問題時,從常規的錯誤日誌、系統/程序指標以及兜底的核心轉儲這些角度來排查問題。這樣就引出了下一個問題:我們知道程序的 CPU/Memory 高,或者拿到了程序 Crash 後的核心轉儲,要如何去進行分析定位到具體的 JavaScript 程式碼段。

其實 Chrome 自帶的 Devtools,對於 JavaScript 程式碼的上述 CPU/Memory 問題有著很好的原生解析展示,本節會給大家做一些實用功能和指標的介紹(基於 Chrome v72,不同的版本間使用方式存在差異)。

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

CPU 飆高問題

I. 匯出 JS 程式碼執行狀態

當我們通過第一節中提到的系統/程序指標排查發現當前的 Node.js 應用的 CPU 特別高時,首先我們需要去通過一些方式將當前 Node.js 應用一段時間內的 JavaScript 程式碼執行狀況 Dump 出來,這樣子才能分析知道 CPU 高的原因。幸運的是,V8 引擎內部實現了一個 CPU Profiler 能夠幫助我們完成一段時間內 JS 程式碼執行狀態的匯出,目前也有不少成熟的模組或者工具來幫我們完成這樣的操作。

v8-profiler 是一個老牌的 Node.js 應用效能分析工具,它可以很方便地幫助開發者匯出 JS 程式碼地執行狀態,我們可以在專案目錄執行如下命令安裝此模組:

npm install v8-profiler --save

接著可以在程式碼中按照如下方式獲取到 5s 內地 JS 程式碼執行狀態:

'use strict';

const v8Profiler = require('v8-profiler');
const title = 'test';
v8Profiler.startProfiling(title, true);
setTimeout(() => {
    const profiler = v8Profiler.stopProfiling(title);
    profiler.delete();
    console.log(profiler);
}, 5000);

那麼我們可以看到,v8-profiler 模組幫我匯出的程式碼執行狀態實際上是一個很大的 JSON 物件,我們可以將這個 JSON 物件序列化為字串後儲存到檔案:test.cpuprofile 。注意這裡的檔名字尾必須為 .cpuprofile ,否則 Chrome devtools 是不識別的。

注意:v8-profiler 目前也處於年久失修的狀態了,在 Node.js 8 和 Node.js 10 上已經無法正確編譯安裝了,如果你在 8 或者 10 的專案中想進行使用,可以試試看 v8-profiler-next

II. 分析 CPU Profile 檔案

藉助於 v8-profiler 拿到我們的 Node.js 應用一段時間內的 JS 程式碼執行狀態後,我們可以將其匯入 Chrome devtools 中進行分析展示。

在 Chrome 72 中,分析我們 Dump 出來的 CPU Profile 的方法已經和之前有所不同了,預設工具欄中也不會展示 CPU Profile 的分析頁面,我們需要通過點選工具欄右側的 更多 按鈕,然後選擇 More tools -> JavaScript Profiler 來進入到 CPU 的分析頁面,如下圖所示:

選中 JavaScript Profiler 後,在出現的頁面上點選 Load 按鈕,然後將剛才儲存得到的 test.cpuprofile 檔案載入進來,就可以看到 Chrome devtools 的解析結果了:

這裡預設的檢視是 Heavy 檢視,在這個檢視下,Devtools 會按照對你的應用的影響程度從高到低,將這些函式列舉出來,點選展開能夠看到這些列舉出來的函式的全路徑,方便你去程式碼中對應的位置進行排查。這裡解釋兩個比較重要的指標,以便讓大家能更有針對性地進行排查:

  • Self Time: 此函式本身程式碼段執行地時間(不包含任何呼叫)
  • Total Time: 此函式包含了其呼叫地其它函式總共的執行時間

像在上述地截圖例子中,ejs 模組在線上都應該開啟了快取,所以 ejs 模組的 compile 方法不應該出現在列表中,這顯然是一個非常可疑的效能損耗點,需要我們去展開找到原因。

除了 Heavy 檢視,Devtools 實際上還給我們提供了火焰圖來進行更多維度的展示,點選左上角可以切換:

火焰圖按照我們的 CPU 取樣時間軸進行展示,那麼在這裡我們更容易看到我們的 Node.js 應用在取樣期間 JS 程式碼的執行行為,新增的兩個指標這邊也給大家解釋一下其含義:

  • Aggregated self time: 在 CPU 取樣期間聚合後的此函式本身程式碼段的執行總時間(不包含其他呼叫)
  • Aggregated total time: 在 CPU 取樣期間聚合後的此函式包含了其呼叫地其它函式總共的執行總時間

綜上,藉助於 Chrome devtools 和能夠匯出當前 Node.js 應用 Javascript 程式碼執行狀態的模組,我們已經可以比較完備地對應用服務異常時,排查定位到相應的 Node.js 程序 CPU 很高的情況進行排查和定位分析了。在生產實踐中,這部分的 JS 程式碼的效能的分析往往也會用到新專案上線前的效能壓測中,有興趣的同學可以更深入地研究下。

記憶體洩漏問題

I. 判斷是否記憶體洩漏

在筆者的經歷中,記憶體洩漏問題是 Node.js 在線上執行時出現的問題種類中的重災區。尤其是三方庫自身的 Bug 或者開發者使用不當引起的記憶體洩漏,會讓很多的 Node.js 開發者感到束手無策。本節首先向讀者介紹下,什麼情況下我們的應用算是有很大的可能在發生記憶體洩漏呢?

實際上判斷我們的線上 Node.js 應用是否有記憶體洩漏也非常簡單:藉助於大家各自公司的一些系統和程序監控工具,如果我們發現 Node.js 應用的總記憶體佔用曲線 處於長時間的只增不降 ,並且堆記憶體按照趨勢突破了 堆限制的 70%  了,那麼基本上應用 很大可能 產生了洩漏。

當然事無絕對,如果確實應用的訪問量(QPS)也在一直增長中,那麼記憶體曲線只增不減也屬於正常情況,如果確實因為 QPS 的不斷增長導致堆記憶體超過堆限制的 70% 甚至 90%,此時我們需要考慮的擴容伺服器來緩解記憶體問題。

II. 匯出 JS 堆記憶體快照

如果確認了 Node.js 應用出現了記憶體洩漏的問題,那麼和上面 CPU 的問題一樣,我們需要通過一些辦法匯出 JS 記憶體快照(堆快照)來進行分析。V8 引擎同樣在內部提供了介面可以直接將分配在 V8 堆上的 JS 物件匯出來供開發者進行分析,這裡我們採用 heapdump 這個模組,首先依舊是執行如下命令進行安裝:

npm install heapdump --save

接著可以在程式碼中按照如下方法使用此模組:

'use sytrict';

const heapdump = require('heapdump');
heapdump.writeSnapshot('./test' + '.heapsnapshot');

這樣我們就在當前目錄下得到了一個堆快照檔案:test.heapsnapshot ,用文字編輯工具開啟這個檔案,可以看到其依舊是一個很大的 JSON 結構,同樣這裡的堆快照檔案字尾必須為 .heapsnapshot ,否則 Chrome devtools 是不識別的。

III. 分析堆快照

在 Chrome devtools 的工具欄中選擇 Memory 即可進入到分析頁面,如下圖所示:

然後點選頁面上的 Load 按鈕,選擇我們剛才生成 test.heapsnapshot 檔案,就可以看到分析結果,如下圖所示:

預設的檢視其實是一個 Summary 檢視,這裡的 Constructor 和我們編寫 JS 程式碼時的建構函式並無不同,都是指代此建構函式建立的物件,新版本的 Chrome devtools 中還在建構函式後面增加 * number 的資訊,它代表這個建構函式建立的例項的個數。

實際上在堆快照的分析檢視中,有兩個非常重要的概念需要大家去理解,否則很可能拿到堆快照看著分析結果也無所適從,它們是 Shallow Size 和 Retained Size ,要更好地去理解這兩個概念,我們需要先了解 支配樹。首先我們看如下簡化後的堆快照描述的記憶體關係圖:

這裡的 1 為根節點,即 GC 根,那麼對於物件 5 來說,如果我們想要讓物件 5 回收(即從 GC 根不可達),僅僅去掉物件 4 或者物件 3 對於物件 5 的引用是不夠的,因為顯然從根節點 1 可以分別從物件 3 或者物件 4 遍歷到物件 5。因此我們只有去掉物件 2 才能將物件 5 回收,所以在上面這個圖中,物件 5 的直接支配者是物件 2。照著這個思路,我們可以通過一定的演算法將上述簡化後的堆記憶體關係圖轉化為支配樹:

物件 1 到物件 8 間的支配關係描述如下:

  • 物件 1 支配物件 2
  • 物件 2 支配物件 3 、4 和 5
  • 物件 4 支配物件 6
  • 物件 5 支配物件 7
  • 物件 6 支配物件 8

好了,到這裡我們可以開始解釋什麼是 Shallow Size 和 Retained Size 了,實際上物件的 Shallow Size 就是物件自身被建立時,在 V8 堆上分配的大小,結合上面的例子,即物件 1 到 8 自身的大小。物件的 Retained Size 則是把此物件從堆上拿掉,則 Full GC 後 V8 堆能夠釋放出的空間大小。同樣結合上面的例子,支配樹的葉子節點物件 3、物件 7 和物件 8 因為沒有任何直接支配物件,因此其 Retained Size 等於其 Shallow Size。

將剩下的非葉子節點可以一一展開,為了篇幅描述方便,SZ_5表示物件 5 的 Shallow Size,RZ_5 表示物件 5 的 Retained Size,那麼可以得到如下結果:

  • 物件 3 的 Retained Size:RZ_3 = SZ_3
  • 物件 7 的 Retained Size:RZ_7 = SZ_7
  • 物件 8 的 Retained Size:RZ_8 = SZ_8
  • 物件 6 的 Retained Size:RZ_6 = SZ_6 + RZ_8 = SZ_6 + SZ_8
  • 物件 5 的 Retained Size:RZ_5 = SZ_5 + RZ_7 = SZ_5 + SZ_7
  • 物件 4 的 Retained Size:RZ_4 = SZ_4 + RZ_6 = SZ_4 + SZ_6 + SZ_8
  • 物件 2 的 Retained Size:RZ_2 = SZ_2 + RZ_3 + RZ_4 + RZ_5 = SZ_2 + SZ_3 + SZ_4 + SZ_5 + SZ_6 + SZ_7 + SZ_8
  • GC 根 1 的 Retained Size:RZ_1 = SZ_1 + RZ_2 = SZ_1 + SZ_2 + RZ_3 + RZ_4 + RZ_5 = SZ_2 + SZ_3 + SZ_4 + SZ_5 + SZ_6 + SZ_7 + SZ_8

這裡可以發現,GC 根的 Retained Size 等於堆上所有從此根出發可達物件的 Shallow Size 之和,這和我們的理解預期是相符合的,畢竟將 GC 根從堆上拿掉的話,原本就應當將從此根出發的所有物件都清理掉。

理解了這一點,回到我們最開始看到的預設總覽檢視中,正常來說,可能的洩漏物件往往其 Retained Size 特別大,我們可以在視窗中依據 Retained Size 進行排序來對那些佔據了堆空間絕大部分的物件進行排查:

假如確認了可疑物件,Chrome devtools 中也會給你自動展開方便你去定位到程式碼段,下面以 NativeModule 這個構造器生成的物件 vm 為例:

這裡上半部分是順序的引用關係,比如 NativeModule 例項 @45655 的 exports 屬性指向了物件 @45589,filename 屬性則指向一個字串 "vm.js";下半部分則是反向的引用關係:NativeModule 例項 @13021 的 _cache 屬性指向了 Object 例項 @41103,而 Object 例項 @41103 的 vm 屬性指向了 NativeModule 例項 @45655。

如果對這部分展示圖表比較暈的可以仔細看下上面的例子,因為找到可疑的洩漏物件,結合上圖能看到此物件下的屬性和值及其父引用關係鏈,絕大部分情況下我們就可以定位到生成可疑物件的 JS 程式碼段了。

實際上除了預設的 Summary 檢視,Chrome devtools 還提供了 Containment 和 Statistics 檢視,這裡再看下 Containment 檢視,選擇堆快照解析頁面的左上角可以進行切換,如下圖所示:

這個檢視實際上是堆快照解析出來的記憶體關係圖的直接展示,因此相比 Summary 檢視,從這個檢視中直接查詢可疑的洩漏物件相對比較困難。

結尾

Chrome devtools 實際上是非常強大的一個工具,本節也只是僅僅介紹了對 CPU Profile 和堆快照解析能力的介紹和常用檢視的使用指南,如果你仔細閱讀了本節內容,面對伺服器上定位到的 Node.js 應用 CPU 飆高或者記憶體洩漏這樣的問題,想必就可以做到心中有數不慌亂了。

作者:奕鈞

原文連結

​本文為雲棲社群原創內容,未經