1355956 - (photon-startup) [meta] Photon - Make Firefox start more quickly

Status: NEW

(Firefox :: General, enhancement)

Description

[Mike Conley (:mconley) (:⚙️)]

This metabug is about trying to defer as much as possible between the point where Firefox starts, and when it's actually ready to show the browser UI and be responsive to user input. 

Bug 1336227 is for showing a window as soon as possible when the Firefox binary starts. This bug works the startup problem from the other direction, and is not at odds with bug 1336227 at all.

Here are some profiles from ehsan.

https://perf-html.io/public/77c989cd274432351ef15a082486627a49eba2c8/calltree/?thread=2
https://perf-html.io/public/2978df5a0760939bc8735d3ec1439f696d5aee6b/calltree/?thread=2
https://perf-html.io/public/11b6c1934622563fbe9736d04ae9d4c78be294ca/calltree/?thread=2

Comment 1

[Florian Quèze [:florian]]

On these profiles, is there an easy way to see at which point the window is first drawn?

Comment 2

[Florian Quèze [:florian]]

Here is a profile from a slow netbook:
https://perf-html.io/public/1ef6024e7ed4470d26d58b8cbed150eec5e5ec95/calltree/?thread=0

Comment 3

[Mike Conley (:mconley) (:⚙️)]

Yet another profile:

https://perf-html.io/public/75cea1de7333eb66c69f39778d9c21d21e3c2b67/calltree/?thread=2

Comment 4

[Florian Quèze [:florian]]

Here is a warm startup profile of the current nightly on a very slow netbook (hence giving a very detailed profile), where it takes 9.9s to reach first paint: https://perfht.ml/2rXVdp1

Comment 5

[Mike Conley (:mconley) (:⚙️)]

TelemetryStartup.js consumes a whopping 400ms here. :/

https://perf-html.io/public/0278318b3bf2973d3bf5d5862efe73e630cfe45c/calltree/?callTreeFilters=prefix-07xVnCwr&range=0.0000_9.8977&thread=0

Comment 6

[Ben Kelly [:bkelly, not reviewing]]

Is there a talos test measuring this use case?  How can I verify new code does not regress this metric?

Comment 7

[Florian Quèze [:florian]]

