1216403 - Performance regression in Apps (2015/10/20)

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Performance, defect, P2)

Description

[Bobby Chien]

Performance regression in Calendar, Clock, Contacts, Video, Music

Gaia:
good: https://github.com/mozilla-b2g/gaia/commit/b86bffe236928abe
bad: https://github.com/mozilla-b2g/gaia/commit/496987319b5e4a62

Gecko:
good: http://hg.mozilla.org/mozilla-central/rev/b1f37ff7b4c325c7
bad: http://hg.mozilla.org/mozilla-central/rev/b25b7b26c83989d6


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

Comment 1

[Bobby Chien]

Ting, could you try bisect-bot? Thanks.

Comment 2

[:Eli Perelman]

According to bug 1216101 comment 4, there is a good indication that this stems from the landing of the new homescreen. If the new homescreen/Gecko is doing more work during the launching process, this would be regression causality.

Comment 3

[:Eli Perelman]

Also, the commits of the regressions from Raptor may not line up with the actual regressor since the landing of the homescreen occurred at a different time than Raptor enabling the performance tests to run against the new homescreen. As such, doing a bisect first is probably not the best course.

Since we believe the new homescreen may be at fault, I'd say to run a couple tests using the latest Raptor:

* Test a regressing app against the old homescreen
* Test a regressing app against the new homescreen

Determine if there is a regression just from homescreen changes, and that should give us the answer on whether a bisect is actually needed.

Comment 4

[GitHub Autolander Bot]

Attachment: [gaia] Cwiiis:bug1216403-homescreen-launch-perf-marker > mozilla-b2g:master

Comment 5

[Chris Lord [:cwiiis]]

Comment on attachment 8676872 [details] [review]
[gaia] Cwiiis:bug1216403-homescreen-launch-perf-marker > mozilla-b2g:master

Eli, does this put results back in line with verticalhome?

