如何用回调测量JavaScript代码的执行时间?

我有一段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");
}
});
}

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

322293 次浏览
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");
}
});
}

有一种方法是专门为这个设计的。查看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 shell)中运行的快速测试:

for i in {1..100}; do echo $i; curl http://localhost:8080/; done

使用Node.js console.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");
}
};

调用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开发者文档

你也可以试试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

老问题,但一个简单的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的回答。文档在这里

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

使用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;
}

我从AWS转到Azure时也遇到了同样的问题

快递&aws,你已经可以使用,existing time()和timeEnd()

对于Azure,使用这个: https://github.com/manoharreddyporeddy/my-nodejs-notes/blob/master/performance_timers_helper_nodejs_azure_aws.js < / p >

这些time()和timeEnd()使用现有的hrtime()函数,提供高分辨率的实时时间。

希望这能有所帮助。

令人惊讶的是,还没有人提到图书馆的新建:

在Node >= 8.5中可用,并且应该在现代浏览器中

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

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

节点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);
// apparently you should clean up...
performance.clearMarks();
performance.clearMeasures();
// Prints the number of milliseconds between Mark 'A' and Mark 'B'
})();

< a href = " https://repl。它/ @CodyGeisler NodeJsPerformanceHooks noreferrer“rel = > https://repl.it/@CodyGeisler NodeJsPerformanceHooks < / >

节点12.倍

https://nodejs.org/docs/latest-v12.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);
// apparently you should clean up...
performance.clearMarks();
// performance.clearMeasures(); // Not a function in Node.js 12
});
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);
}
})();

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

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
}
*/

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

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

下面是一个使用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;
};

我为此设计了一个简单的方法,使用console.time () &console.timeEnd ():

测量函数定义
function measureRunningTime(func,...args){
const varToString = varObj => Object.keys(varObj)[0]
const displayName = func.name || varToString({ func })
console.time(displayName)
func(...args)
console.timeEnd(displayName)
}


要使用它,传递一个不带参数、带参数绑定或带参数作为以下参数的函数。

例子:

假设我想检查最简单的搜索算法SimpleSearch的运行时间:
度量函数定义(代码在这里)
const simpleSearch = (array = [1,2,3] ,item = 3) => {
for(let i = 0; i< array.length; i++){
if (array[i] === item) return i;
}
return -1
}


不带参数的实现
measureRunningTime(simpleSearch)
//Prints something like that-> simpleSearch: 0.04ms
使用.bind()参数实现
const array = [1,2,3]
const item = 3
measureRunningTime(simpleSearch.bind(null, array, item))
//Prints something like that-> bound simpleSearch: 0.04ms
不使用.bind()而带参数的实现
const array = [1,2,3]
const item = 3
measureRunningTime(simpleSearch, array, item)
//Prints something like that-> simpleSearch: 0.04ms
< p >→注意! !这个实现还远远不够完美——比如没有错误处理——但它可以用来检查简单算法的运行时间, 此外,我不是一个有经验的程序员,所以采取一切与盐粒🧂👌