Closed Bug 1605763 Opened 1 year ago Closed 10 months ago

Multiprocess browser console is slow to open

Categories

(DevTools :: Console, defect, P3)

defect

Tracking

(Fission Milestone:M7, firefox75 fixed)

RESOLVED FIXED
Firefox 75
Fission Milestone M7
Tracking Status
firefox75 --- fixed

People

(Reporter: mossop, Assigned: ochameau)

References

(Blocks 2 open bugs)

Details

Attachments

(5 files)

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.

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

Flags: needinfo?(dtownsend)
Attached image 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.

Flags: needinfo?(dtownsend)

(removed, accidentally posted)

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 }:

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.

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

(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?

(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.

Thanks for answering! Should have been false then.

Tracking for Fission riding the trains to Beta (M7)

Fission Milestone: --- → M7
Priority: -- → P3

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.

Assignee: nobody → poirot.alex
Status: NEW → ASSIGNED
Depends on: 1598022
Attached image 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.

See Also: → 1612585
Duplicate of this bug: 1612585
Depends on: 1613381

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.

Blocks: 1615283
Pushed by apoirot@mozilla.com:
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
Status: ASSIGNED → RESOLVED
Closed: 10 months ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 75
You need to log in before you can comment on or make changes to this bug.