Closed Bug 1171482 Opened 4 years ago Closed 2 years ago

Experiment with queuing mutations before sending the new-mutation event to the client

Categories

(DevTools :: Inspector, enhancement, P3)

40 Branch
enhancement

Tracking

(firefox58 fixed)

RESOLVED FIXED
Firefox 58
Tracking Status
firefox58 --- fixed

People

(Reporter: bgrins, Assigned: jdescottes)

References

(Blocks 2 open bugs)

Details

(Whiteboard: [polish-backlog][difficulty=medium][designer-tools])

Attachments

(4 files, 2 obsolete files)

As we began discussing in Bug 1170848 (see comment 9 - comment 17), there may be a performance gain to be had by queuing up mutations before sending the new-mutations event to the client.  In that process we could also do some pruning of unimportant mutations.

We already do some some queueing mechanism with this._pendingMutations, but a request is sent to the client to fetch the immediately once the first one is retrieved, so we don't have control over how long we wait to queue.  We would have to decide where certain parts of the logic belong (like clearing out multiple attribute changes, which is currently done in getMutations: https://github.com/mozilla/gecko-dev/blob/b3caa9d676228f9dca25a32ff2899b4c2380363d/toolkit/devtools/server/actors/inspector.js#L2712-L2731).
Moving over conversation from Bug 1170848:

