943594 - FxOS 1.3 Perf: Cold Launch Regression in Camera, Gallery, Radio, & Video apps

Status: RESOLVED WONTFIX

(Firefox OS Graveyard :: General, defect, P1)

Description

[Mike Lee [:mlee]]

Attachment: Datazilla Screenshot showing colda Launch Regression in multiple apps on 2013.11.26

Datazilla shows an average 40 - 50ms regression in cold launch times for the Camera, Gallery, Radio, & Video apps in FxOS 1.3 as of today, 2013.11.26. The Usage app also shows a significant spike.

Comment 1

[Mike Lee [:mlee]]

Hema,

Datazilla is showing cold launch regressions in the 1.3 codebase for the Camera, Gallery, Radio, & Video apps. Please assign the relevant media engineers to this issue to help identify the root cause.

Thanks,
Mike

Comment 2

[Kevin Grandon :kgrandon]

We can continue to investigate this while bug 943611 is being worked on. It does not stop investigation of the issue, but is a tool which would allow us to investigate this much faster.

Comment 3

[Hema Koka [:hema]]

Mike, 

On 11/21, I see a dip and then on 11/26 it is spiked up again for camera, gallery and video. Could you take the first shot at investigating what the cause is. 

Thank you!
Hema

Comment 4

[Mike Habicher [:mikeh] (high bugzilla latency)]

Likely a system change--in the 11/25-26 window, there were no changes to the Camera app or to the camera stack.

Comment 5

[Mike Habicher [:mikeh] (high bugzilla latency)]

Worth noting: the datazilla test landed a change within the regression window: https://github.com/davehunt/b2gperf/commits/master/b2gperf/b2gperf.py

Comment 6

[Mike Habicher [:mikeh] (high bugzilla latency)]

Attachment: Nov 25 to Nov 26 Camera app launch-time regression on b2g26_v1_2

mlee, this bug was filed against v1.3/master/m-c, but I noticed a pretty severe regression in launch-time on v1.2 -- is your team aware of this? Note that during the regression interval, nothing changed in the Camera app or the underlying stack, so this is likely a system problem.

Comment 7

[Mike Habicher [:mikeh] (high bugzilla latency)]

Looking for candidates in the gaia/master branch, the shared files used by the Camera app haven't changed within the regression window either:
locales                           // 4 months ago
shared                            // 3 minutes ago
  locales                         // 3 days ago
    date.ini                      // a year ago
  style                           // 6 hours ago
    confirm.css                   // 6 days ago
    buttons.css                   // a month ago
    confirm.css                   // 6 days ago
  js                              // 6 minutes ago
    performance_testing_helper.js // 9 months ago
    l10n.js                       // a month ago
    l10n_date.js                  // 7 months ago
    async_storage.js              // a year ago
    blobview.js                   // a month ago
    gesture_detector.js           // 9 months ago
    lazy_loader.js                // a month ago
    media                         // 17 days ago

Comment 8

[Mike Habicher [:mikeh] (high bugzilla latency)]

Attachment: Nov 24 to Nov 27 Camera app launch-time regression analysis

This spreadsheet includes data for the m-c builds as well. Results are highly variable, particularly in recent builds.
- Nov 24: 1679.2ms, 1683.3ms
- Nov 25: 1741.7ms
- Nov 26: 1733.3ms, 1816.7ms
- Nov 27: 1779.2ms, 1704.2ms

Comment 9

[Mike Lee [:mlee]]

