Boot time significantly regressed between 1.3 and latest nightly

RESOLVED WONTFIX

Status

RESOLVED WONTFIX
4 years ago
3 years ago

People

(Reporter: asa, Unassigned)

Tracking

({perf, regression})

Firefox Tracking Flags

(Not tracked)

Details

(Reporter)

Description

4 years ago
I don't have precise measurements, but it seems like our boot time has about doubled between Firefox 1.3 and the latest nightly. 

We should be tracking boot time and making sure we don't regress unnecessarily. (I understand more features can mean longer boot.)

Steps to reproduce: 

Install v123 base image. Boot up a few times and notice it's pretty snappy. Install v188 base image. Boot up a few times and notice it's far less snappy. 
Install v188 and shallow flash G/g from m-c/master. Boot up and notice it's even less snappy. 

Expected results: 

We get faster at booting over time, not slower. (I understand this is a somewhat unreasonable expected results, but I suspect that's how most "regular folks" will think of it.)
Mike has been looking at that I think.
Flags: needinfo?(mlee)
Eli has been doing daily boot-time measurements for 2.2 during the last couple weeks. I just spoke with him, and he will modify his tools to get a comparable boot-time measurement for 1.3 as well, and then post his results here. ni?=Eli in the meantime.
Flags: needinfo?(mlee) → needinfo?(eperelman)

Comment 3

4 years ago
I have done some simple boot-time test of master and v1.3, which measures the duration from device reboot until the System creates a performance marker denoting to hide the OS logo splash screen (durations are in milliseconds).

MASTER:

{
  "durations": [
    40339.11083984375,
    45964.690185546875,
    41653.218017578125,
    41392.0361328125,
    40346.505859375,
    41373.51416015625,
    40310.9150390625,
    40878.866943359375,
    40796.783935546875,
    39609.390869140625,
    40937.60107421875,
    41095.47998046875,
    40627.01904296875,
    41171.7119140625,
    41062.912109375,
    40163.40087890625,
    41497.252197265625,
    41107.515869140625,
    40917.031982421875,
    41643.096923828125,
    40029.425048828125,
    41380.97607421875,
    41778.158935546875,
    41405.466064453125,
    41222.02490234375,
    41172.27001953125
  ],
  "average": 41149.091346153844
}

---

v1.3

{
  "durations": [
    29392.4638671875,
    28945.450927734375,
    29191.995849609375,
    29513.10791015625,
    29729.194091796875,
    28784.6279296875,
    29913.217041015625,
    28543.912841796875,
    29172.52490234375,
    29779.822021484375,
    28554.83203125,
    29468.208984375,
    28602.64208984375,
    29804.644775390625,
    29324.613037109375,
    28547.36083984375,
    29878.412109375,
    28676.81689453125,
    29298.113037109375,
    28409.68896484375,
    30434.498046875,
    28648.218017578125,
    29765.886962890625,
    28830.342041015625,
    28893.6181640625,
    28967.43408203125,
    29695.01611328125,
    28709.636962890625,
    29350.708984375,
    29429.2939453125
  ],
  "average": 29208.54344889323
}

---

There is a clear 10-12 *second* difference in the boot time between master and v1.3.
Flags: needinfo?(eperelman)
Thanks Eli. That clearly unacceptable. We need to get back to 1.3 or better in the 2.2 timeframe.
For once it seems that we're unconditionally starting the "Find my device" application as well as the built-in keyboard application during startup while we didn't in the past IIRC.
Thanks Eli! We need to fix this.
1) make sure we don't regress any further. I think your manual testing helps but it would be great if we can automate this asap.
2) fix the regressions. I believe you are working on more datapoints?

Comment 7

4 years ago
Better performance testing automation and additional data is part of my current work with meta bug 1088108, but unfortunately it won't help much when comparing against prior branches.
Personally I won't say this is a regression; we are introducing 90 more scripts after v1.3 (v1.3 script count is 122; master is 212). If we say it's a regression then let's back out all features after v1.3! :)

