How to time a worker function?

Hi,

I thought I’d share this trick in the hope that someone might out do me and post a better trick. Or, equally good, point out where and why I am wrong in my calculations. :upside_down_face:

My goal is to time a worker function. First, I tried to update the Date.now() by calling fetch:

const start = Date.now();
runMyTestFunction();
fetch('https://cloudflare.com');//updates Date.now()
console.log(Date.now()-start);

But. This was very imprecise. As expected. So I have given up on Date.now() and fetch. (If someone can make a fairly good timer using Date.now(), please let me know!)

So. Second. I found another way I think is more precise. The idea is that each worker run only for 50ms before its killed. So. By running the function as many times as I can inside a single worker, I can estimate roughly how long it takes to run the function.

For example:

function functionToBeTested(){
  for (let i = 0; i < 1000000; i++) 
    Math.sqrt(i);
}

async function handleRequest(request) {
  for(let i = 0; i < 200; i++){
    functionToBeTested();
    console.log(i);
  }
  return new Response('hello sunshine');
}

addEventListener('fetch', e => e.respondWith(handleRequest(e.request)));

This runs 85 rounds +/-5 before its killed, lets say that all the surrounding stuff takes 7.5ms, which leaves 42.5ms for 85 rounds of functionToBeTested(), which leaves 0.5ms per functionToBeTested().

demo

similar discussion

Date and time in a worker doesn’t progress, it’s too avoid timing attacks. As you have noticed, async work does make time progress, which makes it possible to measure fetch requests and similar.

Hi Thomas :slightly_smiling_face:

not sure I quite understood. Are there other async work than fetch that update the Date.now()? And more reliably than fetch? I thought it was just http requests (and if i remember correctly KV calls which I assume function as http requests under the hood) that updated the Date.now() in a worker? It doesn’t have to be perfect, +/-1ms is good enough for me, but the duration of fetch to the same source varies far too much for me (for the sake of argument, lets say that the most reliable fetch calls fluctuate +/-10ms).

Seems like any promise the worker waits for, will progress the date/time.

1 Like

Att!! This post is wrong. Cloudflare’s setTimeout fooled me :wink: See the post below for an explanation how and why setTimeout updates Date.now() in a way that can make you believe your worker is faster than it actually is.

*** old erroneous post begins ***
Yes, it actually does! :smiley:

async function handleRequest(request) {
  console.log('a', Date.now());
  Promise.resolve().then(()=>console.log('b', Date.now()));
  await new Promise(r=> setTimeout(()=>r(), 2));
  console.log('c', Date.now());
  await new Promise(r=> setTimeout(()=>r(), 0));
  console.log('d', Date.now());
  return new Response('hello sunshine');
}

addEventListener('fetch', e => e.respondWith(handleRequest(e.request)));

demo

This prints:

a 1605084545726
b 1605084545726
c 1605084545728
d 1605084545728

Which illustrate that the calling a sleep(0) (await new Promise(r=> setTimeout(()=>r(), 0));) will actually update the Date.now() correctly. Nice:)

*** old erroneous post ends ***

Ps. added the test for Promise.resolve().then(...) async microtask to see if that one also update the Date.now(), but it didn’t. But setTimeout(...,0) did, and that is more than accurate enough for me.

1 Like

No, the above post that I wrote is wrong. I tried to test it in the wild, and it doesn’t seem to work. setTimeout doesn’t seem to update Date.now() based on the real time, only the ms parameter passed to it. So you can’t use it to estimate how much time a function uses in a worker.

async function sleep(ms){
  await new Promise(r=> setTimeout(()=>r(), ms));
}

//this function takes roughly 3ms to perform for a worker (nov2020).
function functionToBeTested(count){
  let a = 0;
  for (let i = count; i < 1000000; i++) 
    a += Math.sqrt(i);
  return a;
}

async function handleRequest(request) {
  let time = Date.now();
  for (let i = 0; i < 10000; i++){
    console.log('start', i, time);
    functionToBeTested(i);
    await sleep(i%2); //0 or 1 every other time
    time = Date.now();
    console.log('end  ', i, time);
  }
  return new Response('hello sunshine');
}

addEventListener('fetch', e => e.respondWith(handleRequest(e.request)));

demo

This runs approximately 16 ops before the 50ms time limit in cloudflare workers kills the worker. Thus, it takes roughly 3ms per op. But. Date.now() keeps telling us that we spend zero time per op. That time only passes when we wait for the setTimeout. So. setTimeout updates Date.now() with a fictional timestamp, the time passed if no action was actually performed. So, that leaves me with the same old problem. Compare ops/50ms or find an alternative method to fetch that can reliably and roughly update Date.now().

One final note:

If you know roughly how many times a cloudflare worker will run one of your functions in 50ms, you can compare this time with how long it takes you to run the same function the same number of times in devtools.

For example. In the last demo, my cloudflare worker managed to run functionToBeTested 16 times in 50ms. I can then run the same function 16 times in devtools. Which on my computer took 80+/-5ms. Which means that a worker is roughly 1/3 faster than js in devtools in Chrome on my computer. With many caveats such as how busy is my Chrome and OS, which libraries and functions am I calling, etc…).

To see how your browser’s v8 compare to that of Cloudflare’s server, paste the following piece of code into devtools to see the result. (Workers seem to use roughly 50ms to perform this task 16 times (nov2020)).

function functionToBeTested(count){
  let a = 0;
  for (let i = count; i < 1000000; i++) 
    a += Math.sqrt(i);
  return a;
}
const start = Date.now();
for (let i=0; i<16; i++)
  console.log(i, functionToBeTested(i));
console.log(Date.now()-start + 'ms');

Ps. Any and all response is greatly appreciated :slightly_smiling_face: