922071 - Peacekeeper domJQueryHierarchy slower than in Chrome

Status: RESOLVED WORKSFORME

(Core :: DOM: Core & HTML, defect)

Description

[Jan de Mooij [:jandem]]

Attachment: Testcase

The last DOM/jQuery test, finally.

Original test here: http://www.peacekeeper.therichins.net/test22.html Attaching a standalone version with a non-minified version of jQuery (1.6.4)

Chrome 31:  1498 ms
Nightly 27: 2390 ms

This test does:

    $("#chosenOne, div, .title");
    $("#chosenOne .title");
    $("#chosenOne + div");
    $("#chosenOne ~ div");

Profile looks similar to the other ones I just filed. bz: can you confirm this? Sorry again for the needinfo spam but at least we've bugs on file now for all these tests.

Comment 1

[Boris Zbarsky [:bzbarsky]]

Yeah, this looks like the other jQuery bits.  About half the time is in querySelectorAll.  This breaks down (all fractions are of querySelectorAll time) as about 30% the DOM tree traversal, 20% SelectorMatches, 20% SelectorMatchesTree, 15% selector list parsing, 6% malloc/realloc for the return array, 5% destroying the selector list.  

So bug 863966 will slice off about 10% of the overall time here.

The remainder of the time is JS time, which is about the same for all these jquery tests.

Comment 2

[Boris Zbarsky [:bzbarsky]]

> So bug 863966 will slice off about 10% of the overall time here.

And local testing with that patch confirms it.

Comment 3

[Jan de Mooij [:jandem]]

I tested m-i opt builds with/without bug 933475, it improved this from 1987 to 1598 ms. Chrome is still a bit faster though, 1469 ms.

Comment 4

[Boris Zbarsky [:bzbarsky]]

We should probably do some reprofiling once that lands.

Comment 5

[Boris Zbarsky [:bzbarsky]]

I see something similar, with Chrome slightly faster.  So an updated profile.

47% is querySelectorAll calls (42% in the Node code, and a few percent wrapping the return value).

13% is array_slice.

7% seems to be Array.prototype.push.apply() bits (some overhead, and 4.5% in the actual push).

7% is js::jit::DoGetPropFallback landing in HTMLDocument binding proxy code. This keeps coming up; I'll look into what prop this is.

6.3% is js::GetProperty, again mostly on the document.

and then some regexp_exec CloneRegExpObject and whatnot, but we're into <2% long tail territory now.

Comment 6

[Boris Zbarsky [:bzbarsky]]

So I see these 5 things repeat over and over, in this order: js::GetProperty for "nodeType", "charAt", "documentElement", then js::jit::DoGetPropFallback for "nodeType", "querySelectorAll".

