Categories
Mozilla Technology

Using Xperf to Track I/O

Back in December when I was working on the Places branch, I was using Xperf quite a bit to try and figure out why we were regressing certain performance tests. Xperf is an incredibly powerful tool, but it’s really hard to get it to do what you want sometimes. This is largely due to the fact that the documentation isn’t great, and there appears to be wrong information on the Internet (from blogs, which tend to be more useful than the documentation).

I cared about getting information about hard faults, file I/O, and disk I/O to see if patterns changed with my work. In order to accomplish this, I started Xpef like this (from an admin console):
xperf -start "NT Kernel Logger" -on PROC_THREAD+LOADER+HARD_FAULTS+FILE_IO+FILE_IO_INIT+DISK_IO -stackwalk FileWrite+FileRead+FileFlush -MaxBuffers 1024 -BufferSize 1024 -f output.etl
The first list options after -on is a list of providers. To see the list of installed kernel providers on your system and what they do, open up a command prompt, and run xperf -providers K.
The options after -stackwalk tells Xperf to get call stacks for certain events. The full list of events supported can be found here. I found it very difficult to get stacks, and if you are on a 64-bit version of windows, you have an extra hoop to jump through. I was actually never able to get stacks from an optimized build with symbols, so I ended up just using debug builds when I needed stacks, and opt builds when I wanted good numbers for everything else.
The -MaxBuffers and -BufferSize arguments were useful to prevent events from being dropped (if Xperf doesn’t have enough memory set aside to record an event, it just drops it). You can tweak those values to your needs, but the values I used should be fine.

Once I ran that command in my console, I’d perform the test I wanted to get data on. Upon completion, Xperf needs to be told to stop, and then have it merge (merging may be unnecessary when you only use kernel providers, but I never tested this theory):
xperf -stop "NT Kernel Logger"
xperf -merge output.etl output_final.etl

You can now open output_final.etl to examine the data you just gathered!

Categories
Mozilla

Changes to how Places stores data incoming

Sometime soon after the beta 8 code freeze, the Places team will be merging the Places branch into mozilla-central. There are a lot of changes we’ve been working on, the most important of which is some major re-architecting how we store data.

The Benefits

The work on the Places branch brings us a number of benefits. In general, we’ve parallelized work, and made it substantially less likely that we’ll block on the GUI thread. Some of the important fixes we have landed are:

  • Faster Location Bar
    The location bar is faster because other database work no longer blocks us from searching, and the queries are much simpler.
  • Asynchronous Bookmark Notifications
    Indicating if the current page is bookmarked in the location bar (with the star) is now an asynchronous operation that does not block the page load.
  • Faster Bookmarks & History Management/Searches
    Simpler queries and other improvements should make this all work faster.
  • Faster Link Coloring
    Link coloring is now executed on a separate database connection so it cannot block other database work.
  • Expiration Work
    Less work at startup, less work at shutdown, and less work when we run expiration.
  • Less Data Stored
    Embedded pages are now tracked only in memory and never hit the disk.
  • Better Battery Management
    Much less work during idle time, which will improve our power consumption behaviors.
  • Fixes 29 blockers and 18 other issues

A bit of History

Way back in the days leading up to Firefox 3.5, we moved from storing all of our history and location data in disk tables to in-memory tables that we’d flush out to disk every two minutes off of the GUI thread. The benefit of this was two-fold:

  1. No longer performing the vast majority of our disk writes on the GUI thread
  2. No longer performing the vast majority of our fsyncs/Flushes on the GUI thread

More details about how we came up with this solution can be found in a series of blog posts.

The Problem

This solution has worked out pretty well for us for a while, but recently, especially on OS X, it has not been. The short story is that our architecture did not scale well due to lock contention between our GUI thread and our background I/O thread. While the common case access case may be fine, the failure case (when we hit lock contention) is pretty terrible. The problem is so terrible that I once described it like this:

the failure case makes us fall on our faces, skid about 100 feet, and then fall off a cliff without a parachute.

Ultimately, the only way we can avoid this situation is to not do any database work on separate threads with the same database connection. It was not an issue in the past because we just did not do enough work on the I/O thread, but as we have added to the workload of that thread, we increase the likelihood of it holding the lock, which means there is a higher probability that the GUI thread will not be able to instantly acquire the lock and do whatever it needs to do. This essentially leaves us with two options:

  1. Move the rest of our database work off of the GUI thread.
  2. Move database work from the I/O thread back to the GUI thread.

