Как измерить время выполнения кода JavaScript с помощью обратных вызовов

У меня есть фрагмент кода JavaScript, который я выполняю с помощью интерпретатора node.js.

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

Я хочу знать, как измерить время, затраченное на эти операции вставки БД. Я мог бы вычислить разницу значений Date после и до этого фрагмента кода, но это было бы неправильно из-за асинхронного характера кода.

 BFil16 мая 2012 г., 12:59
Просто прочитайте время начала до вызова db, и время окончания внутри обратного вызова.
 Stormshadow16 мая 2012 г., 13:13
Существует вероятность того, что время, когда DB завершает вставку, и время выполнения обратного вызова не совпадают, и это может привести к ошибке в измерении?
 brillout01 мар. 2017 г., 14:10
я написалtimerlog который похож наconsole.time() но с дополнительными функциями;github.com/brillout/timerlog
 D.Deriso22 июл. 2014 г., 04:34
Эй, @Stormshadow, если ты не возражаешь, нажми кнопку "Принять", если мы ответили на твой вопрос?
 BFil16 мая 2012 г., 13:32
Нет, вы не должны беспокоиться об этом, если код библиотеки db хорошо спроектирован и не обрабатывает никакие другие операции перед запуском обратного вызова, вы должны получить хорошую меру. Вы также можете профилировать вставку, поместив метки времени в код библиотеки, где фактически выполняется вставка, вместо вашей собственной, но, опять же, я не буду беспокоиться об этом

Ответы на вопрос(12)

Вы также можете попробовать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

[править] Теперь есть еще более простой способ использовать exectimer, потому что теперь он может переносить код, который будет измеряться. Ваш код может быть упакован так:

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 (); .

Итак, я положил это в верхней части моего приложения.

var start = process.hrtime();

var elapsed_time = function(note){
    var precision = 3; // 3 decimal places
    var elapsed = process.hrtime(start)[1] / 1000000; // divide by a million to get nano to milli
    console.log(process.hrtime(start)[0] + " s, " + elapsed.toFixed(precision) + " ms - " + note); // print message + time
    start = process.hrtime(); // reset the timer
}

Затем я использую его, чтобы узнать, сколько времени занимают функции. Вот основной пример, который печатает содержимое текстового файла с именем "output.txt":

var debug = true;
http.createServer(function(request, response) {

    if(debug) console.log("----------------------------------");
    if(debug) elapsed_time("recieved request");

    var send_html = function(err, contents) {
        if(debug) elapsed_time("start send_html()");
        response.writeHead(200, {'Content-Type': 'text/html' } );
        response.end(contents);
        if(debug) elapsed_time("end send_html()");
    }

    if(debug) elapsed_time("start readFile()");
    fs.readFile('output.txt', send_html);
    if(debug) elapsed_time("end readFile()");

}).listen(8080);

Вот быстрый тест, который вы можете запустить в терминале (оболочка BASH):

for i in {1..100}; do echo $i; curl http://localhost:8080/; done
 31 мар. 2015 г., 19:29
это что превосходит console.time решение в любом случае?
 13 янв. 2017 г., 17:00
Этот работает для меня, так как я хотел вызвать таймер несколько раз
 06 февр. 2019 г., 20:09
Зачем звонишьprocess.hrtime(start) дважды? Есть ли для этого особая причина?
 01 июл. 2015 г., 08:17
Да, это намного точнее, и вы можете сохранить результат в переменной

Старый вопрос, но для простого API и облегченного решения; ты можешь использоватьperfy который использует высокое разрешение в режиме реального времени (process.hrtime) внутренне.

var perfy = require('perfy');

function end(label) {
    return function (err, saved) {
        console.log(err ? 'Error' : 'Saved'); 
        console.log( perfy.end(label).time ); // <——— result: seconds.milliseconds
    };
}

for (var i = 1; i < LIMIT; i++) {
    var label = 'db-save-' + i;
    perfy.start(label); // <——— start and mark time
    db.users.save({ id: i, name: 'MongoUser [' + i + ']' }, end(label));
}

Обратите внимание, что каждый разperfy.end(label) называется, этот экземпляр автоматически уничтожается.

Раскрытие: Написал этот модуль, вдохновленныйОтвет D.Deriso, ДокументыВот.

Вы могли бы датьBenchmark.js попытка Он поддерживает множество платформ, в том числе node.js.

 23 июн. 2016 г., 00:02
Было бы хорошо, если бы вы могли добавить пример того, как использовать benchmark.js для этого варианта использования.

Я бы порекомендовал попробоватьNodeTime что кажется подходящим для того, что вы пытаетесь сделать.

 19 авг. 2016 г., 16:15
Ну, этот ответ был дан четыре с половиной года назад, и я думаю, что NodeTime больше нет. Мир Node.JS действительно движется очень быстро - интересно, что принятый ответ был дан через 12 месяцев после того, как вопрос был задан!
 18 авг. 2016 г., 17:06
Почему бы не предоставить пример кода тоже, это было бы полезно! :-)
Решение Вопроса

Используйте Node.jsconsole.time() а такжеconsole.timeEnd():

var i;
console.time("dbsave");

for(i = 1; i < LIMIT; i++){
    db.users.save({id : i, name : "MongoUser [" + i + "]"}, end);
}

end = function(err, saved) {
    console.log(( err || !saved )?"Error":"Saved");
    if(--i === 1){console.timeEnd("dbsave");}
};
 23 сент. 2013 г., 22:28
Чистое и встроенное решение для узла.
 25 сент. 2014 г., 23:16