For the DoGetPropFallback, I have a script and pc, so I can point to where exactly we are.  The nodeType get is on line 4913 in the testcase:

  if ( context.nodeType === 9 ) {

The "querySelectorAll" get is on line 4938:

  return makeArray( context.querySelectorAll(query), extra );

As far as the js::GetProperty goes, I expect that's in the main $("foo") stuff.  In particular, the init() method starting line 104, which does:

  if (selector.nodeType) {

and then

  if (selector.charAt(0) === "<" && selector.charAt( selector.length - 1 ) === ">" && selector.length >= 3 )

I'm not sure where the documentElement get is.

In any case why are we ending up with slow paths for all that stuff?  The .nodeType on a string should hit some sort of missing-property cache, charAt on a string should be fast, and .nodeType and .querySelectorAll on a document should also hit ICs, I'd think.

Comment 7

[Jan de Mooij [:jandem]]

(In reply to Boris Zbarsky [:bz] from comment #6)
> In any case why are we ending up with slow paths for all that stuff?  The
> .nodeType on a string should hit some sort of missing-property cache, charAt
> on a string should be fast, and .nodeType and .querySelectorAll on a
> document should also hit ICs, I'd think.

Ion only uses a GetPropertyIC if the value is definitely an object. If the value is object-or-string we'll be slow. See also bug 922272, I think that's happening here in a few cases at least.

Maybe we could be smarter and use baseline feedback, at least for the selector.charAt: the baseline IC should always see a string there, so in that case IonBuilder can insert a fallible unbox and inline the charAt etc.

The .nodeType is a bit more complicated because we see both objects and strings there I think (right?). We could have a GetElementIC LIR instruction that takes a boxed value instead of typed object, but that's a huge pain :(

Or IonBuilder could statically check strings don't have a .nodeType property, use a special GetPropertyIC that takes a boxed value, but *unbox* it before calling the first stub. When it's a string it'd just return |undefined| before jumping to the first stub. This way, the cache itself doesn't have to be updated at all...

Comment 8

[Jan de Mooij [:jandem]]

(In reply to Jan de Mooij [:jandem] from comment #7)
> We could have a GetElementIC LIR instruction ...

GetPropertyIC, of course.

Comment 9

[Boris Zbarsky [:bzbarsky]]

> Maybe we could be smarter and use baseline feedback, at least for the selector.charAt

I just checked, and apart from 3 calls at jQuery startup, the "selector" in the function that has the selector.charAt call is always a string.  

Same for the selector.nodeType get: "selector" is always a primitive string there.

For the other .nodeType callsite (line 4913), "context" is always an HTMLDocument.  Same at line 4938.

So we should really at least not be hitting DoGetPropFallback.  And ideally not hitting js::GetProperty for the known-string (both for its missing property and its .charAt).

Comment 10

[Boris Zbarsky [:bzbarsky]]

> I just checked, and apart from 3 calls at jQuery startup

But that part is important due to bug 922272.

I'll look into why we end up in DoGetPropFallback.

Comment 11

[Boris Zbarsky [:bzbarsky]]

> I'll look into why we end up in DoGetPropFallback.

Well, for "nodeType" we got it because of bug 943989.

But even with that fixed, we get the fallback for "querySelectorAll".  Looking into why now.

Comment 12

[Boris Zbarsky [:bzbarsky]]

The querySelectorAll bit is bug 944014.

Comment 13

[Boris Zbarsky [:bzbarsky]]

So what's left is the js::GetProperty "documentElement".  Jan, do you know how I can figure out which script line, or at least which function, is involved there?

Comment 14

[Jan de Mooij [:jandem]]

(In reply to Boris Zbarsky [:bz] from comment #13)
> So what's left is the js::GetProperty "documentElement".  Jan, do you know
> how I can figure out which script line, or at least which function, is
> involved there?

If you have it in gdb you can call js_DumpBacktrace(cx) to get a stack trace. Or else add this to js::GetProperty:

  jsbytecode *pc;
  JSScript *script = cx->currentScript(&pc); 
  printf("%s:%d\n", script->filename(), PCToLineNumber(script, pc));

Comment 15

[Boris Zbarsky [:bzbarsky]]

Thanks.  That last js::GetProperty is on this line:

  var documentElement = (elem ? elem.ownerDocument || elem : 0).documentElement;

At runtime, elem is never null, so this is always ending up doing .documentElement on an HTMLDocument object.  But apparently Ion thinks that it can actually see the 0 there sometime?  Replacing the 0 with {} certainly makes the js::GetProperty go away.

Comment 16

[Olli Pettay [:smaug][[e-mail]]]

Chrome 1345ms, m-i 1586ms

Comment 17

[Jan de Mooij [:jandem]]

(In reply to Olli Pettay [:smaug] from comment #16)
> Chrome 1345ms, m-i 1586ms

Fixing the slow GetProperty paths here is next on my list. Based on bz's profile that should help quite a bit.

Comment 18

[Trev]

Looks like this is fixed now.  Chrome: 1127ms, Nightly: 997ms.

Comment 19

[Olli Pettay [:smaug][[e-mail]]]

We're faster on 64 bit linux (1600 vs 1800).
Would be good to test OSX and Windows.
(not sure which OS comment 18 is about.)

Comment 20

[Trev]

(In reply to Trev from comment #18)
> Looks like this is fixed now.  Chrome: 1127ms, Nightly: 997ms.

This was on 64 bit Windows 7

Comment 21

[Olli Pettay [:smaug][[e-mail]]]

Ok. I think that is enough to confirm this is now fixed.

Comment 22

[Boris Zbarsky [:bzbarsky]]

On Linux, I see, on the testcase: Gecko 840ms, Chrome 1271ms.

On the original test, I see: Gecko 7336 ops/s, Chrome 4565 ops/s.

Comment 23

[Boris Zbarsky [:bzbarsky]]

I mean on _Mac_, for comment 22.