966586 - [b2g] 100ms datazilla regression on Jan 31 (Rocketbar)

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Gaia::Search, defect, P1)

Description

[Ben Kelly [:bkelly, not reviewing]]

On Jan 31, 2014 the hamachi devices under test in datazilla were flashed to the next OEM firmware version date Dec 19, 2013.  This caused nearly every app to regress in cold launch times by 100ms.

We saw a launch time in the last OEM firmware upgrade as well.  That was smaller and was attributed to the change to the new fonts in v1.2.

We're not changing major gonk revisions this time, though.  Its unclear what the issue is.

Comment 1

[Stephen Donner [:stephend] Not actively reading bugmail]

(Hey, sorry for the swath of cc:ed folks, but this needs baseline-establishing before we can reasonably proceed on other branches/devices, I'd think.)

Comment 2

[Ben Kelly [:bkelly, not reviewing]]

I may have been to quick to attribute this to the firmware change.  Looking at the pushlog it appears a couple things landed at the same time:

  http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=5e0a22097bff&tochange=735a648bca0d
  https://github.com/mozilla-b2g/gaia/compare/6c9fac83b743711d0...f9013a0d20824de7778

Both rocketbar and NUWA landed in this same range.

It also looks like inari regressed by about 100ms at roughly the same time as well.

Comment 3

[Ben Kelly [:bkelly, not reviewing]]

Kevin, could you check to see if disabling rocketbar might fix this cold launch regression with b2gperf?

Comment 4

[Ben Kelly [:bkelly, not reviewing]]

NUWA has been backed out and the 100ms regression remains.  That suggests to me that NUWA is not to blame here.

Note, however, there was an additional 200+ms regression on Feb 1.  This regression recovered at the same time NUWA was backed out.  Its unclear to me if they were related.  It seems unlikely, though, since NUWA was enabled prior to the original 200+ms change, but I don't see a good alternative explanation in the changelogs.

Here's the ranges for the improvement on Feb 2:

  https://github.com/mozilla-b2g/gaia/compare/3b2fe2f8616...33eb812eadb61
  http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=d09f9a9f81ae&tochange=3e40f7389d1b

Its a bit confusing with some many large changes landing and getting backed out in a short period.

Comment 5

[Ben Kelly [:bkelly, not reviewing]]

Looking at the video in eideticker (yay eideticker!):

  http://eideticker.mozilla.org/b2g/#/inari/b2g-contacts-startup/timetostableframe

You can see that there is a visual change to draw the app name in the upper left of the status bar now that rocketbar is enabled.  Looking at the frame difference graph before rocketbar:

  http://mzl.la/1bhUtbn

And after rocketbar:

  http://mzl.la/1k0yH43

It is evident that the additional time is occurring around when the current app name in the upper left of the screen is changed.

This would seem to suggest its a rocketbar issue.

Comment 6

[Kevin Grandon :kgrandon]

Hey Ben - those eideticker videos are sweet! :)

I may have addressed some of this yesterday with landing of bug 966312. Before we were clearing the title, then setting it.

I may further be able to fix this by delaying the setting of the title, but that may cause some UX impact.

Comment 7

[Kevin Grandon :kgrandon]

I suppose we're looking at 1.2s vs 1.38s to the "big" pixel jump. 180ms to paint the title seems like an excessively long time to wait. I'm wondering if it could be some issue where we're checking too many event listeners?

Comment 8

[Ben Kelly [:bkelly, not reviewing]]

Thanks Kevin!  If you don't mind, I'm going to assign this to you.

Also, it looks like template app is the best app to show this problem on datazilla.  It doesn't seem to be impacted by most of the other commit noise going on right now.

Comment 9

[Jason Smith [:jsmith]]

Rocketbar is being turned off for 1.4, so I'm clearing nom. I filed a separate bug for turning off the feature on 1.4.

Comment 10

[Dave Hunt [:davehunt] [he/him] ⌚BST]

(In reply to Ben Kelly [:bkelly] from comment #5)
> Looking at the frame difference graph before rocketbar:
> 
>   http://mzl.la/1bhUtbn
> 
> And after rocketbar:
> 
>   http://mzl.la/1k0yH43

I believe bug 966457 has caused these links to become invalid. :(

Comment 11

[Ben Kelly [:bkelly, not reviewing]]

So disabling rocketbar has returned us to our previous launch time performance:

  http://mzl.la/1hWhA3M

Disabled in commit:

  https://github.com/mozilla-b2g/gaia/commit/eba290a91ca1a529c48d3145cd4a97d78ed7913c

Closing this as fixed for now.

Comment 12

[Jason Smith [:jsmith]]

(In reply to Ben Kelly [:bkelly] from comment #11)
> So disabling rocketbar has returned us to our previous launch time
> performance:
> 
>   http://mzl.la/1hWhA3M
> 
> Disabled in commit:
> 
>  
> https://github.com/mozilla-b2g/gaia/commit/
> eba290a91ca1a529c48d3145cd4a97d78ed7913c
> 
> Closing this as fixed for now.

Note - this bug likely will return when we enable rocketbar on 1.5. Do we want to just open a new bug when that happens or keep this open for tracking?

Comment 13

[Ben Kelly [:bkelly, not reviewing]]

Is RocketBar considered completely done or will it be worked on more before being re-enabled?  I had assumed the later and thought making it performant should be part of that work.

Anyway, if we want a bug I would prefer a separate one.

Comment 14

[Jason Smith [:jsmith]]

(In reply to Ben Kelly [:bkelly] from comment #13)
> Is RocketBar considered completely done or will it be worked on more before
> being re-enabled?  I had assumed the later and thought making it performant
> should be part of that work.

There's going to be a lot more work on it before it gets enabled again.

> 
> Anyway, if we want a bug I would prefer a separate one.

Fair enough. If we see this problem when rocketbar gets enabled again, then we can open a separate bug.