1196586 - [Performance] Improve Gallery app startup time to less than 1000ms

Status: RESOLVED FIXED

(Firefox OS Graveyard :: General, defect)

Comment 1

[Bobby Chien]

Report: 2015/08/18

Flame-KK 319MB
-------------------------
appName   master  v2.2
--------  ------  ----
Messages  1545    986
Settings  2669    2437
Video     1182    1020
Gallery   1139    1046
Music     1054    956
FM Radio  741     496
E-Mail    547     1973
Contacts  1149    717
Clock     1395    1206
Calendar  1543    1342
Camera    1465    1297
Dialer    769

Aries-KK 2G
----------------------------------------------------------------------
appName   value  memory  device  branch  context
--------  -----  ------  ------  ------  -----------------------------
Calendar  730    2048    aries   master  calendar.gaiamobile.org
Contacts  565    2048    aries   master  communications.gaiamobile.org
FM Radio  349    2048    aries   master  fm.gaiamobile.org
E-Mail    250    2048    aries   master  email.gaiamobile.org
Music     511    2048    aries   master  music.gaiamobile.org
Clock     518    2048    aries   master  clock.gaiamobile.org
Camera    651    2048    aries   master  camera.gaiamobile.org
Dialer    305    2048    aries   master  communications.gaiamobile.org
Video     710    2048    aries   master  video.gaiamobile.org
Settings  1657   2048    aries   master  settings.gaiamobile.org
Gallery   507    2048    aries   master  gallery.gaiamobile.org
Messages  778    2048    aries   master  sms.gaiamobile.org

Comment 2

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

Profile: http://people.mozilla.org/~bgirard/cleopatra/#report=25b39b7ff21c2018701d020a57bbef4ec4c13d5a

Flame 1GB
Gecko: 8a6045d14d6b
Gaia: cddb9f610cbe03d0ca39d81bbdce46a0fca841ab
Workload: reference-workload-light

Comment 3

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

(In reply to Ting-Yu Chou [:ting] from comment #2)
> Profile:
> http://people.mozilla.org/~bgirard/cleopatra/
> #report=25b39b7ff21c2018701d020a57bbef4ec4c13d5a

Most noticable chunks: gaia-header.js, thumbnails.js, l10n.js.

Comment 4

[Bobby Chien]

coldlaunch.visuallyLoaded
-------------------------
appName   master  v2.2
--------  ------  ----
Gallery   1176    1046

----------------------------------------------------------------------
appName   value  memory  device  branch  context
--------  -----  ------  ------  ------  -----------------------------
Gallery   718    2048    aries   master  gallery.gaiamobile.org

Comment 5

[Punam Dahiya [:pdahiya]]

Scope of bug 1211393 is to reduce the regression seen between 2.2 and 2.5. I am using this bug to investigate and improve gallery startup time by identifying code taking most time and for easy win optimizations.

Comment 6

[Punam Dahiya [:pdahiya]]

On putting Performance.now and running code in WebIDE, here are numbers at different stages of launch before hitting visually loaded and fully loaded mark. 

- the very first line of JavaScript that runs
we include shared/js/l10n.js and that runs first at 223 ms
shared/js/mediadb first line runs at 373 ms
thumbnails.js first line runs at 497 ms ( new media db is called inside it at 501 ms)
startup.js first line runs at 642 ms


- when the DOMContentLoaded event is fired
window DOM loadeded and parsed at 1098.39 ms


- when new MediaDB() is callled
As reported above at 501 ms

- when the localized event is sent (does the l10n library still fire that event?)
localized event fired at  1115.765 
    at fireLocalizedEvent (app://gallery.gaiamobile.org/shared/js/l10n.js:1871:1) l10n.js:1871:1

- when MediaDB sends the enumerable event
MediaDB sends enumerable at 1248.51 ms at enumerateDB (app://gallery.gaiamobile.org/js/thumbnails.js:94:1) 

- when the load event is fired
window load event is fired at 1470.575 ms

- visually loaded marker is at:  1752.575 ms
- media db enumerated:  2318.44

The numbers above are using performance.now in logs and shows there is a huge lag when MediaDB instance is created and enumerable event is fired, hinting indexedDB is idle for a long time before it gets enumerable event.

Comment 7

[Punam Dahiya [:pdahiya]]

Sharing findings with David for his inputs. Video sees a similar lag in captured profile in bug 1210860 by :ting https://bugzilla.mozilla.org/show_bug.cgi?id=1210860#c12.

Comment 8

[Punam Dahiya [:pdahiya]]

David, I need your feedback on data shared in #comment 6. From your experience with gallery and mediaDB, is the lag between new MediaDb() and enumerable event expected. Thanks!

Comment 9

[Punam Dahiya [:pdahiya]]

Hi Ting

Thanks for your analysis as part of https://bugzilla.mozilla.org/show_bug.cgi?id=1210860#c12. Gallery sees similar delay in processing indexedDB open request.

Putting performance.now at indexedDB open request on gallery app start, logs 544.585 ms
https://github.com/mozilla-b2g/gaia/blob/master/shared/js/mediadb.js#L453

And indexedDB open and ready success at Line 497, logs 1230 ms. 
https://github.com/mozilla-b2g/gaia/blob/master/shared/js/mediadb.js#L497

Showing significant lag in opening indexedDB. I believe gecko fix suggested as part of Bug 1214516 should improve this lag. Setting NI flag for you to validate and marking dependency on Bug 1214516. Thanks!

Comment 10

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

Thanks for the heads up. For Video app I can see the content process is simply idling before mediadb is opened, so if we can get the database ready earlier, we can make Video starts up faster.

But the profile in comment 2 didn't show the same idle in Gallery. If the app is busy before mediadb gets ready, there won't be big difference from indexedDB improvements, even you have DB ready earlier, but you still have other works to finish before visullayLoaded.

Though the profile was two months ago, maybe we should capture a new one.

Comment 11

[David Flanagan [:djf]]

(In reply to Punam Dahiya [:pdahiya] from comment #8)
> David, I need your feedback on data shared in #comment 6. From your
> experience with gallery and mediaDB, is the lag between new MediaDb() and
> enumerable event expected. Thanks!

It seems surprising, but it is what I've seen when I've done these measurements too.  So I guess I'd say that numbers like these are what I would expect.

(In reply to Punam Dahiya [:pdahiya] from comment #6)

> The numbers above are using performance.now in logs and shows there is a
> huge lag when MediaDB instance is created and enumerable event is fired,
> hinting indexedDB is idle for a long time before it gets enumerable event.

I think that the enumerable event is sent out as soon as it can. That seems to just be how long it takes to get an indexeddb open and ready to enumerate, at least when gekco is also busy loading the app itself.  I have tried moving the new MediaDB() call even earlier in the startup process, and was never able to get the enumerable event any earlier.

Comment 12

[Bobby Chien]

Raptor [1] shows Gallery is below 1000ms.

[1] http://mzl.la/1RkfCtg