The Solution

The second choice is not actually a viable option. Disk I/O completes in a non-deterministic amount of time, which is why we have been moving it from the GUI thread to an I/O thread since Firefox 3.5. The first choice is not entirely viable either due to schedule constraints either (we have tons of API calls that are not used heavily but still synchronous). A hybrid solution exists, however. We can reduce the amount of work we do on the I/O thread by using additional I/O threads. Additionally, we can move the remaining synchronous operations during browsing to an I/O thread. In the end, Places ends up with one read/write thread, and multiple read-only threads.

This wasn’t really an option back in the Firefox 3.5 days because in SQLite readers and writers blocked each other. However, the SQLite developers recently devised a new journaling method called WAL that lets readers not block writers, and writers not block readers. When the Places branch merges into mozilla-central, we will end up with three read-only I/O threads and our original read-write I/O thread. The three read-only threads are used for location bar searches, visited checks (is a given hyperlink visited), and some bookmark operations. Each I/O thread has its own connection to the database, allowing operations to happen in parallel (SQLite is only threadsafe because it serializes all access on each connection object, which is why we had the lock contention in the first place).

Performance Test Issues

One of the things that made this work especially difficult is seemingly random changes in performance numbers. We often had regressions suddenly appear (according to talos) on changesets that would have zero impact on performance, and then backing out the change would cause an additional regression. Other times, when we would merge mozilla-central into Places, we would suddenly get new regressions when comparing to mozilla-central. This could be indicative of a bad interaction with our code and the changes on mozilla-central, however after looking at the changes on mozilla-central that landed with the merge, that appeared to be highly unlikely.

I’m also quite certain that some of our performance tests do not actually test/measure what we actually want to test/measure. I’ll leave that discussion to a future blog posts, however.

Categories
Mozilla

Startup Time in the Wild Take Three

Over a week ago, I collected the data I said I was going to look at last time. I finally had a chance to look at the data (startup times with and without add-ons for two profiles on the latest version of 3.6), and my hypothesis was not verified. That means it is back to the drawing board for me. The graphs are not at all interesting, so I am not going to post them. At this point, I think the goal is officially at risk. With the profiles we got, I am not even seeing slow startups with cold startup. It is hard to diagnose a problem you cannot reproduce, sadly.

Next Step

Next week I am going to sync up with limi and get some contact information from the people that sent these profiles to us. We are going to have to do some remote debugging to see why they see such slow startup times.

News on the Past

Paul is feverishly working on a solution to make session restore not kill us on startup. He even has some test builds which you can download and test, but these are experimental. You should make a copy of your profile as a backup when using this test build in case things go boom.

Categories
Mozilla

Startup Time in the Wild Take Two

This week, I spent some time looking at some real life profiles that were sent into us by users seeing startup time in the minutes. The tests were ran just like I ran the test on my profile: all add-ons disabled. The results I got are both good and bad, but first the results!

Results

The first shows the raw test run data (which isn’t terribly interesting). The second compares the reported startup time for each test. You will probably want to click to zoom in.

Conclusions

Like I said, the results are both good and bad. Good in that I now have a pretty good idea on why people have bad startup times. Bad in that we don’t have any way to quickly improve the issues that people are seeing. What I see from this data is that profiles in the wild, with add-ons disabled aren’t much slower than a clean profile. This seems to implicate add-ons being at least part of the problem (which we knew) or possibly all of the problem at this point (for the profiles tested). The good news is that the add-ons team is already working on solutions to this, and you should expect some blog posts from them about this soon.

Next Step

Next week I’m going to spend some time getting numbers with these profiles on the latest release of Firefox 3.6 with and without add-ons disabled to compare. This will pretty much confirm or deny my hypothesis of this week’s results.

News on the Past

In my last post, we looked at my profile with various pieces removed to try and figure out why startup might be slow for people. With those results, I identified two issues that would impact startup the most:

  1. Large cookies.sqlite
  2. Many tabs being restored

I also have good news about both of these issues! The cookies.sqlite issue is now fixed and will be a part of beta 4, and Paul has some good data about session restore and tabs (with more to come).

Categories
Mozilla

Bugzilla Helper 0.4.2 Released

You can go grab it on AMO or wait for Thunderbird to tell you to update. This contains a one-line work around that makes the add-on work after the semi-recent change in the API. You can read all the fun details over in bug 586032.