This PR moves the performance marker to the equivalent place it was in verticalhome (note that this isn't ready for merging if it does, we need to change this in gaia-site-icon upstream first).

Comment 6

[:Eli Perelman]

I'll still have to test this out, but moving of the marker looks correct to me.

Comment 7

[Chris Lord [:cwiiis]]

Comment on attachment 8676872 [details] [review]
[gaia] Cwiiis:bug1216403-homescreen-launch-perf-marker > mozilla-b2g:master

Eli thinks this should land anyway, so let's do that. I'm broadly in favour of anything that removes code from the main homescreen app.

Comment 8

[:Eli Perelman]

verticalhome.gaiamobile.org:

| Metric                | Mean     | Median  | Min    | Max    | StdDev | 95% Bound |
| --------------------- | -------- | ------- | ------ | ------ | ------ | --------- |
| visuallyLoaded        | 1195.167 | 1191    | 1143   | 1345   | 38.587 | 1208.975  |

homescreen.gaiamobile.org:

| Metric                | Mean     | Median   | Min    | Max    | StdDev | 95% Bound |
| --------------------- | -------- | -------- | ------ | ------ | ------ | --------- |
| visuallyLoaded        | 1277     | 1272.500 | 1199   | 1483   | 50.696 | 1295.141  |

homescreen.gaiamobile.org with Chris's change:

| Metric                | Mean     | Median   | Min    | Max    | StdDev | 95% Bound |
| --------------------- | -------- | -------- | ------ | ------ | ------ | --------- |
| visuallyLoaded        | 1266.133 | 1262     | 1209   | 1324   | 30.532 | 1277.059  |

Comment 9

[:Eli Perelman]

30 runs with the Clock app

verticalhome.gaiamobile.org:

| Metric                | Mean     | Median  | Min    | Max    | StdDev | 95% Bound |
| --------------------- | -------- | ------- | ------ | ------ | ------ | --------- |
| visuallyLoaded        | 1195.167 | 1191    | 1143   | 1345   | 38.587 | 1208.975  |

homescreen.gaiamobile.org:

| Metric                | Mean     | Median   | Min    | Max    | StdDev | 95% Bound |
| --------------------- | -------- | -------- | ------ | ------ | ------ | --------- |
| visuallyLoaded        | 1277     | 1272.500 | 1199   | 1483   | 50.696 | 1295.141  |

homescreen.gaiamobile.org with Chris's change:

| Metric                | Mean     | Median   | Min    | Max    | StdDev | 95% Bound |
| --------------------- | -------- | -------- | ------ | ------ | ------ | --------- |
| visuallyLoaded        | 1266.133 | 1262     | 1209   | 1324   | 30.532 | 1277.059  |

Comment 10

[Chris Lord [:cwiiis]]

Eli, post this patch, is this a big enough difference that we want to try and do something about it?

I get the feeling that anything we'd do to address this would really just be aiming at better test numbers without actually improving user experience... (by, say, delaying the launch to after more work has been done on the current event loop)

Comment 11

[:Eli Perelman]

Unfortunately the determine of whether we need to continue to improve this doesn't lie with me, but probably more with Gregor and Bobby Chien. If it's possible you are hitting more code paths in Gecko that are beyond your current control, I'd probably still recommend that Ting finish his profile between verticalhome and homescreen.

We also shouldn't defer the mark on the event loop unless it is visually representative (e.g. not move the mark unless the mark closely lines up with user intent).

Comment 12

[Guillaume Marty [:gmarty]]

Comment on attachment 8676872 [details] [review]
[gaia] Cwiiis:bug1216403-homescreen-launch-perf-marker > mozilla-b2g:master

Looks good!

Comment 13

[Ryan VanderMeulen [:RyanVM]]

Master: https://github.com/mozilla-b2g/gaia/commit/41c0e113bec5596912b29e66f1e4121adefbea1c

Comment 14

[Chris Lord [:cwiiis]]

Not marking this as fixed just yet, I'll leave that down to Bobby - there may still be a minor regression. I don't think trying to optimise away a 66ms regression is time well spent, but that isn't necessarily my decision.

Comment 15

[Bobby Chien]

I saw regression is still exist on master. Please refer [1] for raptor number.

[1] https://raptor.mozilla.org/dashboard/script/measures?var-device=flame-kk&var-memory=512&var-branch=master&var-test=cold-launch [Custom time from 10/18 to 10/21, would see more information]

Comment 16

[Chris Lord [:cwiiis]]

(In reply to Bobby Chien [:bchien] from comment #15)
> I saw regression is still exist on master. Please refer [1] for raptor
> number.
> 
> [1]
> https://raptor.mozilla.org/dashboard/script/measures?var-device=flame-kk&var-
> memory=512&var-branch=master&var-test=cold-launch [Custom time from 10/18 to
> 10/21, would see more information]

The fix was only merged on 10/22, where at least for Camera I see a sharp drop (I see little difference elsewhere). It seems results before 10/19 @ 10:00 have been discarded, so I'm uncertain what was going on before that point.

I see a rise at 10/19 @ 19:00 in Clock and Calendar - for Clock, the difference is consistent, but small - inline with what we'd expect from comment #9 (about 60ms). For Calendar, this seems quite big, but that also seems quite unexpected to me - could some other change (either in Gaia or Gecko) have also coincided at that time/date that skews the results?

Could you give some information on the exact regressions you're talking about, their magnitude, and whether you think they're significant?

Comment 17

[Bobby Chien]

Attachment: Regression1.png

For comment #16, Calendar is about 200ms and Clock is about 60ms.

Comment 18

[Bobby Chien]

Attachment: Regression2.png

Gallery is about 70ms. Video is about 40ms. And notable change in test app is about 130ms.

Comment 19

[Chris Lord [:cwiiis]]

(In reply to Bobby Chien [:bchien] from comment #18)
> Created attachment 8678006 [details]
> Regression2.png
> 
> Gallery is about 70ms. Video is about 40ms. And notable change in test app
> is about 130ms.

This range doesn't include the fix that was committed though, does that change anything?

https://github.com/mozilla-b2g/gaia/commit/41c0e113bec5596912b29e66f1e4121adefbea1c

I don't know what builds these are going off to know if this is included yet or not, but hopefully you know what to check :)

Comment 20

[Bobby Chien]

Thanks for update, Chris. However, Patch in comment 13 doesn't reflect to resolve regression per my comment 17 and comment 18. As result on Today's Raptor[1] Number, Could you help to check again?

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

Comment 21

[Hema Koka [:hema]]

(In reply to Chris Lord [:cwiiis] from comment #16)

> 
> The fix was only merged on 10/22, where at least for Camera I see a sharp
> drop (I see little difference elsewhere). 

Optimization patches have been landing on camera app and you can see the sharp drop in launch times as a result...Camera work is tracked here: https://bugzilla.mozilla.org/show_bug.cgi?id=1210849

Comment 22

[Bobby Chien]

(In reply to Hema Koka [:hema] from comment #21)
> (In reply to Chris Lord [:cwiiis] from comment #16)
> 
> > 
> > The fix was only merged on 10/22, where at least for Camera I see a sharp
> > drop (I see little difference elsewhere). 
> 
> Optimization patches have been landing on camera app and you can see the
> sharp drop in launch times as a result...Camera work is tracked here:
> https://bugzilla.mozilla.org/show_bug.cgi?id=1210849

Thanks for update! Hema. I saw Music and Camera drop about 200ms and 100ms. 

We still need to let this case open to track Calendar and Contacts app.

Comment 23

[Chris Lord [:cwiiis]]

Running cold-launch tests over 30 runs on both homescreen and verticalhome:

homescreen contacts:

| Metric                | Mean    | Median  | Min    | Max    | StdDev | 95% Bound |
| --------------------- | ------- | ------- | ------ | ------ | ------ | --------- |
| navigationLoaded      | 349.167 | 351     | 316    | 398    | 20.197 | 356.394   |
| visuallyLoaded        | 419.533 | 418     | 378    | 487    | 25.286 | 428.582   |
| contentInteractive    | 623.867 | 623.500 | 563    | 711    | 31.321 | 635.075   |
| navigationInteractive | 623.967 | 623.500 | 563    | 711    | 31.299 | 635.167   |
| fullyLoaded           | 709.200 | 708.500 | 633    | 785    | 31.282 | 720.394   |
| uss                   | 15.389  | 15.363  | 14.902 | 15.883 | 0.314  | 15.502    |
| pss                   | 19.644  | 19.616  | 19.157 | 20.152 | 0.316  | 19.757    |
| rss                   | 34.664  | 34.631  | 34.180 | 35.195 | 0.318  | 34.778    |

homescreen calendar:

| Metric                | Mean     | Median  | Min    | Max    | StdDev | 95% Bound |
| --------------------- | -------- | ------- | ------ | ------ | ------ | --------- |
| navigationLoaded      | 807.200  | 799.500 | 718    | 926    | 52.373 | 825.941   |
| navigationInteractive | 812.467  | 805.500 | 724    | 931    | 52.359 | 831.203   |
| visuallyLoaded        | 931.967  | 928     | 841    | 1053   | 52.912 | 950.901   |
| contentInteractive    | 932.167  | 928.500 | 841    | 1053   | 52.838 | 951.074   |
| fullyLoaded           | 1517.433 | 1510    | 1437   | 1635   | 50.249 | 1535.415  |
| uss                   | 16.605   | 16.605  | 16.547 | 16.637 | 0.020  | 16.612    |
| pss                   | 21.082   | 21.084  | 21.027 | 21.114 | 0.020  | 21.089    |
| rss                   | 36.298   | 36.301  | 36.254 | 36.328 | 0.020  | 36.305    |

verticalhome contacts:

| Metric                | Mean    | Median  | Min    | Max    | StdDev | 95% Bound |
| --------------------- | ------- | ------- | ------ | ------ | ------ | --------- |
| navigationLoaded      | 342.467 | 345.500 | 295    | 378    | 19.219 | 349.344   |
| visuallyLoaded        | 416.533 | 415     | 356    | 468    | 26.446 | 425.997   |
| contentInteractive    | 625.633 | 624.500 | 560    | 699    | 33.581 | 637.650   |
| navigationInteractive | 625.800 | 624.500 | 560    | 699    | 33.668 | 637.848   |
| fullyLoaded           | 707.133 | 705.500 | 633    | 790    | 37.199 | 720.445   |
| uss                   | 15.447  | 15.572  | 14.844 | 15.812 | 0.308  | 15.557    |
| pss                   | 19.724  | 19.849  | 19.120 | 20.089 | 0.309  | 19.835    |
| rss                   | 34.750  | 34.873  | 34.145 | 35.113 | 0.309  | 34.861    |

verticalhome calendar:

| Metric                | Mean     | Median  | Min    | Max    | StdDev | 95% Bound |
| --------------------- | -------- | ------- | ------ | ------ | ------ | --------- |
| navigationLoaded      | 807.367  | 811.500 | 663    | 928    | 54.363 | 826.820   |
| navigationInteractive | 812.400  | 816.500 | 671    | 933    | 54.091 | 831.756   |
| visuallyLoaded        | 934.700  | 938     | 799    | 1054   | 52.925 | 953.639   |
| contentInteractive    | 934.900  | 938     | 799    | 1054   | 52.984 | 953.860   |
| fullyLoaded           | 1514.067 | 1514    | 1371   | 1633   | 54.790 | 1533.673  |
| uss                   | 16.592   | 16.598  | 16.531 | 16.641 | 0.025  | 16.601    |
| pss                   | 21.071   | 21.076  | 21.012 | 21.120 | 0.025  | 21.080    |
| rss                   | 36.320   | 36.324  | 36.262 | 36.371 | 0.025  | 36.329    |

Basically, the results are identical, as expected. Unassigning from me, homescreen is currently having no appreciable effect on app startup performance.

Comment 24

[Punam Dahiya [:pdahiya]]

Hi Chris

With today's build, for gallery after 30 runs , numbers on my box

new home screen - gallery

| Metric                | Mean     | Median    | Min    | Max    | StdDev  | 95% Bound |
| --------------------- | -------- | --------- | ------ | ------ | ------- | --------- |
| navigationLoaded      | 813.967  | 821       | 684    | 921    | 37.036  | 827.220   |
| navigationInteractive | 815.400  | 822       | 686    | 923    | 37.017  | 828.646   |
| visuallyLoaded        | 1228.267 | 1230      | 1172   | 1295   | 27.947  | 1238.268  |
| contentInteractive    | 1228.633 | 1230      | 1172   | 1296   | 27.985  | 1238.648  |
| mediaEnumerated       | 1700     | 1696.500  | 1629   | 1830   | 41.647  | 1714.903  |
| fullyLoaded           | 9987.900 | 10015.500 | 9298   | 10578  | 212.497 | 10063.941 |
| uss                   | 18.952   | 18.955    | 18.777 | 19.172 | 0.072   | 18.978    |
| pss                   | 22.984   | 22.982    | 22.823 | 23.228 | 0.075   | 23.011    |
| rss                   | 38.962   | 38.963    | 38.785 | 39.184 | 0.074   | 38.988    |

vertical home - gallery

| Metric                | Mean     | Median   | Min    | Max    | StdDev  | 95% Bound |
| --------------------- | -------- | -------- | ------ | ------ | ------- | --------- |
| navigationLoaded      | 730.833  | 730.500  | 676    | 774    | 21.851  | 738.653   |
| navigationInteractive | 732.167  | 732      | 677    | 775    | 21.880  | 739.996   |
| visuallyLoaded        | 1140.133 | 1143.500 | 1099   | 1176   | 18.729  | 1146.835  |
| contentInteractive    | 1140.433 | 1144     | 1099   | 1176   | 18.674  | 1147.116  |
| mediaEnumerated       | 1597.633 | 1595.500 | 1541   | 1675   | 30.570  | 1608.573  |
| fullyLoaded           | 9912.200 | 9939.500 | 9413   | 10195  | 176.609 | 9975.399  |
| uss                   | 18.942   | 18.938   | 18.754 | 19.262 | 0.080   | 18.970    |
| pss                   | 22.981   | 22.985   | 22.781 | 23.325 | 0.087   | 23.012    |
| rss                   | 38.966   | 38.965   | 38.766 | 39.285 | 0.082   | 38.995    |

Can you please check for gallery app and if possible, help improve launch time. Thanks!

Comment 25

[Chris Lord [:cwiiis]]

Yesterday's pvt gecko engineering build, gaia checkout 0036c757d418347afc9f252b2766b88e283848bf

New home screen, gallery, 30 runs:

| Metric                | Mean     | Median   | Min    | Max    | StdDev | 95% Bound |
| --------------------- | -------- | -------- | ------ | ------ | ------ | --------- |
| navigationLoaded      | 366.633  | 366.500  | 317    | 409    | 23.440 | 375.021   |
| navigationInteractive | 367.300  | 367      | 318    | 409    | 23.481 | 375.702   |
| visuallyLoaded        | 558.333  | 559.500  | 509    | 593    | 22.064 | 566.229   |
| contentInteractive    | 558.533  | 560      | 509    | 593    | 22.133 | 566.453   |
| mediaEnumerated       | 961.400  | 968      | 885    | 1012   | 31.879 | 972.808   |
| fullyLoaded           | 1397.233 | 1396.500 | 1312   | 1485   | 41.882 | 1412.221  |
| uss                   | 19.881   | 19.864   | 19.414 | 20.434 | 0.229  | 19.963    |
| pss                   | 24.459   | 24.441   | 23.994 | 25.012 | 0.229  | 24.541    |
| rss                   | 39.839   | 39.819   | 39.379 | 40.391 | 0.228  | 39.921    |

verticalhome:

| Metric                | Mean     | Median   | Min    | Max    | StdDev | 95% Bound |
| --------------------- | -------- | -------- | ------ | ------ | ------ | --------- |
| navigationLoaded      | 366.100  | 369.500  | 297    | 424    | 22.153 | 374.027   |
| navigationInteractive | 366.800  | 370.500  | 297    | 425    | 22.215 | 374.749   |
| visuallyLoaded        | 564.800  | 564      | 468    | 646    | 31.854 | 576.199   |
| contentInteractive    | 564.967  | 564.500  | 468    | 647    | 31.943 | 576.397   |
| mediaEnumerated       | 965.400  | 963.500  | 885    | 1041   | 35.680 | 978.168   |
| fullyLoaded           | 1390.733 | 1398.500 | 1304   | 1472   | 50.530 | 1408.815  |
| uss                   | 19.084   | 19.084   | 18.676 | 19.359 | 0.213  | 19.160    |
| rss                   | 39.058   | 39.056   | 38.652 | 39.332 | 0.213  | 39.135    |
| pss                   | 22.980   | 22.980   | 22.573 | 23.255 | 0.213  | 23.057    |

I don't think there's much I can do to help here. All that happens when you launch an app on home screen is that it calls the app launch API and sets a timeout to remove an icon style transition. The size of the DOM may be affecting the cost of the style change, but I don't think a difference of <100ms (going on your results, the difference is ~4ms for me) is worth trying to optimise for.

Comment 26

[Bobby Chien]

As Raptor's report, regression is only exist in Calendar. Create bug 1220533 to follow up, and mark this as resolved fixed.