(In reply to Patrick Brosset [:pbrosset] [:patrick] [:pbro] from comment #22)
> > Note that there is similar logic in getMutations (which filters out changes
> > on identical attribute names):
> > https://github.com/mozilla/gecko-dev/blob/
> > b3caa9d676228f9dca25a32ff2899b4c2380363d/toolkit/devtools/server/actors/
> > inspector.js#L2712.  I'm not sure if this is doing the exact same thing or
> > something different, but it could make sense to clear them out at this stage
> > instead
> Wow, I had never noticed this! That's great, it means we already skip
> previous attribute mutations for given node/attributeName pairs, which means
> what I proposed doesn't break any assumption, it's already what we do.
> However, I believe we can do better than the filter in getMutations. With
> this, we wait right until the front-end requests the list of mutations to
> filter, while with my approach, the filtering is done earlier, in
> onMutations, so we never need to store large amount of mutations and loop
> through them.

Yeah, that does seem like a better place to store this, before it's ever pushed onto the pending list.  We should just make sure to remove the other logic at the same time.

> > @@ +2791,5 @@
> > > +      let index = this._mutationsToBeHandled.length + i;
> > > +
> > > +      let attributeIndexes = this._attributeChangingNodes.get(change.target);
> > > +      if (!attributeIndexes) {
> > > +        this._attributeChangingNodes.set(change.target, {
> > 
> > you could get a unique string ID to store in here instead of the node by
> > doing something like this:
> > 
> >  let targetActor = this._refMap.get(change.target);
> >  targetActor.actorID
> Yes but I wanted to avoid a lookup in this map, especially if the target
> hasn't been referenced yet, this will force the creation of an actor.

But the thing is, we don't care about (and immediately discard) any mutation that doesn't already have an actor created: https://github.com/mozilla/gecko-dev/blob/ae98e02935d6a5003dcbbae4faed0ae8508714d2/toolkit/devtools/server/actors/inspector.js#L2767-L2770
Whiteboard: [devedition-40][difficulty=medium]
Whiteboard: [devedition-40][difficulty=medium] → [polish-backlog][difficulty=medium]
See Also: → 1244348
Inspector bug triage. Filter on CLIMBING SHOES.
Severity: normal → enhancement
Priority: -- → P3
See Also: → 1289203
For information, there is definitely a perf win in some use cases when reducing the frequency of mutations. In Bug 1366693, we receive hundreds of sequential childList mutations for the same node. The inspector spends a lot of time retrieving the children of this node. This happens during the page load, which goes from a few hundred milliseconds without the inspector to 30 seconds with the inspector.

Adding 500ms of throttling gets the load time of the page down to 1-2 seconds. I added the throttling in the inspector front because it seemed easier at first glance, but I could do it on the actor too.

(In reply to Brian Grinstead [:bgrins] from comment #0)
> would have to decide where certain parts of the logic belong (like clearing
> out multiple attribute changes, which is currently done in getMutations:
> https://github.com/mozilla/gecko-dev/blob/
> b3caa9d676228f9dca25a32ff2899b4c2380363d/toolkit/devtools/server/actors/
> inspector.js#L2712-L2731).

I could not find where this code moved. Anyone knows if we are still doing this?
Blocks: 1366693
Assignee: nobody → jdescottes
Status: NEW → ASSIGNED
See Also: → 1406973
Brian, let me know what you think about simply landing some throttling already. It might be counter intuitive, but it already gives great performance improvements in some use cases such as Bug 1366693. We could add filtering of mutations in a second step.
I sent some of my current patches to talos to see if DAMP would report anything:

https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=133594d24782c6cb6aa76b418d480b287e19f575&newProject=try&newRevision=377746fbf1e2cf74ee2700c89d7999288a4dc0e5&framework=1

The results are pretty bad for DAMP's test case. Either it does nothing, or in the case of the inspector reload, makes things much worse. I think this is due to the throttling added here. Since the markup view finishes its initialization after receiving the new-root mutation, and we wait for this in DAMP, it makes sense to see a performance hit here.

And in the general case it also means that the markup view will take more time to initialize itself on page reload.

We could assign different priorities to mutations. Some of them, such as new-root could be allowed to force a flush of all pending mutations and fire the event.
(In reply to Julian Descottes [:jdescottes] from comment #7)
> I sent some of my current patches to talos to see if DAMP would report
> anything:
> 
> https://treeherder.mozilla.org/perf.html#/
> compare?originalProject=try&originalRevision=133594d24782c6cb6aa76b418d480b28
> 7e19f575&newProject=try&newRevision=377746fbf1e2cf74ee2700c89d7999288a4dc0e5&
> framework=1
> 
> The results are pretty bad for DAMP's test case. Either it does nothing, or
> in the case of the inspector reload, makes things much worse. I think this
> is due to the throttling added here. Since the markup view finishes its
> initialization after receiving the new-root mutation, and we wait for this
> in DAMP, it makes sense to see a performance hit here.


+1, 0.5s delay for simpliest docs looks bad.
Also, shouldn't we use a smaller delay?
I imagine it would also introduce some delay between dynamic page update and markup view displaying them.
It would be interesting to see what is the typical delay between all the mutations you would like to merge.
See what it is on a fast computer, and on a slow one. (I can help with the slow one ;))

Also, complicated/bild.de doesn't highlight any win.
Would you have any simple test case that would highlight the win?
If yes, we should include it in DAMP.
Comment on attachment 8916672 [details]
Bug 1171482 - throttle new-mutations events in inspector actor;

https://reviewboard.mozilla.org/r/187764/#review193182

::: devtools/server/actors/inspector.js:889
(Diff revision 2)
>      this._retainedOrphans = new Set();
>  
>      this.onMutations = this.onMutations.bind(this);
>      this.onFrameLoad = this.onFrameLoad.bind(this);
>      this.onFrameUnload = this.onFrameUnload.bind(this);
> +    this._throttledEmitNewMutations = throttle(() => {

How fast can the inspector process mutations while still keeping minimal perf impact?  (Or restated: what's the smallest delay we can use with minimal perf impact?)

If it's okay to go fairly fast and we only need to limit the overhead of many thousands of simultaneous changes, could we use something like `requestAnimationFrame` (perhaps slower than 60 fps though...) or `requestIdleCallback` to drive the throttling (instead of a fixed delay)?  This would allow the platform to help with scheduling the work.
Comment on attachment 8916672 [details]
Bug 1171482 - throttle new-mutations events in inspector actor;

https://reviewboard.mozilla.org/r/187764/#review193664

::: devtools/server/actors/inspector.js:2341
(Diff revision 2)
> -      this.emit("new-mutations");
> +      /**
> +       * If many mutations are fired at the same time, clients might sequentially request
> +       * children/siblings for updated nodes, which can be costly. By throttling the calls
> +       * to getMutations, duplicated mutations will be ignored.
> +       */
> +      this._throttledEmitNewMutations();

I agree with Ryan that requestIdleCallback may be a better option in this case instead of a fixed throttle timeout. You can also pass a second argument with a max timeout to make sure it happens within N ms.

We'd need to expose `requestIdleCallback` and `cancelIdleCallback` similar to `atob` in builtin-modules.js.

In addition to that, I haven't measured it but I do suspect that we may want to force emitting for certain events like "new-root" to more eagerly get the markup UI displayed when a document is loaded. Something like this might work:

```
emitNewMutations() {
  this.emit("new-mutations");
  cancelIdleCallback(this._idleNewMutationCallback);
  this._idleNewMutationCallback = null;
},

...

queueMutation() {
  ...
  if (needEvent) {
    if (/* it is a new-root event */) {
      this.emitNewMutations();
    } else if (!this._idleNewMutationCallback) {
      this._idleNewMutationCallback = requestIdleCallback(this.emitNewMutations, { timeout: 100 });
    }
  }
},
```
Attachment #8916672 - Flags: review?(bgrinstead)
Thanks for the reviews! It looks like a previous comment was lost.

I don't have the precise timings in mind anymore but on my machine the figures for my test case from Bug 1366693 were roughly:

- no throttling: 25,000 ms
- 100ms throttling: 17,000ms
- 250ms throttling: 4000ms
- 500px throttling: 2000ms
- no devtools: 300ms

(on a recent MBP 15)

So I don't think requestAnimationFrame or requestIdleCallback would really help here? 

With the additional perf improvements I'm doing on the NodeActor in Bug 1366693, the figures were a bit better:
- no throttling: 15,000 ms
- 100ms throttling: 3000ms
- 250ms throttling: 2000ms
- 500px throttling: 1500ms
- no devtools: 300ms
(In reply to J. Ryan Stinnett [:jryans] (use ni?) from comment #9)
> Comment on attachment 8916672 [details]
> Bug 1171482 - throttle new-mutations events in inspector actor;
> 
> https://reviewboard.mozilla.org/r/187764/#review193182
> 
> ::: devtools/server/actors/inspector.js:889
> (Diff revision 2)
> >      this._retainedOrphans = new Set();
> >  
> >      this.onMutations = this.onMutations.bind(this);
> >      this.onFrameLoad = this.onFrameLoad.bind(this);
> >      this.onFrameUnload = this.onFrameUnload.bind(this);
> > +    this._throttledEmitNewMutations = throttle(() => {
> 
> How fast can the inspector process mutations while still keeping minimal
> perf impact?  (Or restated: what's the smallest delay we can use with
> minimal perf impact?)
> 
> If it's okay to go fairly fast and we only need to limit the overhead of
> many thousands of simultaneous changes, could we use something like
> `requestAnimationFrame` (perhaps slower than 60 fps though...) or
> `requestIdleCallback` to drive the throttling (instead of a fixed delay)? 
> This would allow the platform to help with scheduling the work.

On my machine, 250ms is the minimum delay where devtools start being usable.
Flags: needinfo?(bgrinstead)
Flags: needinfo?(bgrinstead)
(In reply to Alexandre Poirot [:ochameau] from comment #8)
> (In reply to Julian Descottes [:jdescottes] from comment #7)
> > I sent some of my current patches to talos to see if DAMP would report
> > anything:
> > 
> > https://treeherder.mozilla.org/perf.html#/
> > compare?originalProject=try&originalRevision=133594d24782c6cb6aa76b418d480b28
> > 7e19f575&newProject=try&newRevision=377746fbf1e2cf74ee2700c89d7999288a4dc0e5&
> > framework=1
> > 
> > The results are pretty bad for DAMP's test case. Either it does nothing, or
> > in the case of the inspector reload, makes things much worse. I think this
> > is due to the throttling added here. Since the markup view finishes its
> > initialization after receiving the new-root mutation, and we wait for this
> > in DAMP, it makes sense to see a performance hit here.
> 
> 
> +1, 0.5s delay for simpliest docs looks bad.
> Also, shouldn't we use a smaller delay?
> I imagine it would also introduce some delay between dynamic page update and
> markup view displaying them.
> It would be interesting to see what is the typical delay between all the
> mutations you would like to merge.
> See what it is on a fast computer, and on a slow one. (I can help with the
> slow one ;))

See comment 11 for some tests with different delays.

> 
> Also, complicated/bild.de doesn't highlight any win.
> Would you have any simple test case that would highlight the win?
> If yes, we should include it in DAMP.

I added a smaller test case on Bug 1366693: https://bug1366693.bmoattachments.org/attachment.cgi?id=8917000
This is really surprising, how many mutations do you have during your test (without merging)?
Is this mostly childList mutations?

I imagine this case highlight an overall slowness in the inspector to update dynamically inserted nodes.
This test case just insert new DOM Elements, right? The slowest it is to update, the longer your timeout will have to be...
In theory, requestIdleCallback would help in these kind of setup, but yes this is just theory. With all our asynchronous code, the event loop may easily be considered free. Having code running in both parent and content process surely confuses requestIdleCallback. I imagine that the content process, where inspector actor lives is easily free.
(In reply to Julian Descottes [:jdescottes] from comment #12)
> On my machine, 250ms is the minimum delay where devtools start being usable.

1) I'd be interested if requestIdleCallback worked better than a normal throttle
2) I would be OK with doing a normal throttle on certain mutation types, as long as we could still eagerly emit new-root (and maybe there are others that we want to be instant).
(In reply to Alexandre Poirot [:ochameau] from comment #14)
> This is really surprising, how many mutations do you have during your test
> (without merging)?
> Is this mostly childList mutations?
> 
> I imagine this case highlight an overall slowness in the inspector to update
> dynamically inserted nodes.
> This test case just insert new DOM Elements, right? The slowest it is to
> update, the longer your timeout will have to be...
> In theory, requestIdleCallback would help in these kind of setup, but yes
> this is just theory. With all our asynchronous code, the event loop may
> easily be considered free. Having code running in both parent and content
> process surely confuses requestIdleCallback. I imagine that the content
> process, where inspector actor lives is easily free.

Yes, the issue is with childList mutations. We get 300 of them, all for the same container.

The server sends roughly one childList mutation at a time. When the markupview receives the childList mutation, it will call walker.children() for the container being updated (always the same in my examples). children() is pretty slow and I think that's the reason why this scenario is very vad, because everytime we get a mutation, we call children() which takes a lot of time on the content process, which prevents it from continuing to run its own code (in my examples, loading the next script, or creating the next child). Mutations that should happen every 5ms show a gap of up to 100ms with DevTools opened.

In total we end up creating ~30,000 NodeActor forms in the process and creating a NodeActor form is quite slow at the moment (have a patch about that in Bug 1366693). Also note that the calls to children() get slower and slower as more children are added.

So we have:
too many childList mutations => too many redundant calls to children() => too many NodeActor forms created

When I was pointed to this bug I thought throttling the mutations could be a good fit. But if that's not the case and if we only want to buffer on very short intervals, then we could think about making the markup view smarter to avoid redundant calls to children(), since it is a costly API.

(In reply to Brian Grinstead [:bgrins] from comment #15)
> (In reply to Julian Descottes [:jdescottes] from comment #12)
> > On my machine, 250ms is the minimum delay where devtools start being usable.
> 
> 1) I'd be interested if requestIdleCallback worked better than a normal
> throttle
> 2) I would be OK with doing a normal throttle on certain mutation types, as
> long as we could still eagerly emit new-root (and maybe there are others
> that we want to be instant).

I'll try to create a patch with requestIdleCallback to compare.
> Mutations that should happen every 5ms show a gap of up to 100ms
> with DevTools opened.

I think we end up in a chicken/egg kind of problem here.
May be you could proceed immediately with a small throttle and come back to this after fixing the rest. (you can always keep bug 1366693 to ensure we make it fast by end of Q4 ;))

In comment 11, if you consider only 100ms throttle, you highlight a 5x win with your additional fix, whereas it is only 1.5x win with current tip. So I believe a small throttle will still be a win after various other perf fixes.

> In total we end up creating ~30,000 NodeActor forms in the process

Against attachment 8917000 [details]? That's crazy, it only creates 300 elements and is almost empty markup view !!! !! !
If we fetch all children again on every new script, we can potential fetch 1+2+3+...+300=45150 of them...
This patch is using requestIdleCallback. Was not sure how to expose it from builtin-modules so I just used the root windows of the inspector actor here.

It improves the situation a bit.

With https://bug1366693.bmoattachments.org/attachment.cgi?id=8917000 (creating div every 5ms) we go from 12 seconds to 8 seconds.

With the script load test case (load_issue.zip attached to Bug 1366693) we go from 22 seconds to 20 seconds.

If I use my perf patch from Bug 1366693, the DIV scenario goes to 2 seconds. However, the script scenario only goes down to 11 seconds. In my opinion waiting for more than 10 seconds to reload a page is still not OK.
(there was a small typo in the previous patch, did not impact the timings)
Attachment #8919686 - Attachment is obsolete: true
I think it makes sense. requestIdleCallback may fire early on the content process if that's the parent process being blocked by inspector uI.

I would suggest moving on with a small delay, like 100ms and work on other fixes that will make it finally usage.

As you said:

> With the additional perf improvements I'm doing on the NodeActor in Bug 1366693, the figures were a bit better:
> - 100ms throttling: 3000ms

^-- this looks good to me and I imagine we can find some other fixes on top of this.
(In reply to Julian Descottes [:jdescottes] from comment #18)
> Created attachment 8919686 [details] [diff] [review]
> use requestIdleCallback to fire new-mutations events
> 
> This patch is using requestIdleCallback. Was not sure how to expose it from
> builtin-modules so I just used the root windows of the inspector actor here.

In case we need it later, here's what you can do to export `requestIdleCallback` and `cancelIdleCallback` instead of relying on the content window:

1) Import from Cu.getGlobalForObject(jsmScope) just like `atob` here:
https://dxr.mozilla.org/mozilla-central/source/devtools/shared/builtin-modules.js#21-22
2) Export it as a global: https://dxr.mozilla.org/mozilla-central/source/devtools/shared/builtin-modules.js#217
(In reply to Brian Grinstead [:bgrins] from comment #24)
> (In reply to Julian Descottes [:jdescottes] from comment #18)
> > Created attachment 8919686 [details] [diff] [review]
> > use requestIdleCallback to fire new-mutations events
> > 
> > This patch is using requestIdleCallback. Was not sure how to expose it from
> > builtin-modules so I just used the root windows of the inspector actor here.
> 
> In case we need it later, here's what you can do to export
> `requestIdleCallback` and `cancelIdleCallback` instead of relying on the
> content window:
> 
> 1) Import from Cu.getGlobalForObject(jsmScope) just like `atob` here:
> https://dxr.mozilla.org/mozilla-central/source/devtools/shared/builtin-
> modules.js#21-22

That's what I tried but requestIdleCallback is undefined here. Also I suppose requestIdleCallback is relative to the current process in which it runs so I'm not sure how a single version of this method can really be shared as a global?
Played around adding a new test for DAMP. 

I used a faster version of the test case creating DIVs (with only 50 elements created). On my machine the test averages at 800ms without the throttling patch and below 400ms with it, so DAMP should be able to detect improvements regressions there.

https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=223a706f4fece138998d5b293c74f619445724c6&newProject=try&newRevision=36ed7968985475910e870dff72f293497df1bad7&framework=1
Comment on attachment 8919749 [details]
Bug 1171482 - add DAMP test for inspector mutations;

https://reviewboard.mozilla.org/r/190688/#review195896

::: testing/talos/talos/tests/devtools/addon/content/damp.js:297
(Diff revision 1)
> +
> +    let time = yield new Promise(resolve => {
> +      messageManager.addMessageListener("done", (e) => {
> +        resolve(e.data);
> +      });
> +    });

You should also wait for inspector UI events, like inspector-updated or something. Otherwise the panel will most likely still update after the test is done and possibly pollute the next ones.
(In reply to Alexandre Poirot [:ochameau] from comment #31)
> Comment on attachment 8919749 [details]
> Bug 1171482 - add DAMP test for inspector mutations
> 
> https://reviewboard.mozilla.org/r/190688/#review195896
> 
> ::: testing/talos/talos/tests/devtools/addon/content/damp.js:297
> (Diff revision 1)
> > +
> > +    let time = yield new Promise(resolve => {
> > +      messageManager.addMessageListener("done", (e) => {
> > +        resolve(e.data);
> > +      });
> > +    });
> 
> You should also wait for inspector UI events, like inspector-updated or
> something. Otherwise the panel will most likely still update after the test
> is done and possibly pollute the next ones.

Even knowing we are closing the toolbox after the test? We normally stop listening to mutations and to update the UI when we destroy the inspector.
(In reply to Julian Descottes [:jdescottes] from comment #32)
> Even knowing we are closing the toolbox after the test? We normally stop
> listening to mutations and to update the UI when we destroy the inspector.

Yes:
* otherwise it makes close test very fuzzy,
* you aren't really ensuring that the inspector itself updates quickly.
Comment on attachment 8916672 [details]
Bug 1171482 - throttle new-mutations events in inspector actor;

https://reviewboard.mozilla.org/r/187764/#review195880

Generally looks good, but see comments inline

::: devtools/server/actors/inspector.js:2348
(Diff revision 3)
> +      /**
> +       * If many mutations are fired at the same time, clients might sequentially request
> +       * children/siblings for updated nodes, which can be costly. By throttling the calls
> +       * to getMutations, duplicated mutations will be ignored.
> +       */
> +      this._throttledEmitNewMutations();

What happens with an active throttled call if this actor is destroyed?  Do we need to protect against that case in `_emitNewMutations`?

::: devtools/server/actors/inspector.js:2355
(Diff revision 3)
> +      this._emitNewMutations();
>      }
>    },
>  
> +  _emitNewMutations: function () {
> +    this._waitingForGetMutations = true;

Nit: instead of introducing the `_waitingForGetMutations` variable and keeping it in sync, could we update this function to check `if (this._pendingMutations.length > 0)` before doing the emit? Tracing through this, I don't think it would change the behavior compared with the early return on `this._waitingForGetMutations` in `queueMutation`, and IMO it'd be easier to folow.
Attachment #8916672 - Flags: review?(bgrinstead) → review+
(In reply to Julian Descottes [:jdescottes] from comment #25)
> (In reply to Brian Grinstead [:bgrins] from comment #24)
> > (In reply to Julian Descottes [:jdescottes] from comment #18)
> > > Created attachment 8919686 [details] [diff] [review]
> > > use requestIdleCallback to fire new-mutations events
> > > 
> > > This patch is using requestIdleCallback. Was not sure how to expose it from
> > > builtin-modules so I just used the root windows of the inspector actor here.
> > 
> > In case we need it later, here's what you can do to export
> > `requestIdleCallback` and `cancelIdleCallback` instead of relying on the
> > content window:
> > 
> > 1) Import from Cu.getGlobalForObject(jsmScope) just like `atob` here:
> > https://dxr.mozilla.org/mozilla-central/source/devtools/shared/builtin-
> > modules.js#21-22
> 
> That's what I tried but requestIdleCallback is undefined here. Also I
> suppose requestIdleCallback is relative to the current process in which it
> runs so I'm not sure how a single version of this method can really be
> shared as a global?

Huh, I thought I checked that it worked locally before leaving the comment, but I must be misremembering.
(In reply to Alexandre Poirot [:ochameau] from comment #33)
> (In reply to Julian Descottes [:jdescottes] from comment #32)
> > Even knowing we are closing the toolbox after the test? We normally stop
> > listening to mutations and to update the UI when we destroy the inspector.
> 
> Yes:
> * otherwise it makes close test very fuzzy,

What do you mean by fuzzy here. Are we measuring the closing time in this test?

> * you aren't really ensuring that the inspector itself updates quickly.

That's not what I intended to do with this test, but I can try to modify it to do that. 
Will be interesting to see if the test variance is acceptable when measuring the inspector update performance.
(In reply to Julian Descottes [:jdescottes] from comment #36)
> (In reply to Alexandre Poirot [:ochameau] from comment #33)
> > (In reply to Julian Descottes [:jdescottes] from comment #32)
> > > Even knowing we are closing the toolbox after the test? We normally stop
> > > listening to mutations and to update the UI when we destroy the inspector.
> > 
> > Yes:
> > * otherwise it makes close test very fuzzy,
> 
> What do you mean by fuzzy here. Are we measuring the closing time in this
> test?

Oh. I was confused with "_getToolLoadingTests" tests. You are right, we won't measure toolbox close time.
Toolbox destruction may clean up things and we may stop doing things and so may not pollute the test after this one.
But I would prefer to be sure we won't!

(from my experience on bug 1407826 it looks like a couple of tests are still doings things up to 2s after each step,
 so it looks like it is very easy to let things still execute after the test is done)
Thanks for having a look!

(In reply to Brian Grinstead [:bgrins] from comment #34)
> Comment on attachment 8916672 [details]
> Bug 1171482 - throttle new-mutations events in inspector actor
> 
> https://reviewboard.mozilla.org/r/187764/#review195880
> 
> Generally looks good, but see comments inline
> 
> ::: devtools/server/actors/inspector.js:2348
> (Diff revision 3)
> > +      /**
> > +       * If many mutations are fired at the same time, clients might sequentially request
> > +       * children/siblings for updated nodes, which can be costly. By throttling the calls
> > +       * to getMutations, duplicated mutations will be ignored.
> > +       */
> > +      this._throttledEmitNewMutations();
> 
> What happens with an active throttled call if this actor is destroyed?  Do
> we need to protect against that case in `_emitNewMutations`?
> 

Good point, we should check to see if the actor was already destroyed in _emitNewMutations. 

> ::: devtools/server/actors/inspector.js:2355
> (Diff revision 3)
> > +      this._emitNewMutations();
> >      }
> >    },
> >  
> > +  _emitNewMutations: function () {
> > +    this._waitingForGetMutations = true;
> 
> Nit: instead of introducing the `_waitingForGetMutations` variable and
> keeping it in sync, could we update this function to check `if
> (this._pendingMutations.length > 0)` before doing the emit? Tracing through
> this, I don't think it would change the behavior compared with the early
> return on `this._waitingForGetMutations` in `queueMutation`, and IMO it'd be
> easier to folow.

Even if pendingMutations.length > 0, we might already have fired the new-mutations event.

There is a small async roundtrip to exchange mutations between the front and the actor. If we receive two mutations successively and they are not throttled, we might call _emitNewMutations twice before the consumer had the opportunity to get the mutations. The first roundtrip will return mutations, the second roundtrip will return an empty array (and was therefore not needed).

Before we used to simply fire the event if the length was 0 before adding the new mutations. But mixing throttled and non-throttled mutations makes this trick invalid. Does that make sense?

Made me realize I need to cancel a throttled emitNewMutations, in case a non-throttled mutation goes through in the meantime. 
Our throttle util doesn't support cancelling at the moment, alternatively I could guard emitNewMutations with 

  if (!this._waitingForGetMutations && this.pendingMutations.length > 0)

With this guard we can remove the early return from `queueMutation`. So handling _waitingForGetMutations will be restricted to firing the event and receiving the call to getMutation, which might make it easier to understand (note there is still a tiny behavior change, but this one should only impact the actor).
Brian: what do you think specifically about "only throttling childList mutations" compared to "throttle everything except newRoot". Which approach makes more sense in your opinion? The first one is safer but might not fix a large variety of issues, the second approach should have more impact.
Flags: needinfo?(bgrinstead)
(In reply to Alexandre Poirot [:ochameau] from comment #37)
> (In reply to Julian Descottes [:jdescottes] from comment #36)
> > (In reply to Alexandre Poirot [:ochameau] from comment #33)
> > > (In reply to Julian Descottes [:jdescottes] from comment #32)
> > > > Even knowing we are closing the toolbox after the test? We normally stop
> > > > listening to mutations and to update the UI when we destroy the inspector.
> > > 
> > > Yes:
> > > * otherwise it makes close test very fuzzy,
> > 
> > What do you mean by fuzzy here. Are we measuring the closing time in this
> > test?
> 
> Oh. I was confused with "_getToolLoadingTests" tests. You are right, we
> won't measure toolbox close time.
> Toolbox destruction may clean up things and we may stop doing things and so
> may not pollute the test after this one.
> But I would prefer to be sure we won't!
> 
> (from my experience on bug 1407826 it looks like a couple of tests are still
> doings things up to 2s after each step,
>  so it looks like it is very easy to let things still execute after the test
> is done)

Thanks for the clarification! I'm trying out a new test relying on the inspector's markupmutation event. This seems to be quite stable so I'm going to use that. Simply waiting to receive N markupmutation events, N being the number of children added.

Unsurprisingly, DAMP reports less "win" with this new approach since the 100ms of throttling compete with the content script going 300ms faster. Currently trying to stress the inspector a bit more in my test by doing more mutations (150 rather than 50) and then dividing the result. But when under too much stress, the 100ms throttling are not so efficient (as shown in my tests earlier). I'll still fiddle with this for a bit and will reupload for review. 

Some damp results:
- 150 mutations, baseline vs 100ms throttling: https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=73a348ec03464ac2b126599f983b3d02a24efb0a&newProject=try&newRevision=068bb2a04b71819d8f58a795d449316d61b9a7b4&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&framework=1
- 150 mutations, baseline vs 100ms throttling + node actor improvements: https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=73a348ec03464ac2b126599f983b3d02a24efb0a&newProject=try&newRevision=2c8bae6862aedeb56ea44072efd78a388be45698&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&framework=1
(In reply to Julian Descottes [:jdescottes] from comment #39)
> Brian: what do you think specifically about "only throttling childList
> mutations" compared to "throttle everything except newRoot". Which approach
> makes more sense in your opinion? The first one is safer but might not fix a
> large variety of issues, the second approach should have more impact.

In general, throttling mutations should be 'safe' in that the frontend already expects to receive multiple mutations at a time (due to the lag between emitting and receiving). I believe the risk is mostly perf-related in that we would throttle away a mutation that should happen ASAP to provide user feedback (i.e. a new page is loaded or a page is unloaded).

Certainly attribute changes and character data should be throttled as well, since we can easily imagine these happening in a loop on the page.  But I'm not so sure about things like newRoot, frameLoad, documentUnload, pseudoClassLock. I haven't looked closely at each but I suspect that we want these things to happen immediately. Maybe we should whitelist a set of 'immediate' mutations.
Flags: needinfo?(bgrinstead)
Attachment #8919687 - Attachment is obsolete: true
Attachment #8919749 - Flags: review?(poirot.alex)
Thanks for the feedback Brian!

Updated the implementation according to comment 41.

Regarding the new DAMP test here are a few compare pages:
- baseline vs throttling (20% improvement)
  https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=0e28117a9e4a522b8a0b8edd2d18e0aa2b6412cb&newProject=try&newRevision=0f04a755a3cc151192b383eacbd597c8dfbc6409&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&framework=1

- baseline vs throttling + additional fixes (70% improvement)
  https://treeherder.mozilla.org/perf.html#/comparesubtest?originalProject=try&originalRevision=0e28117a9e4a522b8a0b8edd2d18e0aa2b6412cb&newProject=try&newRevision=17d49f35f1221d4520ca73a080a6b487fca03564&originalSignature=edaec66500db21d37602c99daa61ac983f21a6ac&newSignature=edaec66500db21d37602c99daa61ac983f21a6ac&framework=1

I ended up using 100 mutations for the test. After this lands this will give us a DAMP test around 2000ms (less than 1000ms after all the fixes are in). I can divide the result by 2 if we are afraid this might disturb DAMP results.
(In reply to Julian Descottes [:jdescottes] from comment #46)
> I ended up using 100 mutations for the test. After this lands this will give
> us a DAMP test around 2000ms (less than 1000ms after all the fixes are in).
> I can divide the result by 2 if we are afraid this might disturb DAMP
> results.

I was assuming that we needed to worry about that, but I may have misunderstood how the summarization works. Joel, is there risk that adding a new subtest for DAMP that has a much bigger value than other subtests?  i.e. will that make regressions on the smaller values harder to detect?
Flags: needinfo?(jmaher)
Whiteboard: [polish-backlog][difficulty=medium] → [polish-backlog][difficulty=medium][designer-tools]
we use a geometric mean for all the subtests which means that smaller values will have a reasonable chance of affecting the overall metric.  It isn't perfect, but it does help neutralize the effects of subtests with widely different values.  I would really like to see damp broken into a few smaller benchmarks which might remove a lot of the concerns here.
Comment on attachment 8919695 [details]
Bug 1171482 - wait for 2 distinct mutations in markup test;

https://reviewboard.mozilla.org/r/190604/#review196638
Attachment #8919695 - Flags: review?(pbrosset) → review+
Comment on attachment 8919749 [details]
Bug 1171482 - add DAMP test for inspector mutations;

https://reviewboard.mozilla.org/r/190688/#review196682

Thanks!
And welcome to DAMP contributor list :)

::: testing/talos/talos/tests/devtools/addon/content/damp.js:350
(Diff revision 2)
> +            content.setTimeout(() => addElement(index + 1), ${DELAY});
> +          };
> +          addElement(0);
> +        });
> +      }`
> +    ) + ")()", true);

nit: loadFrameScript's allowDelayedLoad argument should be false. No need to apply it to any other document other than the current one. (really a nit!)
http://searchfox.org/mozilla-central/source/dom/base/nsIMessageManager.idl#437-445

::: testing/talos/talos/tests/devtools/addon/content/damp.js:752
(Diff revision 2)
>          return;
>        }
>      }
> +    if (config.subtests.indexOf("inspectorMutations") > -1) {
> +      tests = tests.concat(this._inspectorMutationsTest);
> +    }

This is no longer necessary thanks to my recent patch with --subtests.
Attachment #8919749 - Flags: review?(poirot.alex) → review+
Attachment #8919694 - Flags: review?(bgrinstead)
Comment on attachment 8916672 [details]
Bug 1171482 - throttle new-mutations events in inspector actor;

Brian: flagging you for final review. I used a whitelist of "direct mutations" listing the ones you mentioned.
Attachment #8916672 - Flags: review?(bgrinstead)
Comment on attachment 8919694 [details]
Bug 1171482 - extract throttle to dedicated util;

https://reviewboard.mozilla.org/r/190602/#review197284
Attachment #8919694 - Flags: review?(bgrinstead) → review+
Comment on attachment 8916672 [details]
Bug 1171482 - throttle new-mutations events in inspector actor;

https://reviewboard.mozilla.org/r/187764/#review197308

::: devtools/server/actors/inspector.js:2344
(Diff revision 6)
> -      this.emit("new-mutations");
> +    // to retrieve them.
> +    if (this._waitingForGetMutations) {
> +      return;
> +    }
> +
> +    if (IMMEDIATE_MUTATIONS.indexOf(mutation.type) != -1) {

Nit: `IMMEDIATE_MUTATIONS.includes(mutation.type)`.  Or, turn it into an object and check `IMMEDIATE_MUTATIONS[mutation.type]`.
Attachment #8916672 - Flags: review?(bgrinstead) → review+
Pushed by jdescottes@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/502b8b343daf
add DAMP test for inspector mutations;r=ochameau
https://hg.mozilla.org/integration/autoland/rev/9ac26a4888e4
extract throttle to dedicated util;r=bgrins
https://hg.mozilla.org/integration/autoland/rev/cd52c19b1fca
wait for 2 distinct mutations in markup test;r=pbro
https://hg.mozilla.org/integration/autoland/rev/60ff8f836495
throttle new-mutations events in inspector actor;r=bgrins
:jdescottes, did you notice local performance improvements with the version that landed here?

Here's what I am seeing locally using the test page[1]:

+------------------+--------------------+-------------------+
|                  | Before bug 1171482 | After bug 1171482 |
+------------------+--------------------+-------------------+
| Inspector Closed |        1.7s        |       1.7s        |
|  Inspector Open  |      3 - 4.8s      |    4.8 - 5.5s     |
+------------------+--------------------+-------------------+

It seems like these patches make the inspector open case slightly slower, but it's possible something else is at play.

[1]: https://bug1366693.bmoattachments.org/attachment.cgi?id=8917000
Flags: needinfo?(jdescottes)
That's really surprising! 

So I do see roughly a 50% improvement (tested on central with the actual patches that landed)
- with the patch -> between 6 and 7 seconds (did 5 reloads)
- without the patch -> between 12 and 13 seconds (5 reloads as well)

DAMP also shows improvements for the new test case added. See https://treeherder.mozilla.org/perf.html#/compare?originalProject=try&originalRevision=639956abc5e52cfd3cdc4f35d816588a4975289a&newProject=try&newRevision=d4d5e9b9e9dd814dfeda50fadbd5fd7ca4798615&framework=1
- linux: 27% faster
- windows: 18% faster

We discussed a bit yesterday and your test machine (2016 MBP) is more powerful than mine (2015 MBP) and more powerful than DAMP hardware for sure.
I think your machine is too powerful be impacted by the "bottleneck" situation which I fix here where calls to children() are slowing down the actual content page. I'm surprised that it slows down the scenario for you still.

Maybe in your case the throttling queues too many mutations and actually makes things worst? 

If you have time for some more tests could you:
- try to use a lower/higher throttling delay and see how it impacts the performance?
- import the patch at https://hg.mozilla.org/try/rev/b23c60cf8dc82d7c533c9502a02fddec21e15c89 and see if it improves anything?

Thanks!
Flags: needinfo?(jdescottes) → needinfo?(jryans)
Okay, well, maybe my previous experiment was botched somehow?  I got very different results today.  

In comment 63, I was jumping between Nightly builds, supposedly with and without these patches.  Maybe I did something wrong?  Not sure.

This time, I pulled down today's autoland for the throttle case, and reverted only this bug for the no throttle case.

+--------------------+--------------------+-------------------+
|                    |  Inspector Closed  |   Inspector Open  |
+--------------------+--------------------+-------------------+
| Revert throttle    |        1.7s        |   9.78 - 11.95s   |
| 100ms throttle     |        1.7s        |   4.76 - 5.49s    |
| 100ms w/ form memo |        1.7s        |   1.83 - 1.89s    |
| 500ms throttle     |        1.7s        |   2.0  - 2.22s    |
+--------------------+--------------------+-------------------+

So, hopefully that's more in line with what you were seeing?

Looks like 100ms plus the form memo patch gets pretty close to zero impact!
Flags: needinfo?(jryans)
The DAMP test added here got faster after Bug 1412538 landed.

Locally for attachment 8917000 [details] I went from 6-7s to 3-4s. Less impactful on my real life scenario (17s to 13s) but still a sensible improvement.
See Also: → 1412538
Product: Firefox → DevTools
You need to log in before you can comment on or make changes to this bug.