Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Exact time of display: requestAnimationFrame usage and timeline

What I want to achieve is to detect the precise time of when a certain change appeared on the screen (primarily with Google Chrome). For example I show an item using $("xelement").show(); or change it using $("#xelement").text("sth new"); and then I would want to see what the performance.now() was exactly when the change appeared on the user's screen with the given screen repaint. So I'm totally open to any solutions - below I just refer primarily to requestAnimationFrame (rAF) because that is the function that is supposed to help achieve exactly this, only it doesn't seem to; see below.

Basically, as I imagine, rAF should execute everything inside it in about 0-17 ms (whenever the next frame appears on my standard 60 Hz screen). Moreover, the timestamp argument should give the value of the time of this execution (and this value is based on the same DOMHighResTimeStamp measure as performance.now()).

Now here is one of the many tests I made for this: https://jsfiddle.net/gasparl/k5nx7zvh/31/

function item_display() {
    var before = performance.now();
    requestAnimationFrame(function(timest){
        var r_start = performance.now();
        var r_ts = timest;
        console.log("before:", before);
        console.log("RAF callback start:", r_start);
        console.log("RAF stamp:", r_ts);
        console.log("before vs. RAF callback start:", r_start - before);
        console.log("before vs. RAF stamp:", r_ts - before);
        console.log("")
    });
}
setInterval(item_display, Math.floor(Math.random() * (1000 - 500 + 1)) + 500);

What I see in Chrome is: the function inside rAF is executed always within about 0-3 ms (counting from a performance.now() immediately before it), and, what's weirdest, the rAF timestamp is something totally different from what I get with the performance.now() inside the rAF, being usually about 0-17 ms earlier than the performance.now() called before the rAF (but sometimes about 0-1 ms afterwards).

Here is a typical example:

before: 409265.00000001397
RAF callback start: 409266.30000001758
RAF stamp: 409260.832 
before vs. RAF callback start: 1.30000000353902
before vs. RAF stamp: -4.168000013974961 

In Firefox and in IE it is different. In Firefox the "before vs. RAF callback start" is either around 1-3 ms or around 16-17 ms. The "before vs. RAF stamp" is always positive, usually around 0-3 ms, but sometimes anything between 3-17 ms. In IE both differences are almost always around 15-18 ms (positive). These are more or less the same of different PCs. However, when I run it on my phone's Chrome, then, and only then, it seems plausibly correct: "before vs. RAF stamp" randomly around 0-17, and "RAF callback start" always a few ms afterwards.

