requestAnimationFrame based rendering

Recently I learned about:

https://bugs.chromium.org/p/chromium/issues/detail?id=570845#c9

Chrome 47 has a new feature which lowers the priority of timers during active input when the timers appear to be SO expensive that we can’t run them while handling input at 60fps ( issue 463143 , Scheduling JS Timer Execution - Google Docs). When the user is actively manipulating something, you should be responding to their input in <16ms in order to ensure a smooth experience for the user.

If you need a more guaranteed way of doing work on every frame you should be using requestAnimationFrame (but still aiming to get all your work done <16ms).

This information resolved 2 giant mysteries we had for the last year at Discourse.

Mystery #1

Sometimes when we hit back and scroll down the topic list, Chrome appears to add a 1-3 second delay loading more topics

Mystery #2

When scrolling through topics our widget on the right often did some REAL weird things on slower systems, like this:


I managed to debug and reproduce this on local by using the ember production bundle and setting Chrome to 6x slowdown. I quickly became apparent Chrome does some serious punishing on setTimeout if you start taking too long with it.

In particular I am able to measure 1-3 second delays on timeouts that are meant to take only 10 milliseconds.

This discover is not new @runspired and @rwjblue have known about this issue for a while per:

requestAnimationFrame is basically a much better setTimeout with a few useful additional behaviors. It’s ties to the platform’s refresh rate and will execute the given work during the next refresh. Additionally, any work scheduled into it becomes non-DOM affecting until all scheduled work completes.

Now I am not totally comfortable with the implementation there for Discourse for a couple of reasons:

  • For all we know in some cases ids can overlap and the above code can incorrectly clear the wrong thing.

  • For Discourse we need to be more aggressive and it seems that to get this going right I need to just treat all timeouts under say 16 or so as requestAnimationFrame which in turn gives us a simple requestAnimationFrame debounce. Otherwise we are going to need to walk our internal code and use debounce 0 which is not really semantically what we mean, debounce 10 is a lot closer to the intention. I guess what we really want is to have an internal debounceAnimationFrame but its a bit of a bigger change.

My proposed implementation for Discourse is:

Ember.run.backburner._platform.setTimeout = function(method, wait) {
  // 16 is one animation frame approximately, so bypass
  if (!wait || wait < 16 || !window.requestAnimationFrame) {
    return [null, window.requestAnimationFrame(method, wait)];
  } else {
    return [setTimeout(method, wait)];
  }
}

Ember.run.backburner._platform.clearTimeout = function(id) {
  if (id[0] === null) {
    window.cancelAnimationFrame(id[1]);
  } else {
    clearTimeout(id[0]);
  }
}

This seems to work, but I wanted some advice from the Ember team about this, what are your thoughts? Should we go with this or something else? Does any of this belong in Ember?

4 Likes

What does “active input” means exactly? Does this mean all user interactions?

Oh, you can try it yourself here :heart_eyes:

Just open devtools in Chrome and paste in:

Ember.run.backburner._platform.setTimeout = function(method, wait) {
      var start = window.performance.now();
      var wrapped = function(){
          var duration = window.performance.now() - start;
          if ((duration - wait) > 10) {
              console.log("setTimeout unexpectedly delayed. Expecting: " + wait + "ms actual: " + duration + "ms");
          }
          method();
      }
      return setTimeout(wrapped, wait);
    }

Scrolling and clicking is definitely is considered active input, this is me scrolling and clicking through the site (make sure to go to a long topic from the front page):

setTimeout unexpectedly delayed. Expecting: 1ms actual: 44.49999995995313ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 1ms actual: 126.20000005699694ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 102.79999999329448ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 17.699999967589974ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 10ms actual: 21.39999996870756ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 204.60000005550683ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 294.70000008586794ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 83.89999996870756ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 84.09999997820705ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 10ms actual: 87.10000000428408ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 228.40000002179295ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 16.899999929592013ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 16.99999999254942ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 224.70000002067536ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 500ms actual: 525.400000042282ms
2VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 15.000000013969839ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 271.70000004116446ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 288.1000000052154ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 1ms actual: 28.399999951943755ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 1ms actual: 171.6999999480322ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 54.00000000372529ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 57.20000003930181ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 57.79999995138496ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 10ms actual: 58.59999998938292ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 346.50000010151416ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 255.59999991673976ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 12.000000104308128ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 231.90000001341105ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 1ms actual: 197.7999999653548ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 28.70000002440065ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 28.30000000540167ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 10ms actual: 30.900000012479722ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 18.899999908171594ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 19.699999946169555ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 20.299999974668026ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 10ms actual: 21.499999915249646ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 11.999999987892807ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 1ms actual: 175.6000000750646ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 50.79999996814877ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 55.099999997764826ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 56.299999938346446ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 10ms actual: 57.4000000488013ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 1ms actual: 93.09999994002283ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 1ms actual: 36.00000008009374ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 1ms actual: 79.70000000204891ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 0ms actual: 30.100000090897083ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 34.40000000409782ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 34.899999969638884ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 10ms actual: 36.700000055134296ms

0ms being delayed quarter of a second is most likely the runloop.

If you turn on 4x or 6x delay while running this experiment you can see how brutal stuff can get on slow computers.


setTimeout unexpectedly delayed. Expecting: 0ms actual: 3820.699999923818ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 2059.2999999644235ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 5ms actual: 2062.3999999370426ms
VM277:6 setTimeout unexpectedly delayed. Expecting: 10ms actual: 2070.4999999143183ms

Twitter responses:

https://twitter.com/Runspired/status/967139197499858944

https://twitter.com/Runspired/status/967141111209779200

I made a small tweak to the snippet above to also add perf measures, so we can see whats happening in a trace:

Ember.run.backburner._platform.setTimeout = function(method, wait) {
  var start = window.performance.now();
  var i = Math.random();
  performance.mark('start' + i);
  var wrapped = function() {
    performance.mark('stop' + i);
    performance.measure('timeout of ' + wait, 'start' + i, 'stop' + i);
    var duration = window.performance.now() - start;
    if ((duration - wait) > 10) {
      console.log("setTimeout unexpectedly delayed. Expecting: " + wait + "ms actual: " + duration + "ms");
    }
    method();
  }
  return setTimeout(wrapped, wait);
}

For example, this section looks very reasonable:

https://discuss.emberjs.com/uploads/short-url/laVpcvYKw6KeIYYzXLrR7SENEOv.png

And so does this segment:

https://discuss.emberjs.com/uploads/short-url/1b4wfzpFZxxdZHqfRts1AkxmyCT.png

(sorry, but got this when posting: “Sorry, new users can only put one image in a post.”)

But then there are also timer delays like this, which I don’t really understand:

So yeah I think I can agree when @sam said:

once you throttle CPU and run the profiler you can actually see the computer sitting there doing nothing on lots of these “extra” delays, Something is not quite right with the Chrome algorithm

2 Likes

Should I open an item on the Chrome bug tracker for this?

Good question.

How about… we do it together? :slight_smile: Can you take a first pass on the text? I’ll file it on your behalf and add in the right engineers.