714653 - Raytracing is about 3x times slower than in Chrome

Status: NEW

(Core :: JavaScript Engine, defect)

Comment 2

[Boris Zbarsky [:bzbarsky]]

So in case it matters, this is doing most of the heavy lifting in a worker.  I _think_ it uses only one worker in both Gecko and Chrome, but that's worth double-checking.

Profile shows that the main thread is mostly drawing; the worker thread is mostly running JS.  A bit of time (4% of total) is also spent on the finalizer thread.

Looking at just the worker thread (I started the profiler somewhere around the beginning of the highest-resolution raytracing pass, and profiled about halfway through that pass):

  2% is under mjit::TryCompile from toplevel
 58% is in mjit-generated code
  9% is under js_Array (half self time, and half js::NewDenseUnallocatedArray)
  5% under stubs::SetElem<0> (mostly calling array_setGeneric)
  3% under ic::Call, mostly UncachedInlineCall calling into TryCompile and interp
  3% in stubs::FixupArity
  3% under stubs::Name (mostly self time in that function and in js_NativeGet)
  3% under stubs::GetProp (self time in js::GetPropertyOperation, js::GetPropertyHelper,
     PropertyTable::search)
  2% under stubs::NewInitArray
  2% under stubs::StrictEq

etc etc (stubs::Mod, stubs::Not, stubs::ValueToBoolean, stubs::StrictNe, and so forth).

Obvious questions I have:

1)  Why are we still compiling stuff this late in the process?  Did we end up gcing or something?

2)  Why all the stubcalls?  We clearly have some sort of ICs going (see the ic::Call), but we're getting stubcalls on stubs::Name when looking up global vars on the worker!  Heck, we're getting stubcalls setting array elements; shouldn't that be inlined?

3)  Is running in a worker important?  If the code is changed to run in the browser, how do things look?

Comment 3

[Boris Zbarsky [:bzbarsky]]

Oh, that's all in a build from 2 day ago.  So in particular, I'm pretty sure it has the fix for bug 715756 in it.  For what it's worth, my times for this testcase look as follows:

Us before bug 715756 fix:  38s
Us after bug 715756 fix: 26s
Chrome: 13s
Safari: 34s
Opera: 45s

Comment 4

[Tom S [:evilpie]]

Thanks for getting the stats!
We improved quite a bit here, too.

Current Nightly: 19s
Chromium: 8s

So more like 2x times now.

Comment 5

[Boris Zbarsky [:bzbarsky]]

Yeah, that pretty much matches my numbers.  I asked bent to take a look into whether the worker part here is relevant somehow.  Would be great if someone on the JS side would look into why we have a stubcall-fest...

Comment 6

[Boris Zbarsky [:bzbarsky]]

Attachment: Zipped-up raytracer testcase without workers: the second image in the first row works

bent put this together.  It nixes the worker bits.  The profile looks pretty similar to the worker profile, except now we have some putImageData (14%) and nsIDOMWindow_GetSelf (under the stubs::Name for some reason; why?).

The rest of the stubcalls are still there, including the SetElem that ends up in array code and all the recompilation....

Comment 7

[Shane Bundy]

http://nontroppo.org/timer/progressive_raytracer.html
I'm getting ~70s with Nightly but ~20s with Chromium on a full render (I'm on slow hardware so it's more pronounced).

Comment 8

[Boris Zbarsky [:bzbarsky]]

Shane, that url has nothing to do with this bug (and if you actually search for that url in bugzilla, you will see the bugs that it does have to do with).

Comment 9

[Shane Bundy]

(In reply to Boris Zbarsky (:bz) from comment #8)
I always do a search to avoid dupes and nothing came up when I searched. Now that I've mentioned that URI on here this is the only bug that appears.

Comment 10

[Boris Zbarsky [:bzbarsky]]

That's because you only searched open bugs, presumably.  Try searching all bugs and see the existing discussion about that page in the multiple bugs you find....

Comment 11

[Shane Bundy]

I've found them but they're classed as fixed (which isn't quite the case).

Comment 12

[Boris Zbarsky [:bzbarsky]]

You really need to actually go read the bugs.  In any case, that url has nothing at all to do with this bug, as those bugs explain: this bug is a JS issue and that URL's performance is not gated on JS.

Comment 13

[Shane Bundy]

Sorry for the unnecessary noise. It was dormant for 2 months and I thought it would be buried.

Trying to get back on-topic, what does WebKit do to get around this? Maybe Gecko isn't as dynamic and needs to reload the entire tree/compartment instead of just adding to it.

Comment 14

[Tom S [:evilpie]]

It looks like this regressed between Firefox 16 and Nightly.
From 17s to 21s for the portal.

Comment 15

[Boris Zbarsky [:bzbarsky]]

Tom, was that perhaps due to ion landing?

Comment 16

[Tom S [:evilpie]]

Most likely, just disabling ion brings the time down to 18s.

Comment 17

[Boris Zbarsky [:bzbarsky]]

Do we want a separate bug on the ion regression?

Comment 18

[Tom S [:evilpie]]

We are at 21s now. Baseline JIT is at 35s.

Comment 19

[Tom S [:evilpie]]

The demo page seems to be broken in Firefox now. Chrome still loads it.

Comment 20

[Boris Zbarsky [:bzbarsky]]

Did the page change, or our code?

Comment 21

[Till Schneidereit [:till]]

I can't make heads or tails of it, but we seem to try to interpret the .rt files as JS, whereas Chrome displays them in the codemirror editor and renders them.

Comment 22

[Till Schneidereit [:till]]

Happens in 22, too, fwiw. Didn't test older builds.

Comment 23

[Boris Zbarsky [:bzbarsky]]

Hmm.  $.get() fail somehow?  But this is just using jquery....

Comment 24

[Boris Zbarsky [:bzbarsky]]

And fwiw, I see the same in Fx13 and Fx4, so sounds like page changed.  Whether the bug is page or us is still unclear.

Comment 25

[Tom S [:evilpie]]

Sounds like the page changed, it does however look like I remember it..

Comment 26

[Tom S [:evilpie]]

Firefox Nightly: 5s Chrome 39: 4s