Closed Bug 1024005 Opened 10 years ago Closed 10 years ago

Gaia Email App Startup Time Regression


(Firefox OS Graveyard :: Gaia::E-Mail, defect, P1)

Gonk (Firefox OS)


(Not tracked)

2.0 S4 (20june)


(Reporter: mchang, Assigned: jrburke)



(Keywords: perf, regression, Whiteboard: [c=regression p= s= u=])

Bug 1018534, created an email FTU regression of ~20-30ms.
Results for Email, cold_load_time: median:623, mean:627, std: 28, max:732, min:581, all:657,636,622,621,647,613,581,633,625,643,632,606,623,596,612,639,603,633,664,615,614,592,617,732,633
Results for Email, cold_load_time: median:622, mean:633, std: 39, max:724, min:578, all:682,610,643,608,724,609,623,692,626,617,640,616,596,578,581,637,674,602,633,622,603,723,616,615,679
Results for Email, cold_load_time: median:616, mean:623, std: 28, max:704, min:576, all:659,669,626,611,593,608,614,660,634,614,620,601,704,604,616,616,622,628,576,579,624,613,604,661,638

moz-central backout 1014410, gaia tip
Results for Email, cold_load_time: median:628, mean:639, std: 36, max:711, min:581, all:661,625,640,688,613,610,628,637,598,655,637,697,619,634,581,702,711,625,657,610,602,606,620,711,627
Results for Email, cold_load_time: median:629, mean:636, std: 30, max:701, min:592, all:642,643,642,620,605,627,592,651,683,613,648,612,701,618,682,698,690,614,607,629,628,629,598,614,637
Results for Email, cold_load_time: median:619, mean:627, std: 30, max:703, min:592, all:651,614,624,608,601,696,598,699,619,612,606,625,656,620,592,652,703,613,626,624,602,608,612,612,620

Gaia 1018534 back out
Results for Email, cold_load_time: median:608, mean:624, std: 40, max:692, min:577, all:615,638,631,594,679,590,605,659,682,581,619,583,686,608,577,598,593,678,591,688,580,600,692,669,587
Results for Email, cold_load_time: median:591, mean:598, std: 25, max:665, min:571, all:625,593,581,594,576,594,584,571,623,577,577,603,612,579,585,665,664,591,603,629,614,581,579,579,573
Results for Email, cold_load_time: median:602, mean:601, std: 25, max:661, min:564, all:649,625,625,583,567,580,620,606,593,629,591,564,570,631,605,607,602,573,586,578,578,592,614,661,618

Gaia: f5466f4
Gecko: 187866:13be61241671
Anything we can do about this?
Flags: needinfo?(jrburke)
OS: Mac OS X → Gonk (Firefox OS)
Priority: -- → P1
Hardware: x86 → ARM
Do we think it's a question of permission check costs?  Like say there's a fast-path for certified apps since we can say "yes" almost instantly but for privileged we need to round-trip the lookup/etc.?  If so, that would imply this is a platform bug that is meaningful since it would be slowing down all apps and putting non-built-in apps at a disadvantage.  And I suppose the email mitigation would be to touch less things that trigger permission checks during the startup path.
I'm not really sure. James thought backing out 1014410 on the platform might help, but that didn't change anything. Vivien, do you know the answer to comment 3? Thanks!

The other thing I see in the commit is the acceptContactsPermission. This might be invoked when the app is started and that's why the regression comes?
Flags: needinfo?(21)
I tried with the template app, which is really basic, some results:

template app: type="certified";
Results for Template, cold_load_time: median:456, mean:451, std: 38, max:501, min:266, all:266,501,484,481,471,442,467,462,468,432,458,455,463,468,445,465,485,446,440,455,450,447,460,431,461,444,434,454,438,472

template app: type="privileged", no permissions section:
Results for Template, cold_load_time: median:456, mean:455, std: 31, max:502, min:314, all:314,487,464,467,445,454,455,450,466,437,440,451,469,458,461,450,466,449,450,475,483,434,480,499,443,466,426,452,482,502

template app: type="privileged", permissions: all same as email:
Results for Template, cold_load_time: median:458, mean:461, std: 42, max:567, min:276, all:276,456,494,489,465,457,458,441,489,477,455,450,456,480,464,473,450,450,472,486,436,506,475,567,456,459,452,462,448,452

So no built in cost to just the type setting. I also tried with the email app by reducing the number of "permissions" entry to just "storage":{}, "device-storage:sdcard":{ "access": "readcreate" }, but no difference in timings.

