>Timeline Hacking

2009/08/05 — Leave a comment

>I have been meaning to put up a post about our Firefox startup time work. Vlad and Dietrich have been leading some efforts in trying to identify and understand any bottlenecks that occur when Firefox starts up. This is not an easy thing to do, it seems we are need of more profiling tools.

Vlad has been hacking on a set of C++ and JS function timers for little while, and I also pitched in. The patch Vlad started was both a set of timers and a lot of instrumentation. He had me split it up, clean up the timers and change how it logs the timeline data.

The Timeline data looks like this:


> XRE_main
- 190 ms ( 190 ms total) - XRE_main [ScopedXPCOMStartup]
> NS_CreateServicesFromCategory: xpcom-autoregistration (start)
NS_CreateServicesFromCategory: prefservice:after-app-defaults (prefservice:after-app-defaults)
nsIOService::Init
> nsSocketTransportService::Init
- 0 ms ( 0 ms total) - nsSocketTransportService::Init [Created thread]
- 0 ms ( 0 ms total) - nsSocketTransportService::Init [UpdatePrefs]
NS_CreateServicesFromCategory: xpcom-autoregistration (end)
NS_CreateServicesFromCategory: xpcom-startup (xpcom-startup)
nsChromeRegistry::Init
- 0 ms ( 0 ms total) - nsChromeRegistry::Init [NS_RegisterStaticAtoms]
- 0 ms ( 0 ms total) - nsChromeRegistry::Init [GetProtocolHandler 'jar']
- 0 ms ( 0 ms total) - nsChromeRegistry::Init [A]
- 0 ms ( 0 ms total) - nsChromeRegistry::Init [B]
> nsChromeRegistry::CheckForNewChrome
- 4 ms ( 4 ms total) - nsChromeRegistry::CheckForNewChrome [processed chrome manifest /home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/bin/chrome/browser.jar]
- 4 ms ( 8 ms total) - nsChromeRegistry::CheckForNewChrome [processed chrome manifest /home/ddahl/code/moz/mozilla-central/obj-i686-pc-linux-gnu-optimize/dist/bin/chrome/browser.jar]
- 0 ms ( 8 ms total) - nsChromeRegistry::CheckForNewChrome [processed all chrome manifests]
- 0 ms ( 8 ms total) - nsChromeRegistry::CheckForNewChrome [processed all skin manifests]
SetWindowCreator
- 0 ms ( 0 ms total) - SetWindowCreator [RegisterFactory done]
- 0 ms ( 0 ms total) - SetWindowCreator [Got ToolkitChromeRegistry service]
- 17 ms ( 17 ms total) - SetWindowCreator [OS Accessibility check]
...

There are still a few more iterations to go before this patch is checked into Mozilla Central, but I thought I would point it out to developers since it is quite generic and can time any functions in the Mozilla source, not just startup. While vlad, brenden, wan-teh and bsmedberg are iterating on review and “the hard stuff”, I will keep working on placing timers, hopefully with help from other knowledgeable Mozilla hackers.

Here is the latest wiki page on usage.

I am also working some visualization scripts and tools to make it quick to identify the bottlenecks. Right now, I am using MIT’s Simile Timeline. Pretty cool stuff.

I am hoping that some seasoned Moz Hackers might know of more places to insert timers, or perhaps contribute additional targeted timing instrumentation. The cool thing, of course, is that we added an ac_add_option to turn all of this on, otherwise it is noop code, making it pretty clean to use.

If you have any questions we are all hanging out in #startup. Also, send me an email: ddahl mozilla

Advertisements

No Comments

Be the first to start the conversation!

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s