For more context: This is for an online response-time experiment where users use their own PC (but I typically restrict browser to Chrome, so that's the only browser that really matters to me). I show various items repeatedly, and measure the response time as "from the moment of the display of the element (when the person sees it) to the moment when they press a key", and count an average from the recorded response times for specific items, and then check the difference between certain item types. This also means that it doesn't matter much if the recorded time is always a bit skewed in a direction (e.g. always 3 ms before the actual appearance of the element) as long as this skew is consistent for each display, because only the difference really matters. A 1-2 ms precision would be the ideal, but anything that mitigates the random "refresh rate noise" (0-17 ms) would be nice.

I also gave a try to jQuery.show() callback, but it does not take refresh rate into account: https://jsfiddle.net/gasparl/k5nx7zvh/67/

var r_start;
function shown() {
    r_start = performance.now();
}
function item_display() {
    var before = performance.now();
    $("#stim_id").show(complete = shown())
    var after = performance.now();
    var text = "before: " + before + "<br>callback RT: " + r_start + "<br>after: " + after + "<br>before vs. callback: " + (r_start - before) + "<br>before vs. after: " + (after - r_start)
    console.log("")
    console.log(text)
    $("p").html(text);
    setTimeout(function(){ $("#stim_id").hide(); }, 500);
}
setInterval(item_display, Math.floor(Math.random() * (1000 - 500 + 1)) + 800);

With HTML:

<p><br><br><br><br><br></p>
<span id="stim_id">STIMULUS</span>

The solution (based on Kaiido's answer) along with working display example:

function monkeyPatchRequestPostAnimationFrame() {
  const channel = new MessageChannel();
  const callbacks = [];
  let timestamp = 0;
  let called = false;
  channel.port2.onmessage = e => {
    called = false;
    const toCall = callbacks.slice();
    callbacks.length = 0;
    toCall.forEach(fn => {
      try {
        fn(timestamp);
      } catch (e) {}
    });
  };
  window.requestPostAnimationFrame = function(callback) {
    if (typeof callback !== 'function') {
      throw new TypeError('Argument 1 is not callable');
    }
    callbacks.push(callback);
    if (!called) {
      requestAnimationFrame((time) => {
        timestamp = time;
        channel.port1.postMessage('');
      });
      called = true;
    }
  };
}

if (typeof requestPostAnimationFrame !== 'function') {
  monkeyPatchRequestPostAnimationFrame();
}

function chromeWorkaroundLoop() {
  if (needed) {
    requestAnimationFrame(chromeWorkaroundLoop);
  }
}

// here is how I display items
// includes a 100 ms "warm-up"
function item_display() {
  window.needed = true;
  chromeWorkaroundLoop();
  setTimeout(function() {
    var before = performance.now();
    $("#stim_id").text("Random new text: " + Math.round(Math.random()*1000) + ".");
    $("#stim_id").show();
    // I ask for display above, and get display time below
    requestPostAnimationFrame(function() {
      var rPAF_now = performance.now();
      console.log("before vs. rPAF now:", rPAF_now - before);
      console.log("");
      needed = false;
    });
  }, 100);
}

// below is just running example instances of displaying stuff
function example_loop(count) {
  $("#stim_id").hide();
  setTimeout(function() {
    item_display();
    if (count > 1) {
      example_loop(--count);
    }
  }, Math.floor(Math.random() * (1000 - 500 + 1)) + 500);
}

example_loop(10);
<script src="https://cdnjs.cloudflare.com/ajax/libs/jquery/2.2.3/jquery.min.js"></script>
<div id="stim_id">Any text</div>

EDIT: So, based on empirical measurements, out of all this, it turns out that all that matters is the rAF loop. The rPAF makes no real difference.

like image 788
gaspar Avatar asked Jun 17 '18 09:06

gaspar


1 Answers

What you are experiencing is a Chrome bug (and even two).

Basically, when the pool of requestAnimationFrame callbacks is empty, they'll call it directly at the end of the current event loop, without waiting for the actual painting frame as the specs require.

To workaround this bug, you can keep an ever-going requestAnimationFrame loop, but beware this will mark your document as "animated" and will trigger a bunch of side-effects on your page (like forcing a repaint at every screen refresh). So I'm not sure what you are doing, but it's generally not a great idea to do this, and I would rather invite you to run this animation loop only when required.

let needed = true; // set to false when you don't need the rAF loop anymore

function item_display() {
  var before = performance.now();
  requestAnimationFrame(function(timest) {
    var r_start = performance.now();
    var r_ts = timest;
    console.log("before:", before);
    console.log("RAF callback start:", r_start);
    console.log("RAF stamp:", r_ts);
    console.log("before vs. RAF callback start:", r_start - before);
    console.log("before vs. RAF stamp:", r_ts - before);
    console.log("")
    setTimeout(item_display, Math.floor(Math.random() * (1000 - 500 + 1)) + 500);
  });
}
chromeWorkaroundLoop();
item_display();

function chromeWorkaroundLoop() {
  if (needed) {
    requestAnimationFrame(chromeWorkaroundLoop);
  }
};

Now, requestAnimationFrame callbacks fire before the next paint (actually in the same event loop), and the TimeStamp argument should represent the time after all main tasks and microtasks of the current frame were executed, before it's starts its "update the rendering" sub-task (step 9 here).
[edit]: However it's not really what browsers implement, see this Q/A for more details.

So it's not the most precise you can have, and you are right that using performance.now() inside this callback should get you closer to the actual painting time.

Moreover when Chrome faces yet an other bug here, probably related to the first one, when they do set this rAF timeStamp to... I must admit I don't know what... maybe the previous painting frame's timeStamp.

(function() {
let raf_id,
  eventLoopReport = {
    id: 0,
    timeStamp: 0,
    now: 0
  },
  report = {
    nb_of_loops_between_call_and_start: -1,
    mouseClick_timeStamp: 0,
    calling_task: {
        eventLoop: null,
      now: 0
    },
    rAF_task: {
        eventLoop: null,
      now: 0,
      timeStamp: 0
    }
  };
  
startEventLoopCounter();
  
btn.onclick = triggerSingleFrame;


// increments eventLoop_id at every event loop
// (or at least every time our postMessage loop fires)
function startEventLoopCounter() {
  const channel = new MessageChannel()
  channel.port2.onmessage = e => {
    eventLoopReport.id ++;
    eventLoopReport.timeStamp = e.timeStamp;
    eventLoopReport.now = performance.now();
    channel.port1.postMessage('*');
  };
  channel.port1.postMessage('*');
}

function triggerSingleFrame(e) {
  // mouseClick Event should be generated at least the previous event loop, so its timeStamp should be in the past
    report.mouseClick_timeStamp = e.timeStamp;
    const report_calling = report.calling_task;
  report_calling.now = performance.now();
  report_calling.eventLoop = Object.assign({}, eventLoopReport);

    cancelAnimationFrame(raf_id);
  
    raf_id = requestAnimationFrame((raf_ts) => {
    const report_rAF = report.rAF_task;
        report_rAF.now = performance.now();
    report_rAF.timeStamp = raf_ts;
    report_rAF.eventLoop = Object.assign({}, eventLoopReport);
    report.nb_of_loops_between_call_and_start = report_rAF.eventLoop.id - report_calling.eventLoop.id;
    // this should always be positive
    report_el.textContent = "rAF.timeStamp - mouse_click.timeStamp: " +
            (report.rAF_task.timeStamp - report.mouseClick_timeStamp) + '\n\n' +
      // verbose
        JSON.stringify(report, null, 2) ;
  });
}
})();
<button id="btn">flash</button>
<div id="out"></div>
<pre id="report_el"></pre>

Once again, running an infinite rAF loop will fix this weird bug.

So one thing you might want to check is the maybe incoming requestPostAnimationFrame method.

You can access it in Chrome,1 after you enable "Experimental Web Platform features" in chrome:flags. This method if accepted by html standards will allow us to fire callbacks immediately after the paint operation occurred.

From there, you should be at the closest of the painting.

var needed = true;
function item_display() {
  var before = performance.now();
  requestAnimationFrame(function() {
    requestPostAnimationFrame(function() {
      var rPAF_now = performance.now();
      console.log("before vs. rPAF now:", rPAF_now - before);
      console.log("");
      setTimeout(item_display, Math.floor(Math.random() * (1000 - 500 + 1)) + 500);
    });
  });
}

if (typeof requestPostAnimationFrame === 'function') {
  chromeWorkaroundLoop();
  item_display();
} else {
  console.error("Your browser doesn't support 'requestPostAnimationFrame' method, be sure you enabled 'Experimental Web Platform features' in chrome:flags");
}

function chromeWorkaroundLoop() {
  if (needed) {
    requestAnimationFrame(chromeWorkaroundLoop);
  }
};

And for the browsers that do not yet implement this proposal, or if this proposal never does it through the specs, you can try to polyfill it using a MessageEvent, which should be the first thing to fire at the next event loop.

// polyfills requestPostAnimationFrame
// requestPostAnimationFrame polyfill
if (typeof requestPostAnimationFrame !== "function") {
  (() => {
    const channel = new MessageChannel();
    const callbacks = [];
    let timestamp = 0;
    let called = false;
    let scheduled = false; // to make it work from rAF
    let inRAF = false; // to make it work from rAF
    channel.port2.onmessage = e => {
      called = false;
      const toCall = callbacks.slice();
      callbacks.length = 0;
      toCall.forEach(fn => {
        try {
          fn(timestamp);
        } catch (e) {}
      });
    }
    // We need to overwrite rAF to let us know we are inside an rAF callback
    // as to avoid scheduling yet an other rAF, which would be one painting frame late
    // We could have hooked an infinite loop on rAF, but this means
    // forcing the document to be animated all the time
    // which is bad for perfs
    const rAF = globalThis.requestAnimationFrame;
    globalThis.requestAnimationFrame = function(...args) {
      if (!scheduled) {
        scheduled = true;
        rAF.call(globalThis, (time) => inRAF = time);
        globalThis.requestPostAnimationFrame(() => {
          scheduled = false;
          inRAF = false;
        });
      }
      rAF.apply(globalThis, args);
    };
    globalThis.requestPostAnimationFrame = function(callback) {
      if (typeof callback !== "function") {
        throw new TypeError("Argument 1 is not callable");
      }
      callbacks.push(callback);
      if (!called) {
        if (inRAF) {
          timestamp = inRAF;
          channel.port1.postMessage("");
        } else {
          requestAnimationFrame((time) => {
            timestamp = time;
            channel.port1.postMessage("");
          });
        }
        called = true;
      }
    };
  })();
}

var needed = true;

function item_display() {
  var before = performance.now();
  requestPostAnimationFrame(function() {
    var rPAF_now = performance.now();
    console.log("before vs. rPAF now:", rPAF_now - before);
    console.log("");
    setTimeout(item_display, Math.floor(Math.random() * (1000 - 500 + 1)) + 500);
  });
}


chromeWorkaroundLoop();
item_display();

function chromeWorkaroundLoop() {
  if (needed) {
    requestAnimationFrame(chromeWorkaroundLoop);
  }
};
  1. Turns out this feature has apparently been removed from Chrome experiments. Looking at the implementation issue I can't find why, when, nor if they plan to still work on it.
like image 68
Kaiido Avatar answered Sep 29 '22 09:09

Kaiido