This is because we never take care of system app modularization but keep dumping features as we want. We never figure out what's necessary during booting and what could be lazily loaded.
If this bug gets priority then please prioritize bug system-app-v2 as well.
https://bugzilla.mozilla.org/show_bug.cgi?id=system-app-v2
FYI: bug 941969 is optimizing system app javascripts into one; I am not sure if your test is toward production build (which will trigger the optimization only) or not.

If yes, that means we cannot live with optimization only; we still need certain runtime loading mechanism to enhance performance.
Depends on: 941969
(In reply to Alive Kuo [:alive][NEEDINFO!] from comment #9)
> FYI: bug 941969 is optimizing system app javascripts into one; I am not sure
> if your test is toward production build (which will trigger the optimization
> only) or not.
> 
> If yes, that means we cannot live with optimization only; we still need
> certain runtime loading mechanism to enhance performance.

Sorry, bug 941969 is backout-ed.
Depends on: 1095034

Updated

4 years ago
Keywords: perf
Note that I found several things affecting launch performance when working on the SMS app:

* number of js files (so for this bug 941696 is useful)
* parsing time (AFAIK this can be made on a separate thread for async=trye scripts)
* executing time: this is really important and this was overseen until now. For a lot of scripts, when we first execute the script, it already does expensive things. Especially, merely accessing mozSettings and other API is costly, but DOM operations can be too.
* initing things: basically same thing than executing, except that's usually done in a "init" function executed only at onload or DOMContentLoaded time. Still we likely do a lot of things here at boot time, as alive suggest.

What do I want to mean exactly? I want to mean that:
* bug 941969 is likely not the main culprit here. Why? Because we regressed while we didn't have bug 941969 previously either
* lazy loading scripts is a good idea, but remember that when you lazy load the file, you execute it too. You may want to move some of the things that are in "execution time" to "init", or even to a later lazy loading when we really use the feature provided by the file.

Updated

4 years ago
Blocks: 1161387
(In reply to Julien Wajsberg [:julienw] (PTO May 1st) from comment #11)
> Note that I found several things affecting launch performance when working
> on the SMS app:
> 
> * number of js files (so for this bug 941696 is useful)
> * parsing time (AFAIK this can be made on a separate thread for async=trye
> scripts)
> * executing time: this is really important and this was overseen until now.
> For a lot of scripts, when we first execute the script, it already does
> expensive things. Especially, merely accessing mozSettings and other API is
> costly, but DOM operations can be too.
> * initing things: basically same thing than executing, except that's usually
> done in a "init" function executed only at onload or DOMContentLoaded time.
> Still we likely do a lot of things here at boot time, as alive suggest.
> 
> What do I want to mean exactly? I want to mean that:
> * bug 941969 is likely not the main culprit here. Why? Because we regressed
> while we didn't have bug 941969 previously either
> * lazy loading scripts is a good idea, but remember that when you lazy load
> the file, you execute it too. You may want to move some of the things that
> are in "execution time" to "init", or even to a later lazy loading when we
> really use the feature provided by the file.

I missed your great comment!
The improvement of startup time is already done in bug 1094759; basically utilizing
1. Read all launch config before the application core starts to make sure nothing blocks the db operation
2. Defined visuallyLoad and load/init/execute only visuallyLoaded related scripts
3. Lazy load all other scripts and mark fullyLoaded once everything is load+started
> 3. Lazy load all other scripts and mark fullyLoaded once everything is load+started

I just want to precise that you maybe don't need to lazy load everything at startup -- maybe some things can wait. (you know better than me what can wait :) ).

Updated

4 years ago
Component: General → Performance
OS: All → Gonk (Firefox OS)
Hardware: All → ARM
Another, more recent regression: bug 1169003
See Also: → bug 1169003

Comment 15

3 years ago
This case is too old. According to numbers is hard to be referred as regression perspective in 2.5, makr this bug as WONTFIX. Please reopen this you have concern or any clue to find root cause.

Latest results [1][2] as attached.

[1] https://raptor.mozilla.org/dashboard/script/measures?var-device=flame-kk&var-memory=319&var-branch=master&var-test=reboot
[2] https://raptor.mozilla.org/dashboard/script/measures?var-device=aries&var-memory=2048&var-branch=master&var-test=reboot
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Resolution: --- → WONTFIX
You need to log in before you can comment on or make changes to this bug.