Bug 1355956 (photon-startup)

[meta] Photon - Make Firefox start more quickly

NEW
Unassigned

Status

()

Firefox
General
a year ago
14 days ago

People

(Reporter: mconley, Unassigned)

Tracking

(Depends on: 22 bugs, Blocks: 2 bugs, {meta})

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [photon-performance] [fxperf])

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
Whiteboard: [photon-performance]
Flags: qe-verify-
Summary: Make Firefox start more quickly → [meta] Make Firefox start more quickly
On these profiles, is there an easy way to see at which point the window is first drawn?

Updated

a year ago
Depends on: 1356561
Depends on: 1360164
Depends on: 1360167
Depends on: 1360171
Depends on: 1360205
Depends on: 1360214
Depends on: 1361087
Depends on: 1361091
Depends on: 1361095
Depends on: 1361500
Depends on: 1362364
Alias: photon-startup
Depends on: 1362382
Depends on: 1362401
Depends on: 1363398
Depends on: 1363421
Blocks: 1363750

Updated

11 months ago
Depends on: 1359031

Updated

11 months ago
Summary: [meta] Make Firefox start more quickly → [meta] Photon - Make Firefox start more quickly

Updated

11 months ago
Depends on: 1301517

Updated

11 months ago
Depends on: 1367450

Updated

11 months ago
Depends on: 1368567
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 6

11 months ago
Is there a talos test measuring this use case?  How can I verify new code does not regress this metric?
(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.
(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
Flags: needinfo?(jmaher)
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
Flags: needinfo?(jmaher)

Comment 10

11 months ago
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.

Updated

11 months ago
Depends on: 1369436

Updated

11 months ago
Depends on: 1369443

Updated

11 months ago
Depends on: 1369456

Updated

11 months ago
Depends on: 1369460

Updated

11 months ago
Depends on: 1369466

Updated

11 months ago
Depends on: 1369467

Updated

11 months ago
Depends on: 1369705

Updated

11 months ago
Depends on: 1369751

Updated

11 months ago
Depends on: 1369761

Updated

11 months ago
Depends on: 1369345

Updated

11 months ago
Depends on: 1370516

Updated

11 months ago
Depends on: 1370609
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.

Updated

11 months ago
Depends on: 1370647

Updated

11 months ago
Depends on: 1370658

Updated

11 months ago
Depends on: 1370667

Updated

11 months ago
Depends on: 1370930

Updated

11 months ago
Depends on: 1369539

Updated

11 months ago
Depends on: 1371335

Updated

11 months ago
Depends on: 1371337

Updated

11 months ago
Depends on: 1371339

Updated

11 months ago
Depends on: 1371340

Updated

11 months ago
Depends on: 1371346

Updated

11 months ago
Depends on: 1371348

Updated

11 months ago
Depends on: 1371350

Updated

11 months ago
Depends on: 1371442

Updated

11 months ago
Depends on: 1371603

Updated

11 months ago
Depends on: 1371860

Updated

10 months ago
Depends on: 1372152

Updated

10 months ago
Depends on: 1372518

Updated

10 months ago
Depends on: 1361102
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!
Depends on: 1374731

Updated

10 months ago
Depends on: 1376892

Updated

10 months ago
Depends on: 1376893
(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.
Depends on: 1363482

Updated

10 months ago
Depends on: 1358907

Updated

10 months ago
Depends on: 1377538

Updated

10 months ago
Depends on: 1378171

Updated

10 months ago
Depends on: 1378727
Depends on: 1380377
Depends on: 1363040
Depends on: 1380011
Depends on: 1381594
Depends on: 1381853
Depends on: 1382248
Depends on: 1383088
(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

Updated

9 months ago
Depends on: 1383210
Depends on: 1356594
Depends on: 1357517
Depends on: 1385952

Updated

9 months ago
Depends on: 1386594
Depends on: 1367910
(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.
Depends on: 1389344
Depends on: 1389443
Depends on: 1389519
(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)
Depends on: 1357205
Depends on: 1390706
Depends on: 1374216
Depends on: 1397743
(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 :-)
Depends on: 1381961
Depends on: 1398287
Depends on: 1399454
Depends on: 1399961
Depends on: 1421456
Depends on: 1003968
Depends on: 1418793
Whiteboard: [photon-performance] → [photon-performance] [fxperf]

Updated

2 months ago
Depends on: 1439519
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.
Depends on: 1449940
You need to log in before you can comment on or make changes to this bug.