1210867 - FmRadio app launch time regression from 2.5

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Gaia::FMRadio, defect, P2)

Description

[Hema Koka [:hema]]

FM v2.2 cold launch: 604ms
FM current cold launch: 783ms (~175ms regression)
FM v2.2 USS: 10.37MB
FM current USS: 10.51MB (acceptable)

There were no big changes to this app in 2.5, so I doubt if it is an app issue here.

Comment 1

[Hema Koka [:hema]]

[Blocking Requested - why for this release]: regression from previous release by over 100ms

Comment 3

[Zibi Braniecki [:zbraniecki][:gandalf]]

We retested using new baseline and the regression looks slightly different:
https://gist.github.com/eliperelman/b81a27b7f7f3b3f75f49#fm-radio

v2.2 visuallyLoaded 	690.433 	41.140 	705.155
master visuallyLoaded 	768.067 	80.399 	796.837
v2.2 uss 	        8.613 	0.043 	8.629
master uss 	        10.360 	0.028 	10.370

I tested the impact of l10n -> l20n change in FM (which is one of the only meaningful changes in 2.5):

master:

| Metric                | Mean    | Median  | Min    | Max    | StdDev | 95% Bound |
| --------------------- | ------- | ------- | ------ | ------ | ------ | --------- |
| navigationLoaded      | 574.350 | 572.500 | 507    | 692    | 39.984 | 591.874   |
| navigationInteractive | 755.900 | 737.500 | 706    | 869    | 44.633 | 775.461   |
| visuallyLoaded        | 756.350 | 737.500 | 707    | 869    | 44.560 | 775.879   |
| contentInteractive    | 756.800 | 738.500 | 707    | 870    | 44.666 | 776.376   |
| fullyLoaded           | 935.350 | 907.500 | 874    | 1184   | 74.784 | 968.125   |
| uss                   | 10.136  | 10.139  | 10.109 | 10.160 | 0.014  | 10.142    |
| pss                   | 14.100  | 14.107  | 14.046 | 14.144 | 0.026  | 14.112    |
| rss                   | 28.460  | 28.457  | 28.430 | 28.508 | 0.020  | 28.468    |

using l10n.js:
| Metric                | Mean    | Median  | Min    | Max    | StdDev | 95% Bound |
| --------------------- | ------- | ------- | ------ | ------ | ------ | --------- |
| navigationLoaded      | 597.700 | 589.500 | 538    | 687    | 39.846 | 615.163   |
| navigationInteractive | 753.050 | 745.500 | 702    | 860    | 38.530 | 769.936   |
| visuallyLoaded        | 753.400 | 746.500 | 702    | 860    | 38.703 | 770.362   |
| contentInteractive    | 753.800 | 746.500 | 703    | 860    | 38.499 | 770.673   |
| fullyLoaded           | 916.100 | 909     | 833    | 1065   | 51.016 | 938.459   |
| uss                   | 10.061  | 10.064  | 10.016 | 10.086 | 0.019  | 10.069    |
| pss                   | 14.016  | 14.022  | 13.952 | 14.058 | 0.025  | 14.027    |
| rss                   | 28.373  | 28.375  | 28.320 | 28.430 | 0.023  | 28.383    |

That's well within our expectations of l10n->l20n switch (up to 100kb mem, no perf impact).

That also suggests that the 1.5mb memory regression and ~60-90ms visuallyLoaded regression is not caused by l20n.js switch.

Comment 4

[Hema Koka [:hema]]

We have not made changes to the FMRadio from a functionality point of view. Per comment 3, the l20n.js transition also did not impact the numbers. Therefore this seems to be pointing to gecko regressions (similar to what we are seeing with other apps that had no significant gaia side changes in 2.5).

Bobby, 

Can we get help from the performance team in Taipei to check on gecko regressions? For ex: see the investigations being done here by Ting and others: https://bugzilla.mozilla.org/show_bug.cgi?id=1210860. 

Thanks
Hema

Comment 5

[Bobby Chien]

I attached snapshot [1] for reference. I saw number of Jul 10 ~ Jul 25 was similar with v2.2 regression line. But during Jul 25 ~ Sep 16, the number was going higher than regression line.  

