Monthly Archives: April 2010

Making sense of Firefox startup time

One of the things that we at Mozilla would like to do better at is the amount of time it takes between when you launch Firefox, and when it starts up and is usable.  We’ve been tackling this problem for quite a while, and have already made tremendous improvements.  But we think we can still do better.

Last week, Vlad landed the function timer API, which can be used for producing a log of how much time it takes to execute any given code block.  This is a very useful framework for measuring how much time different things consume at Firefox startup.  On Monday, I, Vlad, Shawn, Johnathan, and Shaver started to look into instrumenting Firefox to produce a useful log of what goes on at Firefox startup, to be able to analyze it to identify the areas that we’re being slow at, in order to focus our attention to improve those pieces of code.

I set up a clone of mozilla-central here to so that we can focus on adding probes to the code without being slowed down by trying to lands things on mozilla-central for now.  Then, we started to add probes like crazy.  The probing work is really finished now, and I think that we’ll spend some time tomorrow to try to analyze the logs, in order to be able to make some sense out of them, and identify the areas where we can attack in order to get the most gain in reducing the startup time.

If you want to create your own startup logs, here are the steps to do that.  Please note that these instructions are for Windows.  Other platforms can be measured similarly, but we’re trying to focus our attention to Windows for now.

  1. Clone the repository.
  2. Your measurement would be most useful if you create a build similar to our release versions of Firefox.  In order to do that, you can grab a copy of the mozconfig file which we use for our release builds.  Make sure that you add ac_add_options –enable-functiontimer so that your build actually includes the probes, and remove the –enable-update-channel and –enable-update-packaging options, to make sure that you don’t mess with the release update channels.
  3. Build firefox, and create an installer:
    make -f client.mk build
    make -C objdir package
    make -C objdir installer
  4. Go to objdir/dist/install/sea, you will find a file named something like firefox-3.7a5pre.en-US.win32.installer.exe there.  This is a normal installer.  Use that to install this version of Firefox somewhere on your system.  Please note that you don’t want to replace this with your default Firefox install, since it’s built from a random revision off of mozilla-central, and it’s subject to all the usual warnings when running experimental builds.
  5. Set the MOZ_FT environment variable to the full path of a file which will be used as a log file, for example: C:\Users\ehsan\startup.log.
  6. Execute the installed version of Firefox.  As soon as you see the window on screen, type an address like mozilla.com inside the location bar, press enter, wait for the page to load, and then close Firefox.
  7. Open the log file you specified in step 5.  Try to find the address that you entered in step 6 in that file.  Anything before the first occurence of the address is what happened before Firefox started up and became usable on your system.

Here is a bit of information about the format of the log.  On each line, you will see a pattern like this:

[   123.45] >5)       |nsContentDLF::CreateBlankDocument (line 349)
[   244.43] * (  2)   |        0.50 ms (     0.65 ms total)NS_InitXPCOM3_P (line 480) [Next: timer startup]
[   330.21] < ( 10)           |      3.48 ms (     3.48 ms total)mozJSComponentLoader::Import (line 1444)
(file: resource://gre/modules/XPCOMUtils.js)

Here is what each of these items mean:

  • Time stamp in ms.  This is the time passed since Firefox was started when this message was being added to the log.
  • >, *, or <.  These include three types of logs: function entry, function marker, and function exit, respectively.  The first and last ones are obvious.  The function marker is used for a few very large functions in order to enable us split up the function’s execution time in chunks, so that we can know how much time a function took to execute.
  • Call nesting depth.  It is a number indicating the depth of the call.  It can be used to show whether a function has been called (directly or indirectly) by another one.
  • Function name and line number.  It shows the function in which the log was recorded, and which line in the respective source code it has been defined on.
  • Elapsed time and total time.  These two numbers show how much time has been elapsed inside the function, and how much total time the function has been executed so far.  Note that these numbers are not applicable to function entries.  Also, note that they will be equal on function exit, because the log is generated as the last step inside the function.
  • Marker identifiers.  These are only used for function markers, and usually show what is going to happen next inside the function.
  • Extra information.  Some of the log lines have some extra information associated with them.  For example, the third line in the sample above shows that the module being loaded was XPCOMUtils.js.

Johnath has also adapted a script to generate graphs from the logs, but at this point, we’re thinking that the graphs are misleading, and therefore I’m not going to talk more about this, but check the bug for more information (including how to create such graphs, and some graph samples.)

The next steps probably include finding out where there are gaps in our logs, and try to add probes to cover those areas.  We also need to generate logs for a range of different profiles, including blank and heavy ones.  We need to generate a variety of logs to ensure that we’re not missing any obvious use case of Firefox.  We are also trying to figure out which types of visualizations for this data would be helpful, to be able to better filter/present the generated logs.  Hopefully, we’ll soon have a number of actionable tasks which we can pursue to reduce Firefox startup time to a significant degree.

If you have any ideas how to improve things, or have any logs which we need to see, either comment here or in the bug.

Posted in Blog Tagged with: , , ,

Assisted starring of oranges

As a good citizen in the Mozilla developer community, you need to watch the tree, and star any random oranges with bug numbers, and put a comment inside the relevant bugs with a link to the log of the orange in order to help debugging the problem.  That’s too much work, and worse, it’s repetitive and boring.  Last weekend, I got sick of it, and decided to hack Tinderboxpushlog to make this a bit easier.  That work is now deployed on Markus‘ instance of Tinderboxpushlog for you all to enjoy.

How to use it?

It’s easy.  Click on a machine name in a build.  A summary of the log appears.  If there are any suggestions available, they will be listed inside the summary, like below.

Bug suggestions inside the log summary

Here, Tinderboxpushlog has found three suggestions for the test failure.  It’s your job to go and read the bugs to figure out which one of the three this failure is related to.  Also, note that the third suggestion has been marked as strike-through, that’s because it’s a resolved bug (I chose to show the suggestions for bugs which have already been resolved because sometimes they need to be reopened, and sometimes there are not resolved on the branch that you’re watching.)  The status of each bug appears as a tooltip of its link.

After you choose which bug is relevant, and you want to star it, you press the Add a comment link as usual.  The dialog which appears should contain suggestions in addition to the usual fields, like below:

Suggestions in the Add Comemnt dialog

You can click on any of the suggestions, and Tinderboxpushlog will add that bug to the comment box.  From that point, you can modify the comment text if needed, and click Add Comment when you’re done.  The orange will be starred as usual, but something else happens as well:

TinderboxPushlog Robot making a comment on the bug

We have hired a robot whose only job is to watch the tinderbox, and go ahead and add a comment to the bug with the log link and a bunch of helpful info.  Please meet TinderboxPushlog Robot, or as his friends call him, tbplbot.  He’s not that smart, but he knows not to comment on the same bug about the same log twice.  I’m posting a picture of him due to popular demand:

TinderboxPushlog Robot

Are there any insider tips?

Just one.  If for some reason you don’t want to add a comment to the bug, you should avoid clicking on the bug link in the Add a Comment dialog (and type in the bug number if you want).  tbplbot is smart enough to honor your request and not comment in the bug.

Wait, I don’t get suggestions in my summary logs!

In order to maximize the performance, and minimize the chance of double-starring, we don’t show suggestions for already-starred logs.  Also, the suggestions are made by looking at the log summary for file names, and looking them up in Bugzilla, so they won’t work for things which typically don’t have those in the log summary, such as leaks and crashes.  If there is a file name, the log is not starred, and still no suggestions appear, there might be a good chance that there’s no bug on file for that orange.  But remember, you should go ahead and search Bugzilla yourself to make sure that the algorithm has not missed something.

I want to help!

Great!  Clone Markus’ repository, file a bug for what you want to do, and hack away!

That’s it!  Go and star some oranges.  Or better yet, try to fix a few of them!

Posted in Blog Tagged with: , ,

Text field lazy initialization

I just landed a set of patches on mozilla-central which makes the initialization of the editor for text fields (input type="text" and input type="password" in HTML terms) lazy.  What we used to do was to initialize the editor component for text fields as soon as we created frames for those elements.  This was not ideal, because users don’t usually use all of those fields on web pages (think about the "search" text fields you see on every website nowadays, for example.)  It also made Gecko significantly slow for pages which included a lot of those elements.

What these patches do is that they defer the initialization of the editor component (which actually allows you to type into the fields, copy and paste stuff, undo/redo your edits, etc.) until when the user is most likely to use it (for example, when the control is focused, or receives keyboard input.)

The work to make this happen was a lot more than I originally anticipated.  It uncovered a number of other problems, which I’ve already fixed or I’m going to.  It also proved to be a long journey as I saw different changes in the tree break my work a lot.  Overall, those problems should have made the patches more robust, but I thought I’d post this change here so that nightly testers can have it in their minds in order to track any possible regressions.  These changes will be in tomorrow’s nightly build.

Update: Actually, I spoke too soon.  The changes caused a problem and I had to back them out.  Hopefully the problem is resolved soon and I’ll re-land the patches.

Update 2: The code has landed and  has been stabilized on trunk now.

Posted in Blog Tagged with: , ,

User name autocomplete in Bugzilla

Atul Varma has built an user name autocomplete tool for Bugzilla.  This reminded me that it’s been a long time since I wanted to add this functionality to the Bugzilla Tweaks jetpack.  Last week I added this feature, but I didn’t get the time to blog about it!

Here is how it looks on a a sample bug:

User name autocomplete for the Assignee field

It is also smart enough to handle multiple users for fields which accept it.

User name autocomplete for multiple users

It works on almost everywhere in Bugzilla where you can enter a user name.  Here is the full list for the curious:

  • CC field on bug pages (both when viewing and filing a new bug)
  • Assignee field on bug pages (both when viewing and filing a new bug)
  • Requestee field on attachments (when you request a flag, like review, from someone)
  • User name entry fields on the advanced search page
  • Add user watch field on the preferences page

This is providing the same functionality of Atul’s tool, with two added benefits: it provides the functionality right where you need it, and doesn’t require you to enter your user name and password.

No more memorizing people’s email addresses!  No more asking around for their email addresses!  No more bugzilla error pages telling you that the user name you entered doesn’t exist, or couldn’t be matched exactly!  I hope you like the idea.

The jetpack lives here.  If you have already installed it, you can either rely on Jetpack Prototype’s auto-update feature, or refresh it manually.

Posted in Blog Tagged with: , ,

Jetpack Prototype with trunk support

If you use Firefox nightly builds, and you had the Jetpack Prototype installed, you might have noticed that about two weeks ago, your jetpacks had started to get disabled a short while after you had opened your browser.  This issue was really frustrating, since some of us run jetpacks which are very important in our daily work.

I filed bug 554169 about this issue.  Paul O’Shannessy fixed this, and earlier this week, the Jetpack team released a new version of the Jetpack Prototype which fixes this issue.  You can install it from AMO, and your jetpacks will resume working reliably on nightly builds.

Thanks a lot to Paul, Myk and Atul for making this happen!

Posted in Blog Tagged with: , ,