Much slower than Chrome in this React app

RESOLVED WORKSFORME

Status

()

defect
RESOLVED WORKSFORME
3 years ago
2 years ago

People

(Reporter: mstange, Assigned: nbp)

Tracking

(Depends on 1 bug)

Trunk
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox51 affected)

Details

Attachments

(2 attachments)

This was reported in https://news.ycombinator.com/item?id=12437459

STR:
 1. Go to https://hsreplay.net/replay/7VAKLeMNaXvshAawnUUoni and wait for it to load.
 2. Drag the scrubber on the bottom of the blue area left and right.

Dragging is really janky (maybe 5-10fps). In Chrome it's smooth.

Profile: https://cleopatra.io/#report=c7ed2cadb56485d6030fd0648da7650eb15f309d&filter=%5B%7B%22type%22%3A%22FocusedFrameSampleFilter%22,%22name%22%3A%22js%3A%3ARunScript%22,%22focusedSymbol%22%3A4%7D%5D

I expected the slowdown to come from rendering the blur filters, but that's not the case - most of the time is spent in JS execution. (20% of the JS execution is in sync IPC in contentObserver.shouldLoad() though, and that's because I have uBlock Origin installed.)

There are lots of "Bailout_NonObjectInput at jumptarget" markers in the timeline.
Here's a profile from a profile without uBlock Origin: https://cleopatra.io/#report=acda8ed8796464c7a67060edb1f29c67d14f6272
Flags: needinfo?(jdemooij)
> 20% of the JS execution is in sync IPC in contentObserver.shouldLoad() though, and that's because I have uBlock Origin installed

What version of uBlock Origin is this?