[1] https://raptor.mozilla.org/dashboard/snapshot/Eta7ZaenC0rmFlU0HgDdqsNhA2JBAhYc?panelId=7&fullscreen

Kanru and Tingyu, could you help for gecko profiling? Thanks.

Comment 6

[Bobby Chien]

Hema, I saw FM launch time tough regression line today. Could you help to comment this if any change? 

[1] https://raptor.mozilla.org/dashboard/script/measures?var-device=flame-kk&var-memory=512&var-branch=master&var-test=cold-launch&panelId=7&fullscreen

Comment 7

[Ting-Yu Chou [:ting] (away)]

Profile: https://people.mozilla.org/~bgirard/cleopatra/#report=676af538cb78c25e7242efee65bc0b7c0393228a

I also saw an idle period (>200ms) before visuallyLoaded, because B2G process main thread is busy handling mozbrowserloadend (system app) and refreshing UI.

Comment 8

[Hema Koka [:hema]]

(In reply to Bobby Chien [:bchien] from comment #6)
> Hema, I saw FM launch time tough regression line today. Could you help to
> comment this if any change? 
> 
> [1]
> https://raptor.mozilla.org/dashboard/script/measures?var-device=flame-kk&var-
> memory=512&var-branch=master&var-test=cold-launch&panelId=7&fullscreen

Afaik, no changes on the app side for FMRadio. The last change was done by gandalf around 12 days ago for l20n: https://github.com/mozilla-b2g/gaia/tree/master/apps/fm

Thanks
Hema

Comment 9

[Hema Koka [:hema]]

Hub agreed to take this up and investigate on the gecko side next week (he is out tomorrow and finishing up some Music tests today). He may be pinging Gandalf and Ting who have been profiling to identify where the issues are on gecko.

Thanks
Hema

Comment 10

[Justin D'Arcangelo [:justindarc]]

Flagging myself for NI? to take a look at this tomorrow.

Comment 11

[Jim Porter (:squib)]

Justin: note that Andrew mentioned on IRC that apparently the JS optimizer in Gaia is totally broken (it doesn't understand () => {} among other things), and that may be contributing to the Gaia-wide startup regression. Some shared scripts use the short function syntax, so even apps that haven't been updated get hosed.

Comment 12

[Dylan Oliver [:doliver]]

triage: Andrew, is there a bug for the optimizer that we can mark as a dependency here?

Comment 13

[Dylan Oliver [:doliver]]

Asking squib too because asuth is on PTO today.

Comment 14

[Nicolas B. Pierron [:nbp] {away}]

(In reply to Dylan Oliver [:doliver] from comment #12)
> triage: Andrew, is there a bug for the optimizer that we can mark as a
> dependency here?

I think this issue is being addressed in Bug 1216598.

Comment 15

[Andrew Sutherland [:asuth] (he/him)]

I believe :squib is referring to :aosmond in comment 11, which is consistent with bug 1216598 mentioned in comment 14.

Comment 16

[Jim Porter (:squib)]

asuth is correct. I was referring to aosmond. In any case, based on IRC, it sounds like things are more complex than that (aren't they always?).

Comment 17

[Hubert Figuiere [:hub]]

The launch time regression appears with 

commit 7ef852e00234822dd7a50ca72593df5d052f453c
Author: Chris Lord <[e-mail]>
Date:   Sat Oct 17 22:57:45 2015 +0100

    Bug 1191745 - Switch to new homescreen by default. r=gmarty

Comment 18

[Hema Koka [:hema]]

Bobby,

Cold Launch times from Raptor today (10/30) shows 764ms. 

2.2 numbers are noted here: 705ms
https://gist.github.com/eliperelman/b81a27b7f7f3b3f75f49#fm-radio

We are around 59ms away and there is nothing else identified to be done on the app side. See previous comments on the app side analysis. This app is under 1ms 

Hub has also pointed that new homescreen changes as a possible cause and those homescreen regressions are tracked in another bug: https://bugzilla.mozilla.org/show_bug.cgi?id=1216403

I am removing this as a blocker for 2.5.

If there anything actionable on the app side that we may have overlooked, please let us know. 

Thanks
Hema