Node.js 应用故障排查手册 —— 利用 CPU 分析调优吞吐量
楔子
在我們想要新上線一個(gè) Node.js 應(yīng)用之前,尤其是技術(shù)棧切換的第一個(gè) Node.js 應(yīng)用,由于擔(dān)心其在線上的吞吐量表現(xiàn),肯定會(huì)想要進(jìn)行性能壓測(cè),以便對(duì)其在當(dāng)前的集群規(guī)模下能抗住多少流量有一個(gè)預(yù)估。本案例實(shí)際上正是在這樣的一個(gè)場(chǎng)景下,我們想要上線 Node.js 技術(shù)棧來做前后端分離,那么刨開后端服務(wù)的響應(yīng) QPS,純使用 Node.js 進(jìn)行的模板渲染能有怎么樣的表現(xiàn),這是大家非常關(guān)心的問題。
本書首發(fā)在 Github,倉(cāng)庫(kù)地址:https://github.com/aliyun-node/Node.js-Troubleshooting-Guide,云棲社區(qū)會(huì)同步更新。
優(yōu)化過程
集群在性能壓測(cè)下反映出來的整體能力其實(shí)由單機(jī)吞吐量就可以測(cè)算得知,因此這次的性能壓測(cè)采用的 4 核 8G 內(nèi)存的服務(wù)器進(jìn)行壓測(cè),并且頁面使用比較流行的 ejs 進(jìn)行服務(wù)端渲染,進(jìn)程數(shù)則按照核數(shù)使用 PM2 啟動(dòng)了四個(gè)業(yè)務(wù)子進(jìn)程來運(yùn)行。
I. 開始?jí)簻y(cè)
完成這些準(zhǔn)備后,使用阿里云提供的?PTS?性能壓測(cè)工具進(jìn)行壓力測(cè)試,此時(shí)大致單機(jī) ejs 模板渲染的 QPS 在?200?左右,此時(shí)通過?Node.js 性能平臺(tái)?監(jiān)控可以看到四個(gè)子進(jìn)程的 CPU 基本都在 100%,即?CPU 負(fù)載達(dá)到了瓶頸,但是區(qū)區(qū) 200 左右的 QPS 顯然系統(tǒng)整體渲染非常的不理想。
II. 模板緩存
因?yàn)槭?CPU 達(dá)到了系統(tǒng)瓶頸導(dǎo)致整體 QPS 上不去,因此按照第二部分工具篇章節(jié)的方法,我們?cè)谄脚_(tái)上抓了?壓測(cè)期間?的 3 分鐘的 CPU Profile,展現(xiàn)的結(jié)果如下圖所示:
這里就看到了很奇怪的地方,因?yàn)閴簻y(cè)環(huán)境下我們已經(jīng)打開了模板緩存,按理來說不會(huì)再出現(xiàn)?ejs.compile?函數(shù)對(duì)應(yīng)的模板編譯才對(duì)。仔細(xì)比對(duì)項(xiàng)目中的渲染邏輯代碼,發(fā)現(xiàn)這部分采用了一個(gè)比較不常見的模塊?koa-view,項(xiàng)目開發(fā)者想當(dāng)然地用 ejs 模塊地入?yún)⒎绞絺魅肓?cache: true,但是實(shí)際上該模塊并沒有對(duì) ejs 模板做更好的支持,因此實(shí)際壓測(cè)情況下模板緩存并沒有生效,而模板地編譯動(dòng)作本質(zhì)上字符串處理,它恰恰是一個(gè) CPU 密集地操作,這就導(dǎo)致了 QPS 達(dá)不到預(yù)期的狀況。
了解到原因之后,首先我們將 koa-view 替換為更好用的?koa-ejs?模塊,并且按照 koa-ejs 的文檔正確開啟緩存:
render(app, {root: path.join(__dirname, 'view'),viewExt: 'html',cache: true });再次進(jìn)行壓測(cè)后,單機(jī)下的 QPS 提升到了?600?左右,雖然大約提升了三倍的性能,但是仍然達(dá)不到預(yù)期的目標(biāo)。
III. include 編譯
為了繼續(xù)優(yōu)化進(jìn)一步提升服務(wù)器的渲染性能,我們繼續(xù)在壓測(cè)期間抓取 3 分鐘的 CPU Profile 進(jìn)行查看:
可以看到,我們雖然已經(jīng)確認(rèn)使用 koa-ejs 模塊且正確開啟了緩存,但是壓測(cè)期間的 CPU Profile 里面竟然還有 ejs 的 compile 動(dòng)作!繼續(xù)展開這里的 compile,發(fā)現(xiàn)是?includeFile?時(shí)引入的,繼續(xù)回到項(xiàng)目本身,觀察壓測(cè)的頁面模板,確實(shí)使用了 ejs 注入的?include?方法來引入其它模板:
<%- include("../xxx") %>對(duì)比 ejs 的源代碼后,這個(gè)注入的 include 函數(shù)調(diào)用鏈確實(shí)也是?include ->?includeFile -> handleCache -> compile,與壓測(cè)得到的 CPU Profile 展示的內(nèi)容一致。那么下面紅框內(nèi)的?replace?部分也是在 compile 過程中產(chǎn)生的。
到了這里開始懷疑 koa-ejs 模塊沒有正確地將 cache 參數(shù)傳遞給真正負(fù)責(zé)渲染地 ejs 模塊,導(dǎo)致這個(gè)問題地發(fā)生,所以繼續(xù)去閱讀 koa-ejs 的緩存設(shè)置,以下是簡(jiǎn)化后的邏輯(koa-ejs@4.1.1 版本):
const cache = Object.create(null);async function render(view, options) {view += settings.viewExt;const viewPath = path.join(settings.root, view);// 如果有緩存直接使用緩存后的模板解析得到的函數(shù)進(jìn)行渲染if (settings.cache && cache[viewPath]) {return cache[viewPath].call(options.scope, options);}// 沒有緩存首次渲染調(diào)用 ejs.compile 進(jìn)行編譯const tpl = await fs.readFile(viewPath, 'utf8');const fn = ejs.compile(tpl, {filename: viewPath,_with: settings._with,compileDebug: settings.debug && settings.compileDebug,debug: settings.debug,delimiter: settings.delimiter});// 將 ejs.compile 得到的模板解析函數(shù)緩存起來if (settings.cache) {cache[viewPath] = fn;}return fn.call(options.scope, options); }顯然,koa-ejs 模板的模板緩存是完全自己實(shí)現(xiàn)的,并沒有在調(diào)用 ejs.compile 方法時(shí)傳入的 option 參數(shù)內(nèi)將用戶設(shè)置的 cache 參數(shù)傳遞過去而使用 ejs 模塊提供的 cache 能力。但是偏偏項(xiàng)目在模板內(nèi)又直接使用了 ejs 模塊注入的 include?方法進(jìn)行模板間的調(diào)用,產(chǎn)生的結(jié)果就是只緩存了主模板,而主模板使用 include 調(diào)用別的模板還是會(huì)重新進(jìn)行編譯解析,進(jìn)而造成壓測(cè)下還是存在大量重復(fù)的模板編譯動(dòng)作導(dǎo)致 QPS 升不上去。
再次找到了問題的根源,為了驗(yàn)證是否是 koa-ejs 模塊本身的 bug,我們?cè)陧?xiàng)目中將其渲染邏輯稍作更改:
const fn = ejs.compile(tpl, {filename: viewPath,_with: settings._with,compileDebug: settings.debug && settings.compileDebug,debug: settings.debug,delimiter: settings.delimiter,// 將用戶設(shè)置的 cache 參數(shù)傳遞給 ejs 而使用到其提供的緩存能力cache: settings.cache });然后打包后進(jìn)行壓測(cè),此時(shí)單機(jī) QPS 從?600 提升至?4000?左右,基本達(dá)到了上線前的性能預(yù)期,為了確認(rèn)壓測(cè)下是否還有模板的編譯動(dòng)作,我們繼續(xù)在?Node.js 性能平臺(tái)?上抓取壓測(cè)期間 3 分鐘的 CPU Profile:
可以看到上述對(duì) koa-ejs 模板進(jìn)行優(yōu)化后,ejs.compile 確實(shí)消失了,而壓測(cè)期間不再有大量重復(fù)且耗費(fèi) CPU 的編譯動(dòng)作后,應(yīng)用整體的性能比最開始有了?20?倍左右的提升。文中 koa-ejs 模塊緩存問題已經(jīng)在 4.1.2 版本(包含)之后被修復(fù)了,詳情可以見?cache include file,如果大家使用的 koa-ejs?版本 >= 4.1.2 就可以放心使用。
結(jié)尾
CPU Profile 本質(zhì)上以可讀的方式反映給開發(fā)者運(yùn)行時(shí)的 JavaScript 代碼執(zhí)行頻繁程度,除了在線上進(jìn)程出現(xiàn)負(fù)載很高時(shí)能夠用來定位問題代碼之外,它在我們上線前進(jìn)行性能壓測(cè)和對(duì)應(yīng)的性能調(diào)優(yōu)時(shí)也能提供巨大的幫助。這里需要注意的是:僅當(dāng)進(jìn)程 CPU 負(fù)載非常高的時(shí)候去抓取得到的 CPU Profile 才能真正反饋給我們問題所在。
在這個(gè)源自真實(shí)生產(chǎn)的案例中,我們也可以看到,正確和不正確地去使用 Node.js 開發(fā)應(yīng)用其前后運(yùn)行效率能達(dá)到二十倍的差距,Node.js 作為一門服務(wù)端技術(shù)棧發(fā)展至今日,其本身能夠提供的性能是毋庸置疑的,絕大部分情況下執(zhí)行效率不佳是由我們自身的業(yè)務(wù)代碼或者三方庫(kù)本身的 Bug 引起的,Node.js 性能平臺(tái)?則可以幫助我們以比較方便的方式找出這些 Bug。
原文鏈接
本文為云棲社區(qū)原創(chuàng)內(nèi)容,未經(jīng)允許不得轉(zhuǎn)載。
總結(jié)
以上是生活随笔為你收集整理的Node.js 应用故障排查手册 —— 利用 CPU 分析调优吞吐量的全部?jī)?nèi)容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: Auto-Keras与AutoML:入门
- 下一篇: 印度版的“大众点评”如何将 Food F