Resolve Check.run immediately if not async

[paulirish]

Running axe on this URL takes ~13s. But towards the end of the profile is an interesting block of time:

Zoomed out it looks like a lot of work, but it's actually quite sparse when you zoom in:

It's 1.3s of timers firing. :) Turns out each timer fire has about 0.1ms of overhead, and this was ~13,000 timers.

I traced it back to the setTimeout here, which doesn't appear to be necessary. But there may be context for why it was originally added that I don't know.

If it is necessary to keep it deferred, you could collect all these as callbacks and then schedule one setTimeout which will then execute all of them. That'd be just as fast.

[WilcoFiers]

I suspect this was originally done to prevent browsers from freezing up. Chrome is pretty good about that sort of thing, but others aren't. Firefox for one starts complaining if a script runs for more than a few seconds. Whether or not that's the reason behind this code is just a guess. @dylanb might know more.

Either way we'd need to test this change in all supported browsers to make sure none of them choke on a single long execution time.

[dylanb]

Ok, this was added to give the frame messages time to bubble up. Without that timeout, documents with iframes do not collect results from the iframes consistently.

Specifically, we saw problems in Firefox. I cannot recall whether the problems also occurred in Chrome.

@paulirish I am interested in your suggestion on the "collection of callbacks", can you elaborate?

[dylanb]

@paulirish Another option is to only do the setTimeout if we are checking frames. This would be compatible with the current code but provide callers who know they are not interested in iframes the ability to get the performance improvements

[paulirish]

hey guys, thanks for the quick feedback.

I suspect this was originally done to prevent browsers from freezing up

Yeah I thought that might be the case, too. But in this scenario, the deferred work is basically 1 fn call and 1 assignment. And, as it turns out, calling setTimeout is already more expensive than just doing the original work. 😆

@paulirish I am interested in your suggestion on the "collection of callbacks", can you elaborate?

I don't 100% understand the aXe runtime, so this could easily make zero sense... Checks happen within rules, right?
Basically I'm thinking each Rule could have a postCheckCallbacks array. (I'm certain you can figure a better name ;)

// at the end of Check.prototype.run ...
thisCheck.parentRule.postCheckCallbacks.push(_ => { 
  resolve(checkResult);
});

// ...

// then somewhere on the Rule-level you'd schedule the timer
setTimeout(_ => { 
  rule.postCheckCallbacks.forEach(cb => cb()); 
}, 0);

This would mean just a total of ~40 timers installed rather than 10,000+.

I also think it's worthwhile trying to verify the iframe race condition issue is still present, as that seems like the kind of issue Mozilla would address in the past 4 years. (Task scheduling is far more specced now than it was then).

[WilcoFiers]

I talked briefly to @stephenmathieson about this idea and he said he'd be up for looking into a postCheckCallbacks solution.

[stephenmathieson]

First off, I'm sorry for the delay, @paulirish. I haven't had time to take a look here until now.

I've pulled this branch down locally and have done some primitive manual testing. Removing the setTimeout in question only seems to trim off about ~100ms while testing in Chrome, which still leaves about 18.5s spent analyzing the provided URL (on my 2017 MBP).

Digging further into that ~18s, I see lots of time spent creating selectors for results (~100ms per invocation). Removing the createUniqueSelector logic (and replacing it with () => "fake selector") took the 18s down to ~7s. IMO we ought to try to optimize selector generation rather than focusing on the timer issue, since the time saved by doing so is significantly larger.

Thoughts @paulirish @dylanb @WilcoFiers?

[paulirish]

@stephenmathieson First up, I 100% support working on the biggest bottleneck.. though I'm not seeing much of a perf win with createUniqueSelector... Not entirely sure what the difference in our setups is..

Regardless... 'FIX THE PERF OF ALL THE THINGS!!!1' ya?? :)

---

Here's how I did my benchmarking:

yarn build; cat axe.js | pbcopy

Then I copied axe into a devtools snippet. I evaluated it in this page. In devtools settings, I check "disable async stack traces" because it adds some overhead.

