948977 - NUWA slows cold launch time for Clock app

Status: RESOLVED WORKSFORME

(Core :: IPC, defect, P1)

Description

[Ben Kelly [:bkelly, not reviewing]]

It appears clock launch time regressed yesterday by about 40ms.  See:

  https://datazilla.mozilla.org/b2g/?branch=master&device=hamachi&range=7&test=cold_load_time&app_list=clock&app=clock&gaia_rev=1997c55ce6e6f743&gecko_rev=3a2d8af198510726

Regression range from datazilla:

  https://github.com/mozilla-b2g/gaia/compare/916bcdd5d9a3...1997c55ce6e6f7
  http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=9f12a9fab080&tochange=df82be9d89a5

Comment 1

[Mike Pennisi [:jugglinmike]]

The changeset corresponding to this timeframe shows no patches to Gaia's Clock application:

https://github.com/mozilla-b2g/gaia/commits/master/apps/clock

So I believe this regression was caused by a change in the platform.

Comment 2

[Ben Kelly [:bkelly, not reviewing]]

Dylan, do you have anyone who can investigate this clock launch time regression?

You can reproduce the timing measurements from datazilla by doing the following with a real device hooked up to USB:

pip install b2gperf
adb forward tcp:2828 tcp:2828
b2gperf --delay=10 Clock

Comment 3

[Ben Kelly [:bkelly, not reviewing]]

Nom for 1.4 blocker due to regression.

Comment 4

[Dietrich Ayala (:dietrich)]

Need regression window of changesets on mozilla-central.

Comment 5

[Ben Kelly [:bkelly, not reviewing]]

I'm just about done bisecting this.  I will post my results shortly.

Comment 6

[Ben Kelly [:bkelly, not reviewing]]

My bisection suggests that this was introduced with bug 930282:

https://hg.mozilla.org/mozilla-central/rev/19124ad87c71
https://hg.mozilla.org/mozilla-central/rev/3fa57d5d6db0
https://hg.mozilla.org/mozilla-central/rev/ecfccd18bcf2

What's more, disabling NUWA in b2g/confvars.sh, such as was done in bug 948829, does not seem to return us to our previous launch times.  Clock only regains about 20ms of the original 40ms regression.  As far as I can tell this is mainly due to the changes in Part 3:

https://hg.mozilla.org/mozilla-central/rev/ecfccd18bcf2

I don't have a good explanation of why this effects Clock more than other apps.

Comment 7

[Ben Kelly [:bkelly, not reviewing]]

(In reply to Ben Kelly [:bkelly] from comment #6)
> What's more, disabling NUWA in b2g/confvars.sh, such as was done in bug
> 948829, does not seem to return us to our previous launch times.  Clock only
> regains about 20ms of the original 40ms regression.  As far as I can tell
> this is mainly due to the changes in Part 3:
> 
> https://hg.mozilla.org/mozilla-central/rev/ecfccd18bcf2

Actually, please ignore this part.  I re-ran my b2gperf tests with NUWA disabled and the regression was fully resolved.  The 20ms I reference above was variation due to using a smaller number of b2gperf iterations while bisecting.

Comment 8

[Ben Kelly [:bkelly, not reviewing]]

Rename the description to reflect that its a NUWA problem.  Also, since NUWA is currently disabled I'm marking this as a blocker for re-enabling NUWA.

Also note, while this effects clock the most, I do believe there are smaller regressions in other apps as well when NUWA is enabled.  Its harder to see in the graph due to outliers in those apps skewing results.

Comment 9

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

If this happens regardless of the value of the Nuwa config variable, why does it block flipping said variable?

Comment 10

[Ben Kelly [:bkelly, not reviewing]]

(In reply to Kyle Huey [:khuey] ([e-mail]) from comment #9)
> If this happens regardless of the value of the Nuwa config variable, why
> does it block flipping said variable?

I think I mis-communicated.  Disabling NUWA does remove the launch regression.  I had previously thought it did not fully, but further testing showed I was incorrect about that.  Sorry for the confusion.

Comment 11

[Ben Kelly [:bkelly, not reviewing]]

And if you are wondering why we don't see the launch time drop back down in datazilla when NUWA was disabled, we are missing data for that time window.  During this same period of datazilla missing data there was another platform regression across many apps.  So the time gain of disabling NUWA was probably wiped out by that regression when we started getting data again last Friday.

Comment 12

[Cervantes Yu [:cyu] [:cervantes]]

Can we know how is app launch performance measured (or any way to perform the same tests on our device)? The number indicates that the preallocated process is used in the test. If this is true, the we should not see such regression resulting from Nuwa. Anyway we need to redo the tests on the device to see how the slowdown came to be.

Comment 13

[Ben Kelly [:bkelly, not reviewing]]

Steps to reproduce are in comment 2.  Basically you need to install b2gperf and run it against a hamachi device.

pip install b2gperf
adb forward tcp:2828 tcp:2828
b2gperf --delay=10 Clock

This will restart b2g, wait 60 seconds, and then launch Clock 30 times.  I typically look at the reported median value.

The cold_load_time is essentially just the time it takes to load static content.  Internally its reported as the time between the gaia system launching the app and when the mozbrowseloadend event occurs.

Comment 14

[Ben Kelly [:bkelly, not reviewing]]

During the recent NUWA enable/disable I did not see launch changes for clock as described here.  It seems that whatever the issue was it has been resolved along with other fixes.  Also, it seems unlikely we would hold back a high priority system memory improvement for a slight launch regression in one app.

Comment 15

[Joe Cheng [:jcheng] (please needinfo)]

remove [tarako]