document.createElement very slow.

[samuknet]

document.createElement appears to be much slower than in FF/Chrome.

The core issue is shown with this code:

function test(n) { // Create n 'div' elements using document.createElement
  var then = performance.now();
  var str = 'div';
  for (var i = 0; i < n; i++) {
    document.createElement(str);
  } 
  return performance.now() - then;
}
// Run test 1000 times and average
var times = [];
for (var i = 0; i < 1000; i++) {
  times.push(test(1000));
}
console.log(times.reduce((acc, n) => acc + n) / times.length); // Print avg. time

FF/Chrome avg. time around 0.317465..
Servo avg. time around 1.3

Full testcase here.

[Manishearth]

I can repro these numbers

[metajack]

Since we create a reflector eagerly and Firefox does it lazily, I would like to see numbers where you modify the benchmark such that the reflector would be created in Firefox. Then at least we will know whether this is the cost of eager creation or if there is another problem hiding here.

@bzbarsky What is the simplest way to ensure a reflector is created? Just access some property of the element?

[bzbarsky]

Since we create a reflector eagerly and Firefox does it lazily

Not relevant here. createElement has to return the reflector, obviously, so it has to create it in Firefox. This is an honest apples to apples comparison.

Note that it would be interesting to test the no-reflector-creation case too (using cloneNode(true) on a tree of nontrivial size). I seem to recall @wycats saying that skipping reflector creation in Firefox helps a lot there, and we were wondering what the Servo numbers would look like. But that's a separate issue, obviously.

[jdm]

So far profiling has revealed a stray memmove in the div element constructor, but it's been difficult to pin down what's causing it.

[jdm]

Inlining the box expression in HTMLDivElement::new into the Node::reflect_node call made the memmove go away, but the timing did not noticeably improve. Current profile shows 25% of time spent under HTMLDivElement::new (14% under HTMLElement::new, 10% under Element::new_inherited, 3.5% under EventTarget::new_inherited), but no smoking guns :(

[jdm]

Following @bzbarsky's advice, I ran the following test in both servo and gecko (with some modifications to the TextEncoder interface):

<script>
var t = 'TestBinding' in window ? (new TestBinding()) : (new TextEncoder());
var start = new Date();
var count = 1000000;
for (var i = 0; i < count; i++) {
  var a = t.receiveVoid();
}
var stop = new Date();
console.log('void method: ' + ((stop - start) / count * 1e6) + 'ns');

var start = new Date();
var count = 1000000;
for (var i = 0; i < count; i++) {
  var a = t.longAttribute;
}
var stop = new Date();
console.log('int getter: ' + ((stop - start) / count * 1e6) + 'ns');

var n = document.firstElement;
var start = new Date();
var count = 1000000;
for (var i = 0; i < count; i++) {
  var a = n.firstChild;
}
var stop = new Date();
console.log('firstChild getter: ' + ((stop - start) / count * 1e6) + 'ns');                   
</script>

Results:

Gecko:
void method: 8ns
int getter: 9ns
firstChild getter: 16ns

Servo:
void method: 39ns
int getter: 33ns
firstChild getter: 74ns

[jdm]

With https://gist.github.com/jdm/4755af850d2d718aac3fc95da456556f applied to rust-mozjs I get void method timings of 18-20ns. The profile shows 30% of execution time is spent code related to catching panics, courtesy of my changes in #11803. I guess we need to talk to the Rust team about what can be done to reduce that.

[jdm]

I filed rust-lang/rust#34727 about catching panics hurting our performance.

[jdm]

I tried removing the catch_unwind stuff and measuring again, and I get timings around 10ns.

[jdm]

Curiously enough, I tried measuring the firstChild getter with the inlining changes and catch_unwind removed - the first two runs averaged 4ns and 2ns, and every single run after that averaged 42-48ns. I have no idea what to make of that. This is consistent across restarts of Servo and page reloads, too.

[wycats]

I seem to recall @wycats saying that skipping reflector creation in Firefox helps a lot there, and we were wondering what the Servo numbers would look like. But that's a separate issue, obviously.

An easy way to test this is to compare constructing a tree using cloneNode with an equivalent tree constructed using the DOM APIs.

[jdm]

No surprise given #12358, the profile for the firstChild getter is dominated by JSCompartment::wrap and related SM wrapping functions.

[notriddle]

So half the problem is insufficient inlining (a solved problem), and the other half is panic catching?

[bzbarsky]

And the third half is the slow compartment wrapping. There might be other things too; those were just the biggest offenders so far...

[Ms2ger]

FTR, servo/rust-mozjs#276 landed

[jdm]

Sadly #12374 and #12395 have only shaved 90ms off of the original testcase for me so far :(

[jdm]

Servo master reports ~1.0 for me now. Progress!

[metajack]

@jdm So that's still just over 3x slower?

[jdm]

Firefox gives me ~0.4, so 2-3x.

[jdm]

Correction, with LTO enabled I get ~0.9.

[jdm]

As far as the timings for tests/html/bindings_perf.html, the situation compared with Gecko is much better:

Gecko:
void method: 8ns
int getter: 9ns
firstChild getter: 16ns

Servo:
void method: 9.215ns
int getter: 8.6575ns
firstChild getter: 18.425ns

This might only need #12357 to make a big difference for the testcase here.

[jdm]

Unfortunately, I still get 0.8-0.9 with #12980 applied.

[jdm]

My servo time is now ~0.6. Progress!

[nox]

What changed?

[jdm]

The various changes to rustc linked from rust-lang/rust#34727.

[nox]

This still seems to be an issue.

[pshaughn]

WPT tests that do a lot of element-creating certainly seem to have timeout and other slow-test problems, e.g. #6386 and #25142