Since 1.9.0, for FF 45+ uBO no longer relies on IPC calls in its shouldLoad() handler -- except for when having to handle MAIN_FRAME resources.
(In reply to R. Hill from comment #2)
> Since 1.9.0, for FF 45+ uBO no longer relies on IPC calls in its
> shouldLoad() handler -- except for when having to handle MAIN_FRAME
> resources.

Nice! I can confirm that I no longer see sync IPC during shouldLoad after I restarted my browser. I'm on uBlock Origin 1.9.4, but I only installed it yesterday, just after uninstalling uBlock (non-"Origin"). I hadn't restarted my browser since then, so there might have been some remnant frame scripts in my session. Sorry for wrongly pointing the finger at uBlock Origin.
2 things:
 - Repeated bailouts at identical location are likely bugs, as they highlight that we are not taking new information into account when we recompile.

   Bailout_NonObjectInput is not supposed to be an invalidating bailout, which explains why we need ~10 bailouts before invalidating.  But usually, with these kind of bailouts we would expect the type information recorded by baseline to invalidate the current compiled code, and force an invalidation before we reach the ~10 bailouts.

   So, either:
   * We optimize beyond the recorded information, and ignore the type info recorded by baseline.  In which case the error is located in IonMonkey.
   * We do not record the information, in which case the error is in Baseline.

 - js::jit::IonCache::linkAndAttachStub represents 1.8% of the profile time, on its own.  This highlights that we are likely generating a lot of ICs, and is probably related to the second source of the slow-down.  As we invalidate the compiled code every ~10 bailouts, we drop all generated ICs and start over from scratch.
tl;dr: Ok, the problem is clear in this image, which is control flow graph of one function which has these repeated bailout, and this is definitely a compiler issue.  The issue is that IteratorStart MIR instruction only accept objects, but we try to use it with an undefined value.

We bailout on the instruction 152 Unbox, with the following and explicit data flow:
  2   Constant undefined
  60  Box constant2
  152 Unbox box60
  153 IteratorStart unbox152

So, this will always bailout once this unbox instruction is reached.  Note the IteratorStart instruction no longer dominates a loop, because the body of the loop got removed by Branch Pruning optimization, as it was never reached before.

The TypePolicy added the box & unbox instructions, and LICM hoisted them to the first block, and to the loop pre-header.

What happens is that at the end of IonBuilder, we generated the following instruction set:
  658 Constant undefined
  659 IteratorStart constant658

The constant "undefined" comes from js::jit::IonBuilder::getPropTryNotDefined, within the following for loop:

  for(var o = t.tags.length; o-- >e; ) {
    var a = t.tag = t.tags.pop();
    t.tagName = t.tag.name,
    d(t,"onclosetag",t.tagName);
    var s = {};
    for(var u in a.ns)  // <--- Type inference infers a.ns as being a non-existant property.
      s[u] = a.ns[u];
    var c = t.tags[t.tags.length-1] || t;
    t.opt.xmlns && a.ns !==c.ns && Object.keys(a.ns).forEach(function(e){
      var n = a.ns[e];
      d(t,"onclosenamespace",{prefix:e,uri:n})
    }

I do not think this is the only issue, because the location of this script comes from joust.js (159510-160418), instead of react.min.*.js file.
Assignee: nobody → nicolas.b.pierron
Status: NEW → ASSIGNED
Flags: needinfo?(jdemooij)
This patch fix the case where an MIteratorStart is effectively used with a
non-object input. Previously, the TypePolicy will enfore that we box & unbox
with an object type, and caused us to bailout every time we were called with
non-object inputs without having any way to avoid that in later compilations.

This patch seems to remove most of the repeated bailout issues. There is
another repeated bailout issue, less frequent, that I am going to
investigate right now.
Attachment #8789374 - Flags: review?(jdemooij)
Depends on: 1301690
Comment on attachment 8789374 [details] [diff] [review]
Accept any value as valid input for MIteratorStart.

Review of attachment 8789374 [details] [diff] [review]:
-----------------------------------------------------------------

Nice find!

::: js/src/jsiter.cpp
@@ +1213,5 @@
> +{
> +    RootedValue res(cx, vp);
> +    if (!ValueToIterator(cx, flags, &res))
> +        return nullptr;
> +    return &res.toObject();

Change ValueToIterator to return JSObject* (nullptr on failure), so we don't need the RootedValue here and in other functions? If not please file a follow-up bug :)
Attachment #8789374 - Flags: review?(jdemooij) → review+
(In reply to Jan de Mooij [:jandem] from comment #7)
> Change ValueToIterator to return JSObject* (nullptr on failure), so we don't
> need the RootedValue here and in other functions? If not please file a
> follow-up bug :)

Actually we don't need ValueToIteratorObject then?
Depends on: 1302142
Comment on attachment 8789374 [details] [diff] [review]
Accept any value as valid input for MIteratorStart.

I've landed this patch as part of Bug 1302142, as this current bug has multiple issues which are not related.
Attachment #8789374 - Flags: checkin+
I did a simple experiment, which is to compare the execution with and without IonMonkey disabled.  With IonMonkey disabled, the page is not as responsive as chrome, but does respond ~10 times faster than with Ion enabled.

I will continue to investigate sources of invalidations.
For some reasons cleopatra markers seems optimistic compared to hand-made logging under rr [1] (synchronous compilations), which reports that we are compiling much more than we are executing JS code [2].

The profile in comment 1 reports that we have 391 samples over ~3800 (~ 10%) which have IonBuilder listed in one of the frames, which seems to go in the same direction, and indicates that we are likely to be running in Baseline when we are not in IonBuilder.

[1] https://developer.mozilla.org/en-US/docs/Mozilla/Projects/SpiderMonkey/Hacking_Tips?document_saved=true#Adding_spew_for_Compilations_Bailouts_Invalidations_(from_gdb)
[2] https://people.mozilla.org/~npierron/hearthsim-joust.log
Depends on: 1303399
Depends on: 1313655
Depends on: 1364854
I can no longer reproduce this issue, neither on the current version hosted on the website, nor the version 116 which was deployed when this bug was opened.

Sadly, I do not know precisely which changes fixed the issue.
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.