Node.js 应用故障排查手册 —— 类死循环导致进程阻塞
類死循環導致進程阻塞
楔子
在實踐篇一中我們看到了兩個表象都是和 CPU 相關的生產問題,它們基本也是我們在線上可能遇到的這一類問題的典型案例,而實際上這兩個案例也存在一個共同點:我們可以通過?Node.js 性能平臺?導出進程對應的 CPU Profile 信息來進行分析定位問題,但是實際在線上的一些極端情況下,我們遇到的故障是沒有辦法通過輕量的 V8 引擎暴露的 CPU Profile 接口(僅部分定制的 AliNode runtime 版本支持,詳見下文)來獲取足夠的進程狀態信息進行分析的,此時我們又回到了束手無策的狀態。
本章節將從一個生產環境下 Node.js 應用出現進程級別阻塞導致的不再提供服務的問題場景來給大家展示下如何處理這類相對極端的應用故障。
本書首發在 Github,倉庫地址:https://github.com/aliyun-node/Node.js-Troubleshooting-Guide,云棲社區會同步更新。
最小化復現代碼
這個例子稍微有些特殊,我們首先給出生產案例的最小化復現代碼,有興趣的同學可以親自運行一番,這樣結合下文的此類問題的排查過程,能更加清晰的看到我們面對這樣的問題時的排查思路,問題最小代碼如下,基于?Egg.js?:
'use strict'; const Controller = require('egg').Controller;class RegexpController extends Controller {async long() {const { ctx } = this;// str 模擬用戶輸入的問題字符串let str = '<br/> ' +' 早餐后自由活動,于指定時間集合自行辦理退房手續。';str += '<br/> <br/>' +' <br/> ' +' <br/>';str += ' <br/>' +' ' +' ' +' <br/>';str += ' <br/> <br/>';str += ' ' +' ' +' 根據船班時間,自行前往暹粒機場,返回中國。<br/>';str += '如需送機服務,需增加280/每單。<br/>';const r = str.replace(/(^(\s*?<br[\s\/]*?>\*?)+|(\s*?<br[\s\/]*?>\s*?)+?$)/igm, '');ctx.body = r;} }module.exports = RegexpController;問題應用狀態
其實這個例子對應的問題場景可能很多 Node.js 開發者都遇到過,它非常有意思,我們首先來看下出現這類故障時我們的 Node.js 應用的狀態。當我們收到在平臺配置的 CPU 告警信息后,登錄性能平臺進入對應的告警應用找到出問題的 CPU 非常高的進程:然后點擊?數據趨勢?按鈕查看此進程當前的狀態信息:
可以看到進程的 CPU 使用率曲線一直處于近乎 100% 的狀態,此時進程不再響應其余的請求,而且我們通過跳板機進入生產環境又可以看到進程其實是存活的,并沒有掛掉,此時基本上可以判斷:此 Node.js 進程因為在執行某個同步函數處于阻塞狀態,且一直卡在此同步函數的執行上。
Node.js 的設計運行模式就是單主線程,并發靠的是底層實現的一整套異步 I/O 和事件循環的調度。簡單的說,具體到事件循環中的某一次,如果我們在執行需要很長時間的同步函數(比如需要循環執行很久才能跳出的?while?循環),那么整個事件循環都會阻塞在這里等待其結束后才能進入下一次,這就是不推薦大家在非初始化的邏輯中使用諸如?fs.readFileSync?等同步方法的原因。
排查方法
這樣的問題其實非常難以排查,原因在于我們沒辦法知道什么樣的用戶輸入造成了這樣的阻塞,所以本地幾乎無法復現問題。幸運的是,性能平臺目前有不止一種解決辦法處理這種類死循環的問題,我們來詳細看下。
I. CPU Profile
這個分析方法可以說是我們的老朋友了,因為類死循環的問題本質上也是 CPU 高的問題,因此我們只要對問題進程抓取 CPU Profile,就能看到當前卡在哪個函數了。需要注意的是,進程假死狀態下是無法直接使用 V8 引擎提供的抓取 CPU Profile 文件的接口,因此工具篇章節的?正確打開 Chrome devtools?一節中提到的 v8-profiler 這樣的第三方模塊是無法正常工作的。
不過定制過的 AliNode runtime 采用了一定的方法規避了這個問題,然而遺憾的是依舊并不是所有的 AliNode runtime 版本都支持在類死循環狀態下抓取 CPU Profile,這里實際上對大家使用的 Runtime 版本有要求:
- AliNode V3 版本需要 >=?v3.11.4
- AliNode V4 版本需要 >=?v4.2.1
- AliNode V1 和 V2 版本不支持
如果你的線上 AliNode runtime 版本恰好符合需求,那么可以按照前面?Node.js 性能平臺使用指南?提到的那樣,對問題進程抓取 3 分鐘的 CPU Profile,并且使用 AliNode 定制的火焰圖分析:
這里可以看到,抓取到的問題進程 3 分鐘的 CPU 全部耗費在?long?函數里面的?replace?方法上,這和我們提供的最小化復現代碼一致,因此可以判斷?long?函數內的正則存在問題進行修復。
II. 診斷報告
診斷報告也是 AliNode 定制的一項導出更多更詳細的 Node.js 進程當前狀態的能力,導出的信息也包含當前的 JavaScript 代碼執行棧以及一些其它進程與系統信息。它與 CPU Profile 的區別主要在兩個地方:
- 診斷報告主要針對此刻進程狀態的導出,CPU Profile 則是一段時間內的 JavaScript 代碼執行狀態
- 診斷報告除了此刻 JavaScript 調用棧信息,還包含了 Native C/C++ 棧信息、Libuv 句柄和部分操作系統信息
當我們的進程處于假死狀態時,顯然不管是一段時間內還是此時此刻的 JavaScript 執行狀況,必然都是卡在我們代碼中的某個函數上,因此我們可以使用診斷報告來處理這樣的問題,當然診斷報告功能同樣也對 AliNode runtime 版本有所要求:
- AliNode V2 版本需要 >=?v2.5.2
- AliNode V3 版本需要 >=?v3.11.8
- AliNode V4 版本需要 >=?v4.3.0
- AliNode V1 版本不支持
- 且要求:Agenthub/Egg-alinode 依賴的 Commandx 版本 >= v1.5.3
如果你使用的 AliNode runtime 版本符合要求,即可進入平臺應用對應的實例信息頁面,選中問題進程:
然后點擊?診斷報告?即可生成此刻問題進程的狀態信息報告:
診斷報告雖然包含了很多的進程和系統信息,但是其本身是一個相對輕量的操作,故而很快就會結束,此時繼續點擊?轉儲?按鈕將生成的診斷報告上傳至云端以供在線分析展示:
繼續點擊?分析?按鈕查看 AliNode 定制的分析功能,展示結果如下:
結果頁面上面的概覽信息比較簡單,我們來看下?JavaScript 棧?頁面的內容,這里顯然也告訴我們當前的 JS 函數卡在?long?方法里面,并且比 CPU Profile 更加詳細的是還帶上了具體阻塞在?long?方法的哪一行,對比我們提供給大家的最小復現代碼其實就是執行?str.replace?這一行,也就是問題的正則匹配操作所在的地方。
III. 核心轉儲分析
其實很多朋友看到這里會有疑惑:既然 CPU Profile 分析和診斷報告已經能夠找到問題所在了,為什么我們還要繼續介紹相對比較重的核心轉儲分析功能呢?
其實道理也很簡單,不管是類死循環狀態下的 CPU Profile 抓取還是診斷報告功能的使用,都對問題進程的 AliNode runtime 版本有所要求,而且更重要的是,這兩種方法我們都只能獲取到問題正則的代碼位置,但是我們無法知道什么樣的用戶輸入在執行這樣的正則時會觸發進程阻塞的問題,這會給我們分析和給出針對性的處理造成困擾。因此,這里最后給大家介紹對 AliNode runtime 版本沒有任何要求,且能拿到更精準信息的核心轉儲分析功能。
首先按照預備章節的核心轉儲一節中提到的?手動生成 Core dump?文件的方法,我們對問題進程進行?sudo gcore <pid>?的方式獲取到核心轉儲文件,然后在平臺的詳情頁面,將鼠標移動到左邊 Tab 欄目的?文件?按鈕上,可以看到?Coredump 文件?的按鈕:
點擊后可以進入 Core dump 文件列表頁,然后點擊上方的?上傳?按鈕進行核心轉儲文件的上傳操作:
這里需要注意的是,請將 Core dump 文件以?.core?結尾重命名,而對應的 Node 可執行文件以?.node?結尾重命名,推薦的命名方式為?<os info>-<alinode/node>-<version>.node,方便以后回顧,比如 centos7-alinode-v4.7.2.node 這種。最后 Core dump 文件和 Node 可執行文件之間必須是?一一對應?的關系。這里一一對應指的是:這份 Core dump 文件必須是由這個 Node 可執行文件啟動的進程生成的,如果這兩者沒有一一對應,分析結果往往是無效信息。
因為 Core dump 文件一般來說都比較大,所以上傳會比較慢,耐心等待至上傳完畢后,我們就可以使用 AliNode 定制的核心轉儲文件分析功能進行分析了,點擊?分析?按鈕即可:
此時我們在新打開的分析結果頁面可以看到如下的分析結果展示信息:
這個頁面的各項含義在工具篇的 Node.js 性能平臺使用指南的 [最佳實踐——核心轉儲分析]() 一節已經解釋過,這里不再贅述,這里直接展開 JavaScript 棧信息:
這里可以看到得到的結論和前面的 CPU Profile 分析以及診斷報告分析一致,都能定位到提供的最小復現代碼中的?long?方法中的異常正則匹配,但是核心轉儲文件分析比前面兩者多了導致當前 Node.js 進程產生問題的異常字符串:??"<br/> 早餐后自由活動,于指定時間集合自行辦理退房手續。<br/> <br/> <br/> <br/> <br/> <br/> <br/> <br/> 根據船班時間,自行前往暹粒機場,返回中國。<br/>如需送機服務,需增加280/每單。<br/>"?,有了這個觸發正則執行異常的問題字符串,我們無論是構造本地復現樣例還是進一步分析都有了重要的信息依靠。
分析問題
上一節中我們采用了 Node.js 性能平臺提供的三種不同的方式分析定位到了線上應用處于假死狀態的原因,這里來簡單的解釋下為什么字符串的正則匹配會造成類死循環的狀態,它實際上異常的用戶輸入觸發了?正則表達式災難性的回溯,會導致執行時間要耗費幾年甚至幾十年,顯然不管是那種情況,單主工作線程的模型會導致我們的 Node.js 應用處于假死狀態,即進程依舊存活,但是卻不再處理新的請求。
關于正則回溯的原因有興趣的同學可以參見?小心別落入正則回溯陷阱?一文。
結尾
其實這類正則回溯引發的進程級別阻塞問題,本質上都是由于不可控的用戶輸入引發的,而 Node.js 應用又往往作為 Web 應用直接面向一線客戶,無時不刻地處理千奇百怪的用戶請求,因此更容易觸發這樣的問題。
相似的問題其實還有一些代碼邏輯中諸如?while?循環的跳出條件在一些情況下失效,導致 Node.js 應用阻塞在循環中。之前我們就算知道是進程阻塞也難以方便的定位到具體的問題代碼以及產生問題的輸入,現在借助于?Node.js 性能平臺?提供的核心轉儲分析能力,相信大家可以比較容易地來解決這樣的問題。
原文鏈接
本文為云棲社區原創內容,未經允許不得轉載。
總結
以上是生活随笔為你收集整理的Node.js 应用故障排查手册 —— 类死循环导致进程阻塞的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 用AI说再见!“辣眼睛”的买家秀
- 下一篇: 2019阿里云开年Hi购季云通信分会场全