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 飆高或者內存泄漏這樣的問題,想必就可以做到心中有數不慌亂了。
原文鏈接
本文為云棲社區原創內容,未經允許不得轉載。
總結
以上是生活随笔為你收集整理的Node.js 应用故障排查手册 —— 正确打开 Chrome devtools的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 达摩院里的女Leader,一面温柔似水一
- 下一篇: Euler 今日问世!国内首个工业级的图