So current state of a guess at the end of today is that the actual use of the APIs incurs some extra cost now. Have not narrowed it down further though, just reporting what data was gathered so far.
Flags: needinfo?(jrburke)
Assignee: nobody → jrburke
Certified apps have a fast path CSP checker that we don't use for privileged apps. That likely explain the slowdown you see here.
(In reply to Mason Chang [:mchang] from comment #4)
> I'm not really sure. James thought backing out 1014410 on the platform might
> help, but that didn't change anything. Vivien, do you know the answer to
> comment 3? Thanks!
> The other thing I see in the commit is the acceptContactsPermission. This
> might be invoked when the app is started and that's why the regression comes?

What Fabrice says. It would be easy to double check that this is related to CSP by simply turning it off (security.csp.enable = false) in the prefs.
Flags: needinfo?(21)
More time capture, median times:

1) privileged: 663
2) privileged with user_pref("security.csp.enable", false): 623
3) certified: 645
4) certified with user_pref("security.csp.enable", false): 623
5) privileged, with no calls to mozContacts: 671
6) privileged, using cookie cache: 677

Disabled CSP helps both the certified and privileged cases. 

5) was testing if not accessing mozContacts on startup would positively affect the time, but I believe what happened is that the non-mozContacts paths just executed the code that would have been in a contacts API callback immediately, resulting in more up front execution.

When looking at the logs during the tests, the cookie cache was not being used, it was not getting set before the app was shut down. So for 6) I opened the app one time to generate the cache, then ran the tests.

The cache route loads a small JS file, synchronously injects HTML that references images, then starts the load of the rest of the JS.

The email app now emits the startup events for logging, which capture the different states better than this metric might, so those are probably the better numbers to look at over the long haul.

Since bug 1027185 will switch the email app's manifest back to certified for other reasons, that will also likely moot this bug, and I will it when the other bug lands. Hopefully that will also give us a historical base for the startup event numbers if we do switch email back to priviliged.


Raw data, run on a hamachi:

Gaia      eac13407742a55b11e1877b4df2abdfd22cd582e
BuildID   20140617040203
Version   33.0a1 Dec 19 14:04:55 CST 2013

Email from: git commit b889fdf33a15440eaab9253ab845543126956a7f

To push each change: make GAIA_OPTIMIZE=1 NOFTU=1 reset-gaia

b2gperf --delay=10 --reset --iterations=30 E-Mail

Results for E-Mail, cold_load_time: median:663, mean:659, std: 41, max:730, min:474, all:474,696,663,676,661,673,655,646,660,621,730,672,704,672,668,692,615,642,653,679,663,676,659,683,662,679,665,661,663,623

privileged with user_pref("security.csp.enable", false):
Results for E-Mail, cold_load_time: median:623, mean:629, std: 64, max:867, min:405, all:405,657,603,656,630,622,614,656,606,629,623,645,867,622,600,649,613,638,623,614,654,722,630,611,604,620,593,624,630,619

 Results for E-Mail, cold_load_time: median:645, mean:647, std: 47, max:756, min:466, all:466,701,645,646,620,673,643,657,652,642,632,654,739,708,636,636,614,657,611,650,632,688,635,653,626,756,637,649,621,652

certified with user_pref("security.csp.enable", false):
Results for E-Mail, cold_load_time: median:623, mean:619, std: 44, max:707, min:408, all:408,664,627,624,600,624,610,626,614,623,595,615,707,616,618,640,598,601,621,627,623,622,640,645,607,621,633,624,659,640

privileged, with no calls to mozContacts
Results for E-Mail, cold_load_time: Results for E-Mail, cold_load_time: median:671, mean:677, std: 54, max:854, min:475, all:475,710,664,678,654,670,655,664,687,726,657,719,666,696,658,854,666,671,675,760,657,685,651,672,666,684,653,677,709,680

privileged, using cookie cache
Results for E-Mail, cold_load_time: median:677, mean:683, std: 56, max:782, min:457, all:457,725,653,693,778,685,676,677,643,667,668,744,674,707,682,662,662,678,680,663,682,705,654,673,677,681,651,782,762,761
Depends on: 1027185
Email app back to being certified. Closing this out. Future comparisons with app startup events likely a better gauge to consider perf impact if privileged is considered in the future.
Closed: 10 years ago
Resolution: --- → WONTFIX
Target Milestone: --- → 2.0 S4 (20june)
(cleaning up email wontfix bugs: setting this to WFM since we resolved the problem by backout.  invalid might also work.)
You need to log in before you can comment on or make changes to this bug.