Chris Jones [:cjones] inactive; ni?/f?/r? if you need me Reporter
	Description • 12 years ago

This will be a common occurrence when b2g is under memory pressure.  Cold startup involves OS process fork/exec, dynamic link, XPCOM startup, then sundry gecko init and actually loading the homescreen resources.

	Chris Jones [:cjones] inactive; ni?/f?/r? if you need me Reporter
	Comment 1 • 12 years ago

The easiest way to force a cold start of the homescreen is
 - load the Maps app
 - pan around the map for 30 seconds or so
 - press the HOME key

The maps app usually consumes enough memory to kill off the homescreen.  (Which is due to both using too much memory, but let's deal with that separately.)  For the purposes of this bug, let's pretend that the maps app represents The General Fat Internet, which we'll have to face.

	Gabriele Svelto [:gsvelto]
	Comment 2 • 12 years ago

I've attached a profile of the home screen app doing a cold startup. The total startup time seems ~6.5s with time roughly split as following:

- ~900ms of startup involving a bunch of calls that look like initialization work (XPCOM, manifest parsing, various unnamed libc calls)

- ~2200ms spent in a long html5::RunFlushLoop() call of which ~1600ms in what looks like a single JS:EvalString() call (again with a significant libc component)

- Lots and lots of time spent in js::RunScript() calls doing a bunch of things (loading and initializing the apps, loading bookmarks, icons, etc...)

	Chris Jones [:cjones] inactive; ni?/f?/r? if you need me Reporter
	Comment 3 • 12 years ago

(In reply to Gabriele Svelto [:gsvelto] from comment #2)
> Created attachment 668231 [details]
> Home screen cold startup profile
> 
> - ~900ms of startup involving a bunch of calls that look like initialization
> work (XPCOM, manifest parsing, various unnamed libc calls)
> 

Hm!  Do the samples give you a hint at what manifests are being parsed?  That shouldn't show up on profiles.

Under what sample labels are the unidentified libc calls showing up?

> - ~2200ms spent in a long html5::RunFlushLoop() call of which ~1600ms in
> what looks like a single JS:EvalString() call (again with a significant libc
> component)

Hmmmm, that is not good indeed.  Seems like we're loading a lot more JS than we need in the homescreen.  We might need to manually instrument to see what string is being evaluated here.

> - Lots and lots of time spent in js::RunScript() calls doing a bunch of
> things (loading and initializing the apps, loading bookmarks, icons, etc...)

Are you seeing samples from particular .js files?  It would be helpful to charge this time to particular code in the homescreen, so we can help gaia folks cut down on what's being run at startup.

	Gabriele Svelto [:gsvelto]
	Comment 4 • 12 years ago

(In reply to Chris Jones [:cjones] [:warhammer] from comment #3)
> Hm!  Do the samples give you a hint at what manifests are being parsed? 
> That shouldn't show up on profiles.

It was just one among many calls I spotted there, but not the longest one. The problem with those first ~700ms is that they look all over the place, lots of small methods and no big hotspot.

> Under what sample labels are the unidentified libc calls showing up?

They show up as unidentified symbols belonging to libc.so, e.g.:

"?? (in /system/lib/libc.so)"

Maybe the libc library has been mostly stripped from symbols? I'll have a look at the build system to figure out if we can get better data out of it.

> Hmmmm, that is not good indeed.  Seems like we're loading a lot more JS than
> we need in the homescreen.  We might need to manually instrument to see what
> string is being evaluated here.

I can see a lot of gaia components being executed in there (appmanager.js, homescreen.js, etc...). I'll have a look at the JavaScript source to figure out what's going on.

> Are you seeing samples from particular .js files?  It would be helpful to
> charge this time to particular code in the homescreen, so we can help gaia
> folks cut down on what's being run at startup.

Yes, two big time sinks csp_shouldLoad() from contentSecurityPolicy.js and convertAppsArray() from Webapps.js. Both together account for 700ms.

	Chris Jones [:cjones] inactive; ni?/f?/r? if you need me Reporter
	Comment 5 • 12 years ago

(In reply to Gabriele Svelto [:gsvelto] from comment #4)
> (In reply to Chris Jones [:cjones] [:warhammer] from comment #3)
> > Are you seeing samples from particular .js files?  It would be helpful to
> > charge this time to particular code in the homescreen, so we can help gaia
> > folks cut down on what's being run at startup.
> 
> Yes, two big time sinks csp_shouldLoad() from contentSecurityPolicy.js and
> convertAppsArray() from Webapps.js. Both together account for 700ms.

These are both part of gecko.  It's not expected that they're taking that long.

	Jonas Sicking (:sicking) No longer reading bugmail consistently
	Comment 6 • 12 years ago

cc'ing Sid who wrote the CSP stuff.

	[:fabrice] Fabrice Desré
	Comment 7 • 12 years ago

convertAppsArray() from a getAll() call has to wrap all the manifests since we enforce __exposedProps__ on js object sent from chrome to content. This may cost a lot indeed, we should try to do something lazy here instead.

	Chris Jones [:cjones] inactive; ni?/f?/r? if you need me Reporter
	Comment 8 • 12 years ago

We have a good handle on this now.