(In reply to Mike Habicher [:mikeh] from comment #6)
> ...
> mlee, this bug was filed against v1.3/master/m-c, but I noticed a pretty
> severe regression in launch-time on v1.2 -- is your team aware of this? Note
> that during the regression interval, nothing changed in the Camera app or
> the underlying stack, so this is likely a system problem.

MikeH,
What severe launch-time regression did you see on 1.2? We're tracking a November 22nd launch-time regression in 1.3 via bug 942893 that appears to be separate this bug 943594 regression impacting media apps.

(In reply to Mike Habicher [:mikeh] from comment #5)
> Worth noting: the datazilla test landed a change within the regression
> window: https://github.com/davehunt/b2gperf/commits/master/b2gperf/b2gperf.py

Dave, any comment on whether b2gperf itself may be causing this apparent regression?

Comment 10

[Mike Habicher [:mikeh] (high bugzilla latency)]

(In reply to Mike Lee [:mlee] from comment #9)
> (In reply to Mike Habicher [:mikeh] from comment #6)
> > ...
> > mlee, this bug was filed against v1.3/master/m-c, but I noticed a pretty
> > severe regression in launch-time on v1.2 -- is your team aware of this? Note
> > that during the regression interval, nothing changed in the Camera app or
> > the underlying stack, so this is likely a system problem.
> 
> MikeH,
> What severe launch-time regression did you see on 1.2? We're tracking a
> November 22nd launch-time regression in 1.3 via bug 942893 that appears to
> be separate this bug 943594 regression impacting media apps.

Take a look at the v1.2 tab in attachment 8339535 [details]: 175 to 200ms increase in Camera app launch time, despite no changes in the app itself. (I haven't looked at any other apps.)

> (In reply to Mike Habicher [:mikeh] from comment #5)
> > Worth noting: the datazilla test landed a change within the regression
> > window: https://github.com/davehunt/b2gperf/commits/master/b2gperf/b2gperf.py
> 
> Dave, any comment on whether b2gperf itself may be causing this apparent
> regression?

Dave cleared up the confusion for me earlier today: this change hasn't been released to the infrastructure yet, so it can't be affecting the results.

djf, take a look at this chart:
  https://datazilla.mozilla.org/b2g/?branch=master&device=hamachi&range=7&test=cold_load_time&app_list=camera,gallery,video&app=camera&gaia_rev=6d4c6803d87c3a67&gecko_rev=83587bd621ddfebf

A similar dip across Camera, Gallery, and Video apps. Can you think of anything these three apps have in common that would affect them in a way that others such as the Music app are not effected? (Interestingly, the Browser app shows a complementary launch-time chart--I wonder if something changed to improve the Browser launch-time that is affecting a subset of the media apps.)

Comment 11

[Mike Habicher [:mikeh] (high bugzilla latency)]

This datazilla chart shows a ~50ms drop in the Camera, Gallery, and Video apps' cold launch times between the Nov 21, 2013, 5:30pm test run (using the 2013-11-20-06-22-58 nightly build) and the 7:40pm test run (using the 2013-11-21-04-04-02 nightly) on the same day:
  https://datazilla.mozilla.org/b2g/?branch=master&device=hamachi&range=30&test=cold_load_time&app_list=camera,gallery,video&app=camera&gaia_rev=6d4c6803d87c3a67&gecko_rev=83587bd621ddfebf

It then shows giving back the 50ms between the Nov 26, 2013, 10:38am test run and the 1:20pm test run.

I just tested the 2013-11-20 nightly build with its gaia replaced by the 2013-11-21 version, and observed no significant change in Camera app launch time: 1558ms vs 1554ms.

Further confounding matters, I just flashed the 2013-11-21 nightly in its entirety and it shows the same launch time: 1558ms. These results were obtained on Inari, so whatever changed for Hamachi doesn't show up on the other device.

Comment 12

[gbennett]

.:First Broken Build:.
Environmental Variables:
Device: Buri 1.3 mozRIL
BuildID: 20131126052050
Gaia: 4ad796b196d468bdb231beba4392acbc90a74e96
Gecko: 99479edbee2a
Version: 28.0a1
Firmware Version: 20131115

.:Last Working Build:.
Environmental Variables:
Device: Buri 1.3 mozRIL
BuildID: 20131125142741
Gaia: bd8053d30c275f8d3040cd494e04b3480a784656
Gecko: 757c2011df5b
Version: 28.0a1
Firmware Version: 20131115


The graph was correct about the regression window. 11/26 build was 30-100ms slower than 11/25 across the board for all apps. Oddly enough warm boot times on avg were slower than cold on the 11/26 build. Didn't know that was possible.

Comment 13

[Mike Habicher [:mikeh] (high bugzilla latency)]

(In reply to Mike Habicher [:mikeh] from comment #11)
> 
> I just tested the 2013-11-20 nightly build with its gaia replaced by the
> 2013-11-21 version, and observed no significant change in Camera app launch
> time: 1558ms vs 1554ms.

I just corrected an error in my calculations: the 2013-11-20-06-22-58 nightly has a Camera app launch time of 1613ms.
The 2013-11-21-04-02-02 nightly has a launch time of 1556ms. This correctly reflects the chart linked to in comment 11.

The hybrid test run with the 2013-11-20 nightly gecko and 2013-11-21 nightly gaia shows the faster time, so the speed improvement is due to a change in gaia.

On the subsequent nightlies, I measure:
- 2013-11-22: 1563ms
- 2013-11-23: 1704ms
- 2013-11-24: 1679, 1683ms
- 2013-11-25: 1741ms
- 2013-11-26-04-02-01: 1733, 1829ms
- 2013-11-26-05-20-50: 1817ms
- 2013-11-27: 1779, 1704ms

Results are somewhat variable, but there is definitely a trend towards longer launch times over this period.

Comment 14

[Mike Habicher [:mikeh] (high bugzilla latency)]

Attachment: Camera app launch-time launch-time data

More data, from Nov 20 to Nov 29.

Next step--look for any nightlies where this is a big change, and try the gecko from the "before" nightly in combination with gaia from the "after" nightly.

Comment 15

[David Flanagan [:djf]]

(In reply to Mike Habicher [:mikeh] from comment #10)

> A similar dip across Camera, Gallery, and Video apps. Can you think of
> anything these three apps have in common that would affect them in a way
> that others such as the Music app are not effected? (Interestingly, the
> Browser app shows a complementary launch-time chart--I wonder if something
> changed to improve the Browser launch-time that is affecting a subset of the
> media apps.)

No, I can't think of anything that changed.  If it was Music instead of Camera, I'd blame mediadb or device storage. But with camera in there, I don't know.

And the fact that increase in startup time almost exactly mirrors a decrease from the week before makes me think that this was some system thing that landed, broke stuff, and got backed out.  Hasn't there been a lot of churn in the graphics layer?

Comment 16

[David Flanagan [:djf]]

Attachment: Screen Shot 2013-12-03 at 3.32.18 PM.png

When I look at a datazilla graph like this, I don't see a startup time regression. I see a promising startup time improvement that got backed out.

Comment 17

[Mike Habicher [:mikeh] (high bugzilla latency)]

That's the conclusion I'm coming to as well: there are certainly no shortage of visual changes over the anti-regression interval, and towards the end, things mostly go back to the way they were. Removing blocking-1.3 nom.

Comment 18

[Ben Kelly [:bkelly, not reviewing]]

FYI, I'm currently investigating if bug 942483 is due to a gonk firmware change around this time frame.  That might also explain the changes with these apps.  Unfortunately I may not be able to prove it conclusively since we don't collect enough information at datazilla currently.  (We opened bug 946254 to help fix that.)

Comment 19

[Ben Kelly [:bkelly, not reviewing]]

And by bug 942483 in comment 18 I actually meant bug 942893.

Comment 20

[Ben Kelly [:bkelly, not reviewing]]

I was able to reproduce the regression running the b2gperf Gallery launch test on my buri:

  gaia git ed5b8ba7245f, gecko hg 53d55d2d0a25 - median 445ms
  gaia git 6d4c6803d87c, gecko hg 99479edbee2a - median 492ms

This seems unrelated to bug 942893 and follows the gecko rev.  I bisected it to this:

changeset:   157467:33f136f3274b
user:        Benoit Girard <[e-mail]>
date:        Mon Nov 25 15:12:20 2013 -0500
summary:     Backout 08eaaed722ef for regression bug 942788.

This was a backout of bug 917416.  Since this is a legitimate backout I'm going to mark this WONTFIX.