@gogaman это хороший момент, так как вы не можете захватить вывод из console.timeEnd (). Возможно, было бы полезно направить вывод в файл и использовать его оттуда?
 20 февр. 2015 г., 15:43
Так в чем же разница между console.time () и process.hrtime () в ответе ниже?
 10 нояб. 2015 г., 14:13
Стоит добавить примечание, что время выполнения затем распечатывается, просто чтобы новые пользователи сейчас.
 06 авг. 2014 г., 20:42
& gt; я хочу знать, как измерить время, затраченное на эти операции вставки в БД. --- console.timeEnd (& quot; dbsave & quot;) просто выводит данные для согласования времени. Вы не можете использовать это дальше и будете менее гибкими. Если вам нужно фактическое значение времени, как в исходном вопросе, вы не можете использовать console.timeEnd (& quot; dbsave & quot;)

И еще один вариант заключается в использованииэкспресс-отладка инструмент:

express-debug is a development tool for express. It's simple middleware that injects useful debugging output into your html, in a non-obstructive way.

Удобно предлагает профилирующую панель:

total req processing time. middleware, param, and route timings.

Также. Чтобы добавить к ответам выше, вы можете проверитьэтот ответ включить любой профилирующий код только для среды разработки.

Вызовconsole.time('label') запишет текущее время в миллисекундах, а затем позвонитconsole.timeEnd('label') будет отображать продолжительность с этой точки.

Время в миллисекундах будет автоматически напечатано рядом с меткой, поэтому вам не нужно делать отдельный вызов console.log для печати метки:

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

Для получения дополнительной информации см.Документы для разработчиков на Mozillaconsole.time.

 17 мая 2018 г., 11:18
это сработало отлично
 25 нояб. 2018 г., 23:48
удивительный простой ответ, который работает в JS и Node!
 06 июл. 2018 г., 16:21
Принятый ответ был изменен после моего ответа, чтобы использовать мой код
 06 июл. 2018 г., 01:11
Что это добавляет кthe accepted answer?

For anyone want to get time elapsed value instead of console output :

использование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;
}

Удивило, что никто не упомянул новые встроенные библиотеки:

Доступно в узле & gt; = 8.5 и должно быть в современных браузерах

https://developer.mozilla.org/en-US/docs/Web/API/Performance

https://nodejs.org/docs/latest-v8.x/api/perf_hooks.html#

Node 8.5 ~ 9.x (Firefox, Chrome)

// const { performance } = require('perf_hooks'); // enable for node
const delay = time => new Promise(res=>setTimeout(res,time))
async function doSomeLongRunningProcess(){
  await delay(1000);
}
performance.mark('A');
(async ()=>{
  await doSomeLongRunningProcess();
  performance.mark('B');
  performance.measure('A to B', 'A', 'B');
  const measure = performance.getEntriesByName('A to B')[0];
  // firefox appears to only show second precision.
  console.log(measure.duration);
  performance.clearMeasures(); // apparently you should remove entries...
  // Prints the number of milliseconds between Mark 'A' and Mark 'B'
})();

https://repl.it/@CodyGeisler/NodeJsPerformanceHooks

Node 10.x

https://nodejs.org/docs/latest-v10.x/api/perf_hooks.html

const { PerformanceObserver, performance } = require('perf_hooks');
const delay = time => new Promise(res => setTimeout(res, time))
async function doSomeLongRunningProcess() {
    await delay(1000);
}
const obs = new PerformanceObserver((items) => {
    console.log('PerformanceObserver A to B',items.getEntries()[0].duration);
    performance.clearMarks();
});
obs.observe({ entryTypes: ['measure'] });

performance.mark('A');

(async function main(){
    try{
        await performance.timerify(doSomeLongRunningProcess)();
        performance.mark('B');
        performance.measure('A to B', 'A', 'B');
    }catch(e){
        console.log('main() error',e);
    }
})();
 30 июл. 2018 г., 08:33
Stability: 1 - Experimental может быть? :)nodejs.org/docs/latest-v8.x/api/…
 30 июл. 2018 г., 00:07
Я сделал пример, чтобы вы могли запустить его онлайн. Это Узел 9.7.1. Если это не работает в v10.4.1, то мне интересно, что может измениться!
 03 авг. 2018 г., 19:38
Да, это точно изменилось. В версии 10 появился новый наблюдатель, документы наnodejs.org/docs/latest-v10.x/api/documentation.html, Я обновлюсь, когда получу шанс!
 29 июл. 2018 г., 09:47
Дает мнеTypeError: performance.getEntriesByName is not a function в узле v10.4.1

У меня была такая же проблема при переходе с AWS на Azure

Для экспресса AWS, вы уже можете использовать, существующие time () и timeEnd ()

Для Azure используйте это: https://github.com/manoharreddyporeddy/my-nodejs-notes/blob/master/performance_timers_helper_nodejs_azure_aws.js

Эти time () и timeEnd () используют существующую функцию hrtime (), которая обеспечивает высокое разрешение в реальном времени.

Надеюсь это поможет.

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");
          }
    });
}
 20 янв. 2015 г., 06:57
Я часто используюvar start = process.hrtime(); ... var end = process.hrtime(start); чтобы получить высокое разрешение (если мне нужно ожидать точность менее миллисекунды)
 19 янв. 2015 г., 20:08
Мне пришлось искать синтаксис "+ новая дата ()" выяснить, что это значит. По комментариям на этот ответ (stackoverflow.com/a/221565/5114) не рекомендуется использовать эту форму из соображений производительности, а также для удобства чтения. Я предпочитаю что-то более многословное, чтобы оно было понятнее читателю. Также посмотрите этот ответ:stackoverflow.com/a/5036460/5114

Ваш ответ на вопрос