我有一段JavaScript代码,我正在使用node.js解释器执行。

for(var i = 1; i < LIMIT; i++) {
  var user = {
    id: i,
    name: "MongoUser [" + i + "]"
  };
  db.users.save(user, function(err, saved) {
    if(err || !saved) {
      console.log("Error");
    } else {
      console.log("Saved");
    }
  });
}

如何测量这些数据库插入操作所花费的时间?我可以在这段代码之后和之前计算日期值的差异,但这将是不正确的,因为代码的异步性质。


当前回答

你也可以试试exectimer。它会给你这样的反馈:

var t = require("exectimer");

var myFunction() {
   var tick = new t.tick("myFunction");
   tick.start();
   // do some processing and end this tick
   tick.stop();
}

// Display the results
console.log(t.timers.myFunction.duration()); // total duration of all ticks
console.log(t.timers.myFunction.min()); // minimal tick duration
console.log(t.timers.myFunction.max()); // maximal tick duration
console.log(t.timers.myFunction.mean()); // mean tick duration
console.log(t.timers.myFunction.median()); // median tick duration

现在有一种更简单的方法来使用exectime。你的代码可以这样包装:

var t = require('exectimer'),
Tick = t.Tick;

for(var i = 1; i < LIMIT; i++){
    Tick.wrap(function saveUsers(done) {
        db.users.save({id : i, name : "MongoUser [" + i + "]"}, function(err, saved) {
            if( err || !saved ) console.log("Error");
            else console.log("Saved");
            done();
        });
    });
}

// Display the results
console.log(t.timers.myFunction.duration()); // total duration of all ticks
console.log(t.timers.saveUsers.min()); // minimal tick duration
console.log(t.timers.saveUsers.max()); // maximal tick duration
console.log(t.timers.saveUsers.mean()); // mean tick duration
console.log(t.timers.saveUsers.median()); // median tick duration

其他回答

对于任何想要获得时间流逝值而不是控制台输出的人:

使用process.hrtime()作为@D。Deriso建议,以下是我更简单的方法:

function functionToBeMeasured() {
    var startTime = process.hrtime();
    // do some task...
    // ......
    var elapsedSeconds = parseHrtimeToSeconds(process.hrtime(startTime));
    console.log('It takes ' + elapsedSeconds + 'seconds');
}

function parseHrtimeToSeconds(hrtime) {
    var seconds = (hrtime[0] + (hrtime[1] / 1e9)).toFixed(3);
    return seconds;
}

调用console.time('label')将以毫秒为单位记录当前时间,然后调用console.timeEnd('label')将显示从该点开始的持续时间。

以毫秒为单位的时间会自动打印在标签旁边,所以你不需要单独调用console.log来打印标签:

console.time('test');
//some code
console.timeEnd('test'); //Prints something like that-> test: 11374.004ms

有关更多信息,请参阅console.time上的Mozilla开发者文档。

我需要它是累积的,用来测量不同的东西。 构建这些函数:

function startMeasuring(key) {
  measureTimers[key] = process.hrtime();
}

function stopMeasuring(key) {
  if (!measures[key]) {
    measures[key] = 0;
  }

  let hrtime = process.hrtime(measureTimers[key]);
  measures[key] += hrtime[0] + hrtime[1] / 1e9;
  measureTimers[key] = null;
}

用法:

startMeasuring("first Promise");
startMeasuring("first and second Promises");
await new Promise((resolve) => {
  setTimeout(resolve, 1400);
});
stopMeasuring("first Promise");
stopMeasuring("first and second Promises");

startMeasuring("first and second Promises");
await new Promise((resolve) => {
  setTimeout(resolve, 600);
});
stopMeasuring("first and second Promises");

console.log("Measure Results", measures); 
/*
Measusre Results {
  setting: 0.00002375,
  'first Promise': 1.409392916,
  'first and second Promise': 2.015160376
}
*/
var start = +new Date();
var counter = 0;
for(var i = 1; i < LIMIT; i++){
    ++counter;
    db.users.save({id : i, name : "MongoUser [" + i + "]"}, function(err, saved) {
          if( err || !saved ) console.log("Error");
          else console.log("Saved");
          if (--counter === 0) 
          {
              var end = +new Date();
              console.log("all users saved in " + (end-start) + " milliseconds");
          }
    });
}

可以使用包装器函数轻松地报告任何现有函数的执行时间。

包装器用于扩展现有函数,以便在现有函数执行之前和之后执行某些操作——这是一种组合逻辑的方便方法。

下面是一个使用withDurationReporting包装器的例子:

// without duration reporting
const doSomethingThatMayTakeAWhile = async (someArg: string, anotherArg: number) => { 
  /** your logic goes here */
}

// with duration reporting
const doSomethingThatMayTakeAWhileWithReporting = withDurationReporting(
  'doSomethingThatMayTakeAWhile', 
  doSomethingThatMayTakeAWhile
);
// note: you can define the function with duration reporting directly, too
const doSomethingThatMayTakeAWhile = withDurationReporting(
  'doSomethingThatMayTakeAWhile', 
  async (someArg: string, anotherArg: number) => { 
    /** your logic goes here */
  }
)

这是包装器本身:

import { hrtime } from 'process';

const roundToHundredths = (num: number) => Math.round(num * 100) / 100; // https://stackoverflow.com/a/14968691/3068233

/**
 * a wrapper which reports how long it took to execute a function, after the function completes
 */
export const withDurationReporting = <R extends any, T extends (...args: any[]) => Promise<R>>(
  title: string,
  logic: T,
  options: {
    reportingThresholdSeconds: number;
    logMethod: (message: string, metadata?: Record<string, any>) => void;
  } = {
    reportingThresholdSeconds: 1, // report on anything that takes more than 1 second, by default
    logMethod: console.log, // log with `console.log` by default
  }, 
) => {
  return (async (...args: Parameters<T>): Promise<R> => {
    const startTimeInNanoseconds = hrtime.bigint();
    const result = await logic(...args);
    const endTimeInNanoseconds = hrtime.bigint();
    const durationInNanoseconds = endTimeInNanoseconds - startTimeInNanoseconds;
    const durationInSeconds = roundToHundredths(Number(durationInNanoseconds) / 1e9); // https://stackoverflow.com/a/53970656/3068233
    if (durationInSeconds >= options.reportingThresholdSeconds)
      options.logMethod(`${title} took ${durationInSeconds} seconds to execute`, { title, durationInSeconds });
    return result;
  }) as T;
};