1605763 - Multiprocess browser console is slow to open

Status: RESOLVED FIXED

(DevTools :: Console, defect, P3)

Description

[Dave Townsend [:mossop]]

The new multiprocess browser console seems much slower to open than the old one. My rough timing is that the old console becomes usable almost immediately after the window opens. The new console however shows an empty console for 3-4 seconds before it becomes usable.

Comment 1

[:Harald Kirschner :digitarald]

Dave, could you attach a profiler.firefox.com recording of what you see?

Comment 2

[:Harald Kirschner :digitarald]

Attachment: image.png

My take (slow on my default profile, but faster in my profiling profile): https://perfht.ml/2ZkAsSI

Following up on a hunch, it does get worse with each tab open (tested with 8): https://perfht.ml/34QLqAn (shown in screenshot)

It looks like the Browser Console is blocking the setting up a console server in each tab to get cached messages, even if the Content Messages checkbox is off.

Comment 3

[:Harald Kirschner :digitarald]

(removed, accidentally posted)

Comment 4

[Julian Descottes [:jdescottes]]

Something is very clear on this profile: all the servers are created sequentially instead of being created in parallel.
There are several spots where this should be easy to fix by using Promise.all instead of for() { await }:

• calling onTargetAvailable on all existing targets: https://searchfox.org/mozilla-central/rev/94a19efaaf1eefa58e36047f73b49ed0c5162163/devtools/shared/resources/target-list.js#402-407
• calling getTarget for all frame descriptors: https://searchfox.org/mozilla-central/rev/94a19efaaf1eefa58e36047f73b49ed0c5162163/devtools/shared/resources/target-list.js#95
• calling getTarget for all process descriptors: https://searchfox.org/mozilla-central/rev/94a19efaaf1eefa58e36047f73b49ed0c5162163/devtools/shared/resources/target-list.js#51

Comment 5

[Julian Descottes [:jdescottes]]

I pushed a patch on try at https://treeherder.mozilla.org/#/jobs?repo=try&revision=abbdeefe418658b13ec165096e0880a29aaa65f9, in case anyone wants to give it a spin. It speeds up the server creation part on my locally recorded profiles, but it's a bit too fast on my machine anyway to say if that's a real sizable improvement. It still seems slower than the regular browser console.

Comment 6

[Dave Townsend [:mossop]]

I was testing in a local artifact build so may not have been fully optimised and I was seeing the numbers I stated with just one tab open. On a regular nightly it is somewhat faster

Comment 7

[Julian Descottes [:jdescottes]]

(In reply to Dave Townsend [:mossop] (he/him) from comment #6)

I was testing in a local artifact build so may not have been fully optimised and I was seeing the numbers I stated with just one tab open. On a regular nightly it is somewhat faster

Any chance you had "Show content messages" enabled in the Browser Console settings when you tested with your local build?

Comment 8

[Dave Townsend [:mossop]]

(In reply to Julian Descottes [:jdescottes] from comment #7)

(In reply to Dave Townsend [:mossop] (he/him) from comment #6)

I was testing in a local artifact build so may not have been fully optimised and I was seeing the numbers I stated with just one tab open. On a regular nightly it is somewhat faster

Any chance you had "Show content messages" enabled in the Browser Console settings when you tested with your local build?

This was a fresh testing profile so it would have been whatever the default for that is.

Comment 9

[Julian Descottes [:jdescottes]]

Thanks for answering! Should have been false then.

Comment 10

[Chris Peterson [:cpeterson]]

Tracking for Fission riding the trains to Beta (M7)

Comment 11

[Alexandre Poirot [:ochameau]]

I think this code is the main culprit:
https://searchfox.org/mozilla-central/rev/4537228c0a18bc0ebba2eb7f5cbebb6ea9ab211c/devtools/client/webconsole/browser-console.js#77-78

      await this.targetList.startListening(TargetList.ALL_TYPES);
      await super.init();

Where we first connect to all the processes, before initializing the console UI.
We can easily swap these two lines because of the following exception:
JavaScript error: resource://devtools/shared/resources/target-list.js, line 390: Error: watchTargets was called for a target type (process) that isn't being listened to
But bug 1598022 and especially this patch https://phabricator.services.mozilla.com/D57009 should help revisiting this code.

Comment 12

[Alexandre Poirot [:ochameau]]

Attachment: Bug 1605763 - Initialize browser console UI before attaching to all process targets.

Comment 13

[Robin Steuber (she/her) [:bytesized]]

Attachment: devtools hang.PNG

I was about to file a bug, but I'm suspicious that the behavior I am seeing is really just a part of this bug so I thought I would post here first. I don't see this problem on my Nightly install, but when I open the Browser Toolbox in my local build, I see it frequently. This is what happens:

• I build an un-optimized build of Firefox, using these build options:

ac_add_options --enable-release
ac_add_options --enable-debug-symbols
ac_add_options --disable-optimize

• I open the browser toolbox
• I see the browser toolbox mostly load (I say "mostly" because certain things like the sources list in the debugger have not loaded yet)
• The toolbox gets taken over by the "Browser Toolbox connection status" pane (see attached image)
• I sometimes have a few moments of responsiveness before the toolbox becomes completely unresponsive

The problem is somewhat inconsistent and seems to be worse on certain tabs of the toolbox. On the console pane I see it less often, and when I do see the hang it doesn't seem last as long. On the debugger pane, I see it most of the time and the hang lasts for multiple minutes.

This is with only one or two tabs open. I am running Windows 10. Let me know if you would like me to file a separate bug for this issue.

Comment 15

[Alexandre Poirot [:ochameau]]

Attachment: Bug 1605763 - Wait for all target-available listeners resolution when calling TargetList.startListeners.

Doing this helps ensuring that all async work done in panels,
when attaching to the top level target, to fetch already existing resources,
is fully completed before the test ends.

Comment 16

[Alexandre Poirot [:ochameau]]

Attachment: Bug 1605763 - Emit 'web-console-created' after the BrowserConsole is fully loaded.

Comment 17

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/4158322d4fdb
Wait for all target-available listeners resolution when calling TargetList.startListeners. r=jdescottes
https://hg.mozilla.org/integration/autoland/rev/f855239e55ab
Initialize browser console UI before attaching to all process targets. r=nchevobbe
https://hg.mozilla.org/integration/autoland/rev/e1125b80f860
Emit 'web-console-created' after the BrowserConsole is fully loaded. r=nchevobbe

Comment 18

[Oana Pop-Rus]

https://hg.mozilla.org/mozilla-central/rev/4158322d4fdb
https://hg.mozilla.org/mozilla-central/rev/f855239e55ab
https://hg.mozilla.org/mozilla-central/rev/e1125b80f860