calculate execution times of async function over multiple calls

Question

If the do work function was performing some operation, say, picking an item from queue and performing some operation. How would I get the execution times for doWork function over time. I want to find out how much time doWork takes to complete at an average.

Sample Code

function doWork () {
  return Promise.resolve({first: 'Tony', last: 'Starks'})
}

async function wrapper () {
  console.time('wrapper')
  const response = await doWork()
  console.timeEnd('wrapper')
  return response
}

Promise.all([
  wrapper(),
  wrapper(),
  wrapper()
]).then((result) => console.info(result))

Output

wrapper: 0.388ms
[ { first: 'Tony', last: 'Starks' },
  { first: 'Tony', last: 'Starks' },
  { first: 'Tony', last: 'Starks' } ]
(node:2749) Warning: No such label 'wrapper' for console.timeEnd()
(node:2749) Warning: No such label 'wrapper' for console.timeEnd()

Answer 1

If you're just trying to get your console.time() and console.end() calls to work around your async function, you can generate a unique label each time you call console.time() and console.end() so that the measurement will still work when there are multiple calls in flight at the same time (since each call will then be using its own label):

let wrapperCntr = 0;

async function wrapper () {
  let cnt = wrapperCntr++;
  console.time('wrapper' + cnt);
  const response = await doWork();
  console.timeEnd('wrapper' + cnt);
  return response;
}

Answer 2

If you're hard-set on testing them in parallel, I recommend this approach:

function doWork () {
  return Promise.resolve({ first: 'Tony', last: 'Stank' })
}

async function wrapper (index) {
  console.time(index)
  const response = await doWork()
  console.timeEnd(index)
  return response
}

Promise.all(
  Array(3) // some big number
    .fill(wrapper)
    .map((wrapper, index) => wrapper(index))
).then((results) => console.info(results))

However, JavaScript is single-threaded. You're initializing 3 asynchronous functions in the same tick. They end up competing for CPU time on each asynchronous callback, which as you observed, causes undue timing delays.

Compare the times for above and below; below will be an order of magnitude faster because they are initialized in series and do not compete for CPU time:

function doWork () {
  return Promise.resolve({ first: 'Tony', last: 'Stank' })
}

async function wrapper ({ index, responses }) {
  console.time(index)
  responses.push(await doWork())
  console.timeEnd(index)
  return { index: ++index, responses }
}

Array(3) // some big number
  .fill(wrapper)
  .reduce(
    (promise, wrapper) => promise.then(wrapper),
    Promise.resolve({ index: 0, responses: [] })
  )
  .then(({ responses: results }) => console.info(results))

Answer 3

Related Question

Why not use the built-in performance package, which is available in node and the browser by default.

The following will work for multiple calls too...

async function timePromise(promiseFunction) {
  try {
    const begin = performance.now();
    await promiseFunction();
    const end = performance.now();
    const timeTaken_ms = end - begin;
    return timeTaken_ms;
  } catch (error) {
    console.error(error);
  }
}