13

Situation:

I have a Node.js api that is called many times a second on a website. I am using console.time('RESPONSE TIME') and console.timeEnd('RESPONSE TIME') to measure how long the api is taking to respond to the client on to each request. Inside of the api, I am using a Promise.all() to aggregate responses from 4 different api's and then return a final response based on what the 4 apis returned.

Issue:

Everything works as expected except for an occasional warning logged Warning: No such label 'RESPONSE TIME' for console.timeEnd(). Why is this and how do I properly avoid this?

I speculate that it's because Node is asynchronous and while one request may still be waiting for it's 4 api's to respond, another request will have finished and hit the console.timeEnd() ending both timers since they share the same name. But I can't find an answer anywhere.

Ryan Walker
  • 715
  • 2
  • 10
  • 23
  • can't you just log `Date.now() - msStart` instead of using the console timing feature? that way, you don't have to worry about order of operations or rush conditions. – dandavis May 21 '19 at 19:09
  • @dandavis I thought about that. It's a solution but ideally I'd like to use `console.time()` since it's cleaner and that's what it's made for. Every ms counts so I'd rather avoid using things like the `Date` object – Ryan Walker May 21 '19 at 21:04
  • Even I am thinking about the explanation you are giving but would like to know if that's the exact reason? – Saras Arya Jan 06 '20 at 15:14
  • @SarasArya In regards to the original question? I still haven't found the answer. – Ryan Walker Jan 06 '20 at 21:40

1 Answers1

15

Your speculation is correct, you should have a unique label name for every api call. Assuming every request has a unique identifier stored in req.id you can use the following:

console.time(`RESPONSE TIME request ${req.id}`)
// await api call
console.timeEnd(`RESPONSE TIME request ${req.id}`)
Rayee Roded
  • 2,440
  • 1
  • 20
  • 21