Then I ran this in the console:

console.time('axe');
await window.axe.run(document, {
    elementRef: true,
    runOnly: {
      type: 'tag',
      values: ['wcag2a', 'wcag2aa']
    },
    resultTypes: ['violations', 'inapplicable'],
});
console.timeEnd('axe');

develop branch:
6,377 ms
6,449 ms
6,535 ms
6,621 ms

develop with this PR cherrypicked:
5,789 ms
5,861 ms
5,944 ms
6,109 ms

Visually, that's here:

So it's worth ~570ms on this page on my machine. Still big enough that I think it's worth it.

---

I tested your 'fake selector' solution and that looks more like a savings of ~90ms in my setup:

[paulirish]

Looking at the logic in my original PR here I don't see how this setTimeout(fn, 0) would make a difference. The checkResult object cannot change during this next event loop. and everything happening from resolve on is synchronous. So I'm pretty sure this code is functionally the same.

Ok, this was added to give the frame messages time to bubble up. Without that timeout, documents with iframes do not collect results from the iframes consistently.

Specifically, we saw problems in Firefox. I cannot recall whether the problems also occurred in Chrome.

@dylanb Do we have any more details? I'm willing to see if there is a difference in results in Firefox.

[stephenmathieson]

I did my benchmarking nearly the same way, but without any additional axe configuration.

Regardless... 'FIX THE PERF OF ALL THE THINGS!!!1' ya?? :)

Haha, absolutely!

So it's worth ~570ms on this page on my machine. Still big enough that I think it's worth it.

Agreed that half a second is worth shaving off. 👍

I tested your 'fake selector' solution and that looks more like a savings of ~90ms in my setup:

Interesting, I'll take another look there and will provide a more detailed update today.

[stephenmathieson]

Wrapping axe.utils.getSelector with something like:

axe.utils.getSelector = (...args) => {
  function createUniqueSelector(...){...}
  console.time('getSelector')
  const selector = createUniqueSelector(...args)
  console.timeEnd('getSelector')
  return selector
}

Shows between 10-100ms per invocation and a total of about 15s (~15441.0485239ms... 16133.1251224012ms, 14866.4254564811ms, 15289.6802264376ms, 15474.9632903336ms) spent on my machine 🤷‍♀️

---

The ticket referenced when this setTimeout was added doesn't provide any more details:

Run all checks asynchronously
We should force all checks to run asynchronously so that the UI doesn't "lock" or "unresponsive script" prompts do not appear

I briefly tested removing the setTimeout in Firefox today and was prompted with a warning about slow scripts. This isn't necessarily due to the missing setTimeout tho, since copy/pasting axe.js into the FF console nearly blew up my machine.

I'll test more throughly (with the Firefox extension) on Monday.

[paulirish]

sg. for avoiding the slow script warning I think it's reasonable to setTimeout0 between running each Rule.

also yah . that's a lot of time generating selectors. funky!

[stephenmathieson]

Additionally, the suggested postCheckCallbacks fix seems slightly more complicated than it seems. I don't believe the checks are aware of the "rule" running them, and there seems to be very little context between the two. I'll poke around further tho

A setTimeout() between running rules seems like a much better solution, since there are fewer rules than checks (and rules compose checks). I can take a stab at that on Monday too.

[paulirish]

yes. I looked into the same thing yesterday and agree totally.

[stephenmathieson]

Good and bad news.

Bad first: removing the setTimeout() from Check#run() does indeed cause FF to warn about unresponsive scripts. I'm seeing it consistently from the Firefox extension and from pasting axe.js into the console (as described by #1172 (comment)).

However, the good news is adding q.defer(resolve => setTimeout(resolve, 0)) to Rule#run() prevents the warning. This means we'll only add as many timeouts as we have rules (rather than a timeout for every check). As @paulirish suggested, this is ~40 rather than ~10k (since checks are composed by rules), which should be a nice/simple win. 😄

I'm going to do some more testing on this, but think this is an acceptable solution to the original problem.

[paulirish]

closing in favor of #1308