(In reply to Mike Conley (:mconley) from comment #5)
> TelemetryStartup.js consumes a whopping 400ms here. :/
> 
> https://perf-html.io/public/0278318b3bf2973d3bf5d5862efe73e630cfe45c/
> calltree/?callTreeFilters=prefix-07xVnCwr&range=0.0000_9.8977&thread=0

That's not really new. See bug 1358927 and bug 1367029.

Comment 8

[Florian Quèze [:florian]]

(In reply to Ben Kelly [reviewing, but slowly][:bkelly] from comment #6)
> Is there a talos test measuring this use case?

https://wiki.mozilla.org/Buildbot/Talos/Tests#ts_paint is the closest I think.

Joel, is there something matching this more closely? (startup until we first paint a window, not until we have loaded a page)

> How can I verify new code does not regress this metric?

We are trying to add tests that fail faster than Talos and in a deterministic way. Eg. bug 1358798

Comment 9

[Joel Maher ( :jmaher ) (UTC -8)]

Great question- ts_paint loads a page, but the page is really simple:
https://dxr.mozilla.org/mozilla-central/source/testing/talos/talos/startup_test/tspaint_test.html

I would think we would need markers from the browser (I assume to be added) that we could query if we wanted to measure first window paint.  I am happy to chat on irc or vidyo

Comment 10

[Ben Kelly [:bkelly, not reviewing]]

I think ts_paint covers what I am looking for.  If we are profiling and improving past its measurement point, though, we maybe want to create a new talos test to cover that extended range.

Windows ts_paint does show a general down-and-to-the-right trend over the last 3 months.  So that's encouraging that its reflecting work done here.  Linux and mac are not that clear, though.

Comment 11

[Florian Quèze [:florian]]

Here are another few interesting startup profiles from the June 5th nightly:

- cold startup after reboot: https://perfht.ml/2qZqQKl (16s for first paint)

- warm startup: https://perfht.ml/2qZ8d96 (3.2s for first paint)
https://perfht.ml/2ruwDLf (5s for first paint)

Here are the specs of the machine:
Dell latitude E5420
i3-2330m @ 2.20Ghz (2 cores / 4 threads) - 2nd Generation Intel® Core™
i3 Processors (Launched Q2'11)
4GB of ram
Win7 Pro SP1

This was with a real user profile, gently used for several years.

Comment 12

[Florian Quèze [:florian]]

Some new startup profiles (from the June 20 nightly) to look into:

http://bit.ly/2sRNGIE (current nightly, old netbook) 14s for first paint

http://bit.ly/2ryVxqO (current nightly, quantum ref hardware) cold startup, 10s for first paint!

Comment 13

[Kris Maglione [:kmag]]

(In reply to Florian Quèze [:florian] [:flo] from comment #12)
> http://bit.ly/2ryVxqO (current nightly, quantum ref hardware) cold startup,
> 10s for first paint!

Looks like huge chunks of this come from opening jar files when registering chrome manifests. Bug 1363482 might help with this a bit, but probably not much at the moment. Most of aggregate time comes from opening add-on JARs, and the IO preloader in bug 1363482 currently only deals with Omnijar jars. It also doesn't have any special logic for opening the jars off-main-thread, just reading them.

But we might be able to improve this situation in a follow-up. If we're only dealing with jars from the jar cache, we should be able to add locking to the initial open operation, and do the initial non-thread-safe setup off-main-thread while that lock is held.

Comment 14

[Florian Quèze [:florian]]

(In reply to Florian Quèze [:florian] [:flo] from comment #12)
> Some new startup profiles (from the June 20 nightly) to look into:
> 
> http://bit.ly/2sRNGIE (current nightly, old netbook) 14s for first paint

Same machine, updated profile (July 21st nightly) https://perfht.ml/2vIJPeN - 11.5s for first paint

Comment 15

[Florian Quèze [:florian]]

(In reply to Florian Quèze [:florian] [:flo] from comment #14)
> (In reply to Florian Quèze [:florian] [:flo] from comment #12)
> > Some new startup profiles (from the June 20 nightly) to look into:
> > 
> > http://bit.ly/2sRNGIE (current nightly, old netbook) 14s for first paint
> 
> Same machine, updated profile (July 21st nightly) https://perfht.ml/2vIJPeN
> - 11.5s for first paint

Same slow machine, https://perfht.ml/2uzfGO3 (August 6th nightly), 11s for first paint.

Comment 16

[Florian Quèze [:florian]]

(In reply to Florian Quèze [:florian] [:flo] from comment #15)
> (In reply to Florian Quèze [:florian] [:flo] from comment #14)
> > (In reply to Florian Quèze [:florian] [:flo] from comment #12)
> > > Some new startup profiles (from the June 20 nightly) to look into:
> > > 
> > > http://bit.ly/2sRNGIE (current nightly, old netbook) 14s for first paint
> > 
> > Same machine, updated profile (July 21st nightly) https://perfht.ml/2vIJPeN
> > - 11.5s for first paint
> 
> Same slow machine, https://perfht.ml/2uzfGO3 (August 6th nightly), 11s for
> first paint.

Same machine, August 11th Nightly, https://perfht.ml/2uNt4y7 (9.5s for first paint)

Comment 17

[Florian Quèze [:florian]]

(In reply to Florian Quèze [:florian] [:flo] from comment #16)
> (In reply to Florian Quèze [:florian] [:flo] from comment #15)
> > (In reply to Florian Quèze [:florian] [:flo] from comment #14)
> > > (In reply to Florian Quèze [:florian] [:flo] from comment #12)
> > > > Some new startup profiles (from the June 20 nightly) to look into:
> > > > 
> > > > http://bit.ly/2sRNGIE (current nightly, old netbook) 14s for first paint
> > > 
> > > Same machine, updated profile (July 21st nightly) https://perfht.ml/2vIJPeN
> > > - 11.5s for first paint
> > 
> > Same slow machine, https://perfht.ml/2uzfGO3 (August 6th nightly), 11s for
> > first paint.
> 
> Same machine, August 11th Nightly, https://perfht.ml/2uNt4y7 (9.5s for first
> paint)

Still the same old netbook, 6.6s for first paint today: https://perfht.ml/2eKHRUw
The fastest I've seen yet on this old hardware :-)

Comment 18

[Florian Quèze [:florian]]

Here is a *cold* startup profile of Nightly 2018-02-13 on the same good old netbook: https://perfht.ml/2on6qLL
My early blank window from bug 1336227 appears after 'only' 2.7s. The browser UI is on screen after 18s. And after 65s (when I finally managed to open the gecko profiler), the jank had not stopped yet.

Comment 19

[Florian Quèze [:florian]]

Here is a cold startup profile on the 2018 quantum ref hardware: https://perfht.ml/2NFvKId

Comment 20

[Florian Quèze [:florian]]

Here's an amazingly slow and janky startup profile on the 2018 ref: https://perfht.ml/2R8jLF5 (Windows Update was downloading updates in the background)

Comment 21

[Florian Quèze [:florian]]

Startup profile of today's nightly on the 2018 quantum ref hardware: https://perfht.ml/2CYLHFw (including mainthreadio markers, now that bug 1522497 is fixed)