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:      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

咱們看到前三個條目佔該程序佔用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:      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應用程序的性能。

---

上一篇：入門指南

下一篇：Docker化Node.js Web應用程序