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 应用程序的性能。
您可能还会发现如何创建火焰图很有帮助。