requestAnimationFrame [now] vs performance.now() time discrepancy

Question

Assumptions: rAF now time is calculated at the time the set of callbacks are all triggered. Therefore any blocking that happens before the first callback of that frame is called doesn't affect the rAF now and it's accurate--at least for that first callback.

Any performance.now() measurements made before a rAF set is triggered should be earlier than rAF now.

Test: Record before (a baseline time before anything happens). Set the next rAF. Compare rAF now and actual performance.now() to before to see how different they are.

Expected results:

var before = performance.now(), frames = ["with blocking", "with no blocking"], calls = 0;
requestAnimationFrame(function frame(rAFnow) {
  var actual = performance.now();
  console.log("frame " + (calls + 1) + " " + frames[calls] + ":");
  console.log("before frame -> rAF now: " + (rAFnow - before));
  console.log("before frame -> rAF actual: " + (actual - before));

  if (++calls < frames.length) { before = actual; requestAnimationFrame(frame); }
});

// blocking
for (var i = 0, l = 0; i < 10000000; i++) {
    l += i;
}

Observations: When there is blocking before the frame starts, the rAF now time is at times incorrect, even for that first frame. Sometimes the first frame's now is actually an earlier time than the recorded before time.

Whether there is blocking happening before the frame or not, every so often the in-frame time rAFnow will be earlier than the pre-frame time before--even when I setup the rAF after I take my first measurement. This can also happen without any blocking whatsoever, though this is rarer.

(I get a timing error on the first blocking frame most of the time. Getting an issue on the others is rarer, but does happen occasionally if you try running it a few times.)

With more extensive testing, I've found bad times with blocking prior to callback: 1% from 100 frames, no blocking: 0.21645021645021645% from ~400 frames, seemingly caused by opening a window or some other potentially CPU-intensive action by the user.

So it's fairly rare, but the problem is this shouldn't happen at all. If you want to do useful things with them, simulating time, animation, etc., then you need those times to make sense.

I've taken into account what people have said, but maybe I am still not understanding how things work. If this is all per-spec, I'd love some psuedo-code to solidify it in my mind.

And more importantly, if anyone has any suggestions for how I could get around these issues, that would be awesome. The only thing I can think of is taking my own performance.now() measurement every frame and using that--but it seems a bit wasteful, having it effectively run twice every frame, on top of any triggered events and so on.

Answer 1

The timestamp passed in to the requestAnimationFrame() callback is the time of the beginning of the animation frame. Multiple callbacks being invoked during the same frame all receive the same timestamp. Thus, it would be really weird if performance.now() returned a time before the parameter value, but not really weird for it to be after that.

Here's the relevant specification:

When the user agent is to run the animation frame callbacks for a Document document with a timestamp now, it must run the following steps:

1. If the value returned by the document object’s hidden attribute is true, abort these steps. [PAGE-VISIBILITY]

2. Let callbacks be a list of the entries in document’s list of animation frame callbacks, in the order in which they were added to the list.

3. Set document’s list of animation frame callbacks to the empty list.

4. For each entry in callbacks, in order: invoke the Web IDL callback function, passing now as the only argument, and if an exception is thrown, report the exception.

So you've registered a callback (let's say just one) for the next animation frame. Tick tick tick, BOOM, time for that animation frame to happen:

1. The JavaScript runtime makes a note of the time and labels that now.
2. The runtime makes a temporary copy of the list of registered animation frame callbacks, and clears the actual list (so that they're not accidentally invoked if things take so long that the next animation frame comes around).
3. The list has just one thing in it: your callback. The system invokes that with now as the parameter.
4. Your callback starts running. Maybe it's never been run before, so the JavaScript optimizer may need to do some work. Or maybe the operating system switches threads to some other system process, like starting up a disk buffer flush or handling some network traffic, or any of dozens of other things.
5. Oh right, your callback. The browser gets the CPU again and your callback code starts running.
6. Your code calls performance.now() and compares it to the now value passed in as a parameter.

Because a brief but non-ignorable amount of time may pass between step 1 and step 6, the return value from performance.now() may indicate that a couple of microseconds, or even more than a couple, have elapsed. That is perfectly normal behavior.

Answer 2

I encountered the same issue on chrome, where calls to performance.now () would return a higher value than the now value passed into subsequent callbacks made by window.requestAnimationFrame ()

My workaround was to set the before using the now passed to the callback in the first window.requestAnimationFrame () rather than performance.now (). It seems that using only one of the two functions to measure time guarantees progressing values.

I hope this helps anyone else suffering through this bug.