楔子
在我們想要新上線一個 Node.js 應用之前，尤其是技術棧切換的第一個 Node.js 應用，由於擔心其在線上的吞吐量表現，肯定會想要進行性能壓測，以便對其在當前的集群規模下能抗住多少流量有一個預估。本案例實際上正是在這樣的一個場景下，我們想要上線 Node.js 技術棧來做前後端分離，那麼刨開後端服務的響應 QPS，純使用 Node.js 進行的模板渲染能有怎麼樣的表現，這是大家非常關心的問題。
本書首發在 Github，倉庫地址：https://github.com/aliyun-node/Node.js-Troubleshooting-Guide，雲棲社區會同步更新。
優化過程
集群在性能壓測下反映出來的整體能力其實由單機吞吐量就可以測算得知，因此這次的性能壓測採用的 4 核 8G 內存的服務器進行壓測，並且頁面使用比較流行的 ejs 進行服務端渲染，進程數則按照核數使用 PM2 啟動了四個業務子進程來運行。
I. 開始壓測
完成這些準備後，使用阿里雲提供的 PTS 性能壓測工具進行壓力測試，此時大致單機 ejs 模板渲染的 QPS 在 200 左右，此時通過 Node.js 性能平臺 監控可以看到四個子進程的 CPU 基本都在 100%，即 CPU 負載達到了瓶頸，但是區區 200 左右的 QPS 顯然系統整體渲染非常的不理想。
II. 模板緩存
因為是 CPU 達到了系統瓶頸導致整體 QPS 上不去，因此按照第二部分工具篇章節的方法，我們在平臺上抓了 壓測期間 的 3 分鐘的 CPU Profile，展現的結果如下圖所示：
這裡就看到了很奇怪的地方，因為壓測環境下我們已經打開了模板緩存，按理來說不會再出現 ejs.compile 函數對應的模板編譯才對。仔細比對項目中的渲染邏輯代碼，發現這部分採用了一個比較不常見的模塊 koa-view，項目開發者想當然地用 ejs 模塊地入參方式傳入了 cache: true，但是實際上該模塊並沒有對 ejs 模板做更好的支持，因此實際壓測情況下模板緩存並沒有生效，而模板地編譯動作本質上字符串處理，它恰恰是一個 CPU 密集地操作，這就導致了 QPS 達不到預期的狀況。
瞭解到原因之後，首先我們將 koa-view 替換為更好用的 koa-ejs 模塊，並且按照 koa-ejs 的文檔正確開啟緩存：
render(app, {
root: path.join(__dirname, 'view'),
viewExt: 'html',
cache: true
});
再次進行壓測後，單機下的 QPS 提升到了 600 左右，雖然大約提升了三倍的性能，但是仍然達不到預期的目標。
III. include 編譯
為了繼續優化進一步提升服務器的渲染性能，我們繼續在壓測期間抓取 3 分鐘的 CPU Profile 進行查看：
可以看到，我們雖然已經確認使用 koa-ejs 模塊且正確開啟了緩存，但是壓測期間的 CPU Profile 裡面竟然還有 ejs 的 compile 動作！繼續展開這裡的 compile，發現是 includeFile 時引入的，繼續回到項目本身，觀察壓測的頁面模板，確實使用了 ejs 注入的 include 方法來引入其它模板：
對比 ejs 的源代碼後，這個注入的 include 函數調用鏈確實也是 include -> includeFile -> handleCache -> compile，與壓測得到的 CPU Profile 展示的內容一致。那麼下面紅框內的 replace 部分也是在 compile 過程中產生的。
到了這裡開始懷疑 koa-ejs 模塊沒有正確地將 cache 參數傳遞給真正負責渲染地 ejs 模塊，導致這個問題地發生，所以繼續去閱讀 koa-ejs 的緩存設置，以下是簡化後的邏輯（[email protected] 版本）：
const cache = Object.create(null);
async function render(view, options) {
view += settings.viewExt;
const viewPath = path.join(settings.root, view);
// 如果有緩存直接使用緩存後的模板解析得到的函數進行渲染
if (settings.cache && cache[viewPath]) {
return cache[viewPath].call(options.scope, options);
}
// 沒有緩存首次渲染調用 ejs.compile 進行編譯
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 得到的模板解析函數緩存起來
if (settings.cache) {
cache[viewPath] = fn;
}
return fn.call(options.scope, options);
}
顯然，koa-ejs 模板的模板緩存是完全自己實現的，並沒有在調用 ejs.compile 方法時傳入的 option 參數內將用戶設置的 cache 參數傳遞過去而使用 ejs 模塊提供的 cache 能力。但是偏偏項目在模板內又直接使用了 ejs 模塊注入的 include 方法進行模板間的調用，產生的結果就是隻緩存了主模板，而主模板使用 include 調用別的模板還是會重新進行編譯解析，進而造成壓測下還是存在大量重複的模板編譯動作導致 QPS 升不上去。
再次找到了問題的根源，為了驗證是否是 koa-ejs 模塊本身的 bug，我們在項目中將其渲染邏輯稍作更改：
const fn = ejs.compile(tpl, {
filename: viewPath,
_with: settings._with,
compileDebug: settings.debug && settings.compileDebug,
debug: settings.debug,
delimiter: settings.delimiter,
// 將用戶設置的 cache 參數傳遞給 ejs 而使用到其提供的緩存能力
cache: settings.cache
});
然後打包後進行壓測，此時單機 QPS 從 600 提升至 4000 左右，基本達到了上線前的性能預期，為了確認壓測下是否還有模板的編譯動作，我們繼續在 Node.js 性能平臺 上抓取壓測期間 3 分鐘的 CPU Profile：
可以看到上述對 koa-ejs 模板進行優化後，ejs.compile 確實消失了，而壓測期間不再有大量重複且耗費 CPU 的編譯動作後，應用整體的性能比最開始有了 20 倍左右的提升。文中 koa-ejs 模塊緩存問題已經在 4.1.2 版本（包含）之後被修復了，詳情可以見 cache include file，如果大家使用的 koa-ejs 版本 >= 4.1.2 就可以放心使用。
結尾
CPU Profile 本質上以可讀的方式反映給開發者運行時的 JavaScript 代碼執行頻繁程度，除了在線上進程出現負載很高時能夠用來定位問題代碼之外，它在我們上線前進行性能壓測和對應的性能調優時也能提供巨大的幫助。這裡需要注意的是：僅當進程 CPU 負載非常高的時候去抓取得到的 CPU Profile 才能真正反饋給我們問題所在。
在這個源自真實生產的案例中，我們也可以看到，正確和不正確地去使用 Node.js 開發應用其前後運行效率能達到二十倍的差距，Node.js 作為一門服務端技術棧發展至今日，其本身能夠提供的性能是毋庸置疑的，絕大部分情況下執行效率不佳是由我們自身的業務代碼或者三方庫本身的 Bug 引起的，Node.js 性能平臺 則可以幫助我們以比較方便的方式找出這些 Bug。
閱讀更多 阿里云云棲社區 的文章
