轻松分析 Node.JS 应用程序
有许多第三方工具可用于分析 Node.JS 应用程序, 但在许多情况下, 最简单的选择是使用 Node.JS 内置的分析器, 内置的分析器使用 V8 内部的分析器 https://developers.google.com/v8/profiler_example , 在程序执行期间定期对堆栈进行采样, 它将这些样本的结果以及重要的优化事件 (如 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', (req, res) => {
- let username = req.query.username || '';
- const password = req.query.password || '';
- username = username.replace(/[!@#$%^&*]/g, '');
- if (!username || !password || users.username) {
- return res.sendStatus(400);
- }
- const salt = crypto.randomBytes(128).toString('base64');
- const hash = crypto.pbkdf2Sync(password, salt, 10000, 512, 'sha512');
- users[username] = { salt, hash };
- res.sendStatus(200);
- });
另一个用于验证用户身份验证尝试:
- App.get('/auth', (req, res) => {
- let username = req.query.username || '';
- const password = req.query.password || '';
- username = username.replace(/[!@#$%^&*]/g, '');
- if (!username || !password || !users[username]) {
- return res.sendStatus(400);
- }
- const { salt, hash } = users[username];
- const encryptHash = crypto.pbkdf2Sync(password, salt, 10000, 512, 'sha512');
- if (crypto.timingSafeEqual(hash, encryptHash)) {
- res.sendStatus(200);
- } else {
- res.sendStatus(401);
- }
- });
请注意, 这些不是推荐的处理程序, 用于在 Node.JS 应用程序中对用户进行身份验证, 仅用于说明目的, 你通常不应该尝试设计自己的加密身份验证机制, 使用现有的, 经过验证的身份验证解决方案要好得多.
现在假设我们已经部署了我们的应用程序, 用户抱怨请求的延迟很高, 我们可以使用内置的分析器轻松运行应用程序:
NODE_ENV=production node --prof App.JS
并使用 ab(ApacheBench)在服务器上加点负荷:
- curl -X GET "http://localhost:8080/newUser?username=matt&password=password"
- ab -k -c 20 -n 250 "http://localhost: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 秒. 在实际示例中, 我们可以代表用户请求在许多函数中执行大量工作, 但即使在我们的简单示例中也是如此, 编译正则表达式, 生成随机 salt, 从用户密码生成唯一哈希, 或者在 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
来源: https://segmentfault.com/a/1190000016976744