Node.js 應用程式效能分析
對 Node.js 應用程式進行效能分析（Profiling）涉及在應用程式執行時測量其效能，分析 CPU、記憶體和其他執行時指標。這有助於識別可能影響應用程式效率、響應能力和可擴充套件性的瓶頸、高 CPU 使用率、記憶體洩漏或緩慢的函式呼叫。
雖然有許多第三方工具可用於分析 Node.js 應用程式，但在許多情況下，最簡單的選擇是使用 Node.js 的內建分析器。內建分析器使用 V8 內部的分析器，它在程式執行期間定期對堆疊進行取樣。它將這些樣本的結果以及重要的最佳化事件（如 JIT 編譯）記錄為一系列的 tick。
code-creation,LazyCompile,0,0x2d5000a337a0,396,"bp native array.js:1153:16",0x289f644df68,~
code-creation,LazyCompile,0,0x2d5000a33940,716,"hasOwnProperty native v8natives.js:198:30",0x289f64438d0,~
code-creation,LazyCompile,0,0x2d5000a33c20,284,"ToName native runtime.js:549:16",0x289f643bb28,~
code-creation,Stub,2,0x2d5000a33d40,182,"DoubleToIStub"
code-creation,Stub,2,0x2d5000a33e00,507,"NumberToStringStub"
過去，您需要 V8 原始碼才能解釋這些 tick。幸運的是，自 Node.js 4.4.0 以來，引入了一些工具，這些工具有助於使用這些資訊，而無需單獨從原始碼構建 V8。讓我們看看內建分析器如何幫助我們深入瞭解應用程式的效能。
為了說明 tick 分析器的使用，我們將使用一個簡單的 Express 應用程式。我們的應用程式將有兩個處理程式，一個用於向我們的系統新增新使用者
app.get('/newUser', (, ) => {
let = .query.username || '';
const = .query.password || '';
= .replace(/[^a-zA-Z0-9]/g, '');
if (! || ! || users[]) {
return .sendStatus(400);
}
const = .randomBytes(128).toString('base64');
const = .pbkdf2Sync(, , 10000, 512, 'sha512');
users[] = { , };
.sendStatus(200);
});
另一個用於驗證使用者身份驗證嘗試
app.get('/auth', (, ) => {
let = .query.username || '';
const = .query.password || '';
= .replace(/[^a-zA-Z0-9]/g, '');
if (! || ! || !users[]) {
return .sendStatus(400);
}
const { , } = users[];
const = .pbkdf2Sync(, , 10000, 512, 'sha512');
if (.timingSafeEqual(, )) {
.sendStatus(200);
} else {
.sendStatus(401);
}
});
請注意，這些並不是在您的 Node.js 應用程式中進行使用者身份驗證的推薦處理程式，它們純粹用於說明目的。通常，您不應該嘗試自己設計加密認證機制。使用現有的、經過驗證的身份驗證解決方案要好得多。
現在假設我們已經部署了我們的應用程式，並且使用者抱怨請求延遲很高。我們可以輕鬆地使用內建分析器執行該應用程式
NODE_ENV=production node --prof app.js
並使用 ab (ApacheBench) 對伺服器施加一些負載
curl -X GET "https://:8080/newUser?username=matt&password=password"
ab -k -c 20 -n 250 "https://:8080/auth?username=matt&password=password"
並得到 ab 的輸出
Concurrency Level: 20
Time taken for tests: 46.932 seconds
Complete requests: 250
Failed requests: 0
Keep-Alive requests: 250
Total transferred: 50250 bytes
HTML transferred: 500 bytes
Requests per second: 5.33 [#/sec] (mean)
Time per request: 3754.556 [ms] (mean)
Time per request: 187.728 [ms] (mean, across all concurrent requests)
Transfer rate: 1.05 [Kbytes/sec] received
...
Percentage of the requests served within a certain time (ms)
50% 3755
66% 3804
75% 3818
80% 3825
90% 3845
95% 3858
98% 3874
99% 3875
100% 4225 (longest request)
從這個輸出中，我們看到我們每秒只能處理大約 5 個請求，並且平均請求往返時間接近 4 秒。在實際例子中，我們可能代表使用者請求在許多函式中做了大量工作，但即使在我們簡單的例子中，時間也可能在編譯正則表示式、生成隨機鹽、從使用者密碼生成唯一雜湊，或者在 Express 框架本身內部丟失。
由於我們使用了 --prof 選項來執行應用程式，因此在您本地執行應用程式的同一目錄中生成了一個 tick 檔案。它的格式應該是 isolate-0xnnnnnnnnnnnn-v8.log（其中 n 是一個數字）。
為了理解這個檔案，我們需要使用與 Node.js 二進位制檔案捆綁在一起的 tick 處理器。要執行該處理器，請使用 --prof-process 標誌
node --prof-process isolate-0xnnnnnnnnnnnn-v8.log > processed.txt
在您喜歡的文字編輯器中開啟 processed.txt，您會看到幾種不同型別的資訊。該檔案按部分劃分，每個部分又按語言劃分。首先，我們檢視摘要部分，看到：
[Summary]:
ticks total nonlib name
79 0.2% 0.2% JavaScript
36703 97.2% 99.2% C++
7 0.0% 0.0% GC
767 2.0% Shared libraries
215 0.6% Unaccounted
這告訴我們，所有收集到的樣本中有 97% 發生在 C++ 程式碼中，並且在檢視處理後輸出的其他部分時，我們應該最關注在 C++ 中完成的工作（而不是 JavaScript）。考慮到這一點，我們接下來找到 [C++] 部分，其中包含有關哪些 C++ 函式佔用最多 CPU 時間的資訊，並看到：
[C++]:
ticks total nonlib name
19557 51.8% 52.9% node::crypto::PBKDF2(v8::FunctionCallbackInfo<v8::Value> const&)
4510 11.9% 12.2% _sha1_block_data_order
3165 8.4% 8.6% _malloc_zone_malloc
我們看到前 3 個條目佔了程式所用 CPU 時間的 72.1%。從這個輸出中，我們立即看到至少 51.8% 的 CPU 時間被一個名為 PBKDF2 的函式佔用，這對應於我們從使用者密碼生成雜湊的過程。然而，下面兩個條目如何影響我們的應用程式可能並不立即明顯（或者即使明顯，我們為了舉例也會假裝不明顯）。為了更好地理解這些函式之間的關係，我們接下來將檢視 [Bottom up (heavy) profile] 部分，該部分提供了有關每個函式主要呼叫者的資訊。檢查該部分，我們發現：
ticks parent name
19557 51.8% node::crypto::PBKDF2(v8::FunctionCallbackInfo<v8::Value> const&)
19557 100.0% v8::internal::Builtins::~Builtins()
19557 100.0% LazyCompile: ~pbkdf2 crypto.js:557:16
4510 11.9% _sha1_block_data_order
4510 100.0% LazyCompile: *pbkdf2 crypto.js:557:16
4510 100.0% LazyCompile: *exports.pbkdf2Sync crypto.js:552:30
3165 8.4% _malloc_zone_malloc
3161 99.9% LazyCompile: *pbkdf2 crypto.js:557:16
3161 100.0% LazyCompile: *exports.pbkdf2Sync crypto.js:552:30
解析這一部分比上面的原始 tick 計數需要更多的工作。在上面的每個“呼叫堆疊”中，父列中的百分比告訴您當前行函式被上一行函式呼叫的樣本百分比。例如，在上面中間的 _sha1_block_data_order 的“呼叫堆疊”中，我們看到 _sha1_block_data_order 出現在 11.9% 的樣本中，這我們從上面的原始計數中已經知道。然而，在這裡，我們還可以看出它總是被 Node.js 加密模組中的 pbkdf2 函式呼叫。我們看到，同樣地，_malloc_zone_malloc 幾乎完全被同一個 pbkdf2 函式呼叫。因此，利用這個檢視中的資訊，我們可以判斷出，我們從使用者密碼進行的雜湊計算不僅佔用了上面的 51.8%，而且還佔用了排名前 3 位取樣最多函式中的所有 CPU 時間，因為對 _sha1_block_data_order 和 _malloc_zone_malloc 的呼叫都是代表 pbkdf2 函式進行的。
此時，很明顯，基於密碼的雜湊生成應該是我們最佳化的目標。值得慶幸的是，您已經完全內化了非同步程式設計的好處，並且您意識到從使用者密碼生成雜湊的工作是以同步方式完成的，從而阻塞了事件迴圈。這使我們在計算雜湊時無法處理其他傳入的請求。
為了解決這個問題，您對上述處理程式做了一個小小的修改，以使用 pbkdf2 函式的非同步版本
app.get('/auth', (, ) => {
let = .query.username || '';
const = .query.password || '';
= .replace(/[^a-zA-Z0-9]/g, '');
if (! || ! || !users[]) {
return .sendStatus(400);
}
.pbkdf2(
,
users[].salt,
10000,
512,
'sha512',
(, ) => {
if (users[].hash.toString() === .toString()) {
.sendStatus(200);
} else {
.sendStatus(401);
}
}
);
});
使用非同步版本的應用重新執行上面的 ab 基準測試，結果如下
Concurrency Level: 20
Time taken for tests: 12.846 seconds
Complete requests: 250
Failed requests: 0
Keep-Alive requests: 250
Total transferred: 50250 bytes
HTML transferred: 500 bytes
Requests per second: 19.46 [#/sec] (mean)
Time per request: 1027.689 [ms] (mean)
Time per request: 51.384 [ms] (mean, across all concurrent requests)
Transfer rate: 3.82 [Kbytes/sec] received
...
Percentage of the requests served within a certain time (ms)
50% 1018
66% 1035
75% 1041
80% 1043
90% 1049
95% 1063
98% 1070
99% 1071
100% 1079 (longest request)
太棒了！您的應用現在每秒處理大約 20 個請求，大約是同步雜湊生成時的 4 倍。此外，平均延遲從之前的 4 秒下降到略高於 1 秒。
希望透過對這個（誠然是刻意設計的）例子的效能調查，您已經瞭解了 V8 tick 處理器如何幫助您更好地理解 Node.js 應用程式的效能。
您可能還會發現如何建立火焰圖很有幫助。