Node.js 指南（轻松分析Node.js应用程序）

轻松分析Node.js应用程序有许多第三方工具可用于分析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’, (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: 20Time taken for tests: 46.932 secondsComplete requests: 250Failed requests: 0Keep-Alive requests: 250Total transferred: 50250 bytesHTML transferred: 500 bytesRequests 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我们看到前三个条目占该程序占用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计数更多的工作，在上面的每个“调用堆栈”中，parent列中的百分比告诉你当前行中的函数调用上面行中的函数的样本百分比。例如，在sha1block_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’, (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); } crypto.pbkdf2(password, users[username].salt, 10000, 512, (err, hash) => { if (users[username].hash.toString() === hash.toString()) { res.sendStatus(200); } else { res.sendStatus(401); } });});以上ab基准测试与你的应用程序的异步版本的一个新的运行结果：Concurrency Level: 20Time taken for tests: 12.846 secondsComplete requests: 250Failed requests: 0Keep-Alive requests: 250Total transferred: 50250 bytesHTML transferred: 500 bytesRequests 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应用程序的性能。上一篇：入门指南下一篇：Docker化Node.js Web应用程序