javascript - node.js 计时 : process. hrtime() vs new Date().getTime()？

Question

我正在尝试解决从 node.js 到远程 http api 的请求耗时过长的问题。首先，我决定向我的 Node 应用程序添加计时:

'use strict';

let logger = require('./logger');
let request = require('request');

module.exports = function(uri, done) {
  // set full url.
  let options = {
    uri: `http://example.org/${uri}`,
    timeout: 60000,
    json: true,
    gzip: true,
    encoding: null
  };
  const startDate = new Date().getTime();
  const start = process.hrtime();

  request(options, function(error, response, body) {
    const endDate = new Date().getTime();
    const end = process.hrtime(start);
    const durationDate = endDate - startDate;
    const duration = end[1] / 1000000;
    const diff = Math.abs(Math.round(durationDate - duration));
    logger.debug(`${uri} hrtime: ${duration} ms, date: ${durationDate} ms, diff: ${diff}`);
    if (!error && response.statusCode === 200) {
      done(error, response, body, body);
    } else {
      done(error, response, body);
    }
  });
};

这是我得到的输出:

<....>
2016-06-29T10:26:59.230Z /account hrtime: 41.567354 ms, date: 41 ms, diff: 1
2016-06-29T10:27:06.369Z /account hrtime: 42.052154 ms, date: 42 ms, diff: 0
2016-06-29T10:27:13.368Z /account hrtime: 51.582807 ms, date: 5052 ms, diff: 5000
2016-06-29T10:27:14.971Z /account hrtime: 40.705936 ms, date: 40 ms, diff: 1
2016-06-29T10:27:22.490Z /account hrtime: 45.953398 ms, date: 5046 ms, diff: 5000
2016-06-29T10:27:29.669Z /account hrtime: 42.504256 ms, date: 5043 ms, diff: 5000
2016-06-29T10:27:31.622Z /account hrtime: 39.405575 ms, date: 39 ms, diff: 0
<....>
2016-06-29T10:27:45.135Z /account hrtime: 40.594642 ms, date: 41 ms, diff: 0
2016-06-29T10:27:52.682Z /account hrtime: 40.290881 ms, date: 40 ms, diff: 0
2016-06-29T10:28:05.115Z /account hrtime: 50.81821 ms, date: 10050 ms, diff: 9999
2016-06-29T10:28:13.555Z /account hrtime: 52.061123 ms, date: 52 ms, diff: 0
<.....>
2016-06-29T10:29:45.052Z /account hrtime: 44.252486 ms, date: 44 ms, diff: 0
2016-06-29T10:29:46.829Z /account hrtime: 39.652963 ms, date: 40 ms, diff: 0
2016-06-29T10:29:49.101Z /account hrtime: 40.841915 ms, date: 41 ms, diff: 0
2016-06-29T10:29:55.097Z /account hrtime: 44.161802 ms, date: 5044 ms, diff: 5000
2016-06-29T10:30:01.784Z /account hrtime: 47.732807 ms, date: 47 ms, diff: 1
2016-06-29T10:30:04.309Z /account hrtime: 40.151299 ms, date: 40 ms, diff: 0
2016-06-29T10:30:06.926Z /account hrtime: 39.933368 ms, date: 40 ms, diff: 0
2016-06-29T10:30:14.440Z /account hrtime: 53.610396 ms, date: 5054 ms, diff: 5000

所以有时候 hrtime 和 getTime() 之间的区别是巨大的。
这不仅仅是一些误报，而是实际行为 - 如果查看远程 http 服务器日志，我发现所有请求实际上都花费了 hrtime 报告的时间，而 getTime() 报告的时间实际上是 node.js 应用程序的时间回应。所以似乎 node.js 应用程序本身存在某种延迟。为什么会发生这种情况？

Node v4.4.6

Answer 1

使用以下内容:

const start = process.hrtime();
// ... processing
const end = process.hrtime(start);
const duration = (end[0]*1000) + (end[1] / 1000000);

您将获得所需的结果。hrtime 返回一个包含两个值的数组 - 第一个是秒，所以将它乘以 1000 得到毫秒，第二个值是纳秒，所以除以 1 后跟 6 个零，即 1000000，将它们相加得到结果。