Controlled Flight Into Terrain

Earlier this year (in Firefox 32), we landed a fix for bug 760356, to reduce how often we delay starting up the browser in order to check whether all your add-ons are compatible. We landed the related bug 1010449 in Firefox 31 to gather telemetry about the compatibility check, so that we could to before/after analysis.

Background

When you upgrade to a new version of Firefox, changes to the core browser can break add-ons. For this reason, every add-on comes with metadata that says which versions of Firefox it works with. There are a couple of straightforward cases, and quite a few tricky corners…

• The add-on is compatible with the new Firefox, and everything works just fine.
• The add-on is incompatible and must be disabled.
  • But maybe there’s an updated version of the add-on available, so we should upgrade it.
  • Or maybe the add-on was installed in a system directory by a third party (e.g. an antivirus toolbar) and Firefox can’t upgrade it.
• The add-on says it’s compatible, but it’s not – this could break your browser!
  • The add-on author could discover this in advance and publish updated metadata to mark the add-on incompatible.
  • Mozilla could discover the incompatibility and publish a metadata override at addons.mozilla.org to protect our users.
• The add-on says it’s not compatible, but it actually is.
  • Again, either the add-on author or Mozilla can publish a compatibility override.

We want to keep as many add-ons as possible enabled, because our users love (most of) their add-ons, while protecting users from incompatible add-ons that break Firefox. To do this, we implemented a very conservative check every time you update to a new version. On the first run with a new Firefox version, before we load any add-ons we ask addons.mozilla.org *and* each add-on’s update server whether there is a metadata update available, and whether there is a newer version of the add-on compatible with the new Firefox version. We then enable/disable based on that updated metadata, and offer the user the chance to upgrade those add-ons that have new versions available. Once this is done, we can load up the add-ons and finish starting up the browser.

This check involves multiple network requests, so it can be rather slow. Not surprisingly, our users would rather not have to wait for these checks, so in bug 760356 we implemented a less conservative approach:

• Keep track of when we last did a background add-on update check, so we know how out of date our metadata is.
• On the first run of a new Firefox version, only interrupt startup if the metadata is too out of date (two days, in the current implementation) *or* if some add-ons were disabled by this Firefox upgrade but are allowed to be upgraded by the user.

Did it work?

Yes! On the Aurora channel, we went from interrupting 92.7% of the time on the 30 -> 31 upgrade  (378091 out of
407710 first runs reported to telemetry) to 74.8% of the time (84930 out of 113488) on the 31 -> 32 upgrade, to only interrupting 16.4% (10158 out of 61946) so far on the 32 -> 33 upgrade.

The change took effect over two release cycles; the new implementation was in 32, so the change from “interrupt if there are *any* add-ons the user could possibly update” to “interrupt if there is a *newly disabled* add-on the user could update” is in effect for the 31 -> 32 upgrade. However, since we didn’t start tracking the metadata update time until 32, the “don’t interrupt if the metadata is fresh” change wasn’t effective until the 32 -> 33 upgrade. I wish I had thought of that at the time; I would have added the code to remember the update time into the telemetry patch that landed in 31.

Cool, what else did we learn?

On Aurora 33, the distribution of metadata age was:

so about 88% of profiles had fresh metadata when they upgraded. The tail is longer than I expected, though it’s not too thick. We could improve this by forcing a metadata ping (or a full add-on background update) when we download a new Firefox version, but we may need to be careful to do it in a way that doesn’t affect usage statistics on the AMO side.

What about add-on upgrades?

We also started gathering detailed information about how many add-ons are enabled or disabled during various parts of the upgrade process. The measures are all shown as histograms in the telemetry dashboard at http://telemetry.mozilla.org;

SIMPLE_MEASURES_ADDONMANAGER_XPIDB_STARTUP_DISABLED

The number of add-ons (both user-upgradeable and non-upgradeable) disabled during the upgrade because they are not compatible with the new version.

SIMPLE_MEASURES_ADDONMANAGER_APPUPDATE_DISABLED

The number of user-upgradeable add-ons disabled during the upgrade.

SIMPLE_MEASURES_ADDONMANAGER_APPUPDATE_METADATA_ENABLED

The number of add-ons that changed from disabled to enabled because of metadata updates during the compatibility check.

SIMPLE_MEASURES_ADDONMANAGER_APPUPDATE_METADATA_DISABLED

The number of add-ons that changed from enabled to disabled because of metadata updates during the compatibility check.

SIMPLE_MEASURES_ADDONMANAGER_APPUPDATE_UPGRADED

The number of add-ons upgraded to a new compatible version during the add-on compatibility check.

SIMPLE_MEASURES_ADDONMANAGER_APPUPDATE_UPGRADE_DECLINED

The number of add-ons that had upgrades available during the compatibility check, but the user chose not to upgrade.

SIMPLE_MEASURES_ADDONMANAGER_APPUPDATE_UPGRADE_FAILED

The number of add-ons that appeared to have upgrades available, but the attempt to install the upgrade failed.

For these values, we got good telemetry data from the Beta 32 upgrade. The counts represent the number of Firefox sessions that reported that number of affected add-ons (e.g. 3170 Telemetry session reports said that 2 add-ons were XPIDB_DISABLED by the upgrade):

The things I find interesting here are:

• The difference between XPIDB disabled and APPUPDATE disabled is (roughly) the add-ons installed in system directories by third party installers. This implies that 80%-ish of add-ons made incompatible by the upgrade are 3rd party installs.
• upgraded + declined + failed is (roughly) the add-ons a user *could* update during the browser upgrade, which works out to fewer than one in 2000 browser upgrades having a useful add-on update available. I suspect this is because most add-on updates have already been performed by our regular background update. In any case, to me this implies that further work on updating add-ons during browser upgrade won’t improve our user experience much.

Felipe landed the Addon Repository (Bug 853389) changes on Aug 1, so they rode the uplift train and are currently in Firefox Aurora (25). My changes for the XPI Provider (Bug 853388), aside from the Telemetry measurements, landed on Sunday (Aug 11) and are in the latest nightly (Firefox 26). I still need to make some changes to the Telemetry patch and get that through reviews, but the core of the work is finally done.

There are a few follow-up bugs that need to be prioritized and sorted out:

• 902950: Fix test TODO left over from bug 853388
• 902956: Preserve unknown fields in XPI JSON database
• 903093: Ensure that XPI and AddonRepository JSON is completely written before shutdown
• 903818: Handle shutdown during asynchronous load of JSON XPI Database

Many thanks to Felipe for his work on the Addon Repository, and to Blair McBride for reviewing everything.

As part of switching the Firefox extensions databases from sqlite to a flat file containing JSON, we want to build a module that flushes the in-memory state of the data out to disk after it changes, in a way that doesn’t hang the main thread waiting for the I/O to complete. Felipe did an initial implementation for bug 853389 based on the DeferredTask module, and I’ve been working on sorting out all the edge cases that the XPIDatabase tests trigger. Unfortunately, there are plenty of edge cases. As a result the attempted implementation is getting rather twisted, so I wanted to put up the current state of my design both to clarify it in my own mind, and to solicit input on ways we could simplify. In particular, I’d like to hear from people who have a good feel for Promise based asynchronous code, to see if there’s an idiomatic Promise based implementation that is more straightforward than the current approach with explicit callbacks.

The basic assumptions of the design are:

• The working copy of the data is a JavaScript tree is mapped to and from the on-disk structure.
• All modification of the data is done through the JS structure, so the data only needs to be read in once at start up time.
• When we decide to write the data, we take a snapshot (via JSON.stringify) and then start the async I/O.
• There is no locking; the in-memory data can be modified while we’re saving the snapshot.
• We wait for a short time after the in-memory data is modified before we start writing, so that we can coalesce sets of changes into a single write.
• Clients indicate that the data needs to be saved by calling saveChanges(), and can optionally be notified (by callback or Promise resolution) when all in-memory changes up to the time saveChanges() was called have been written to disk.

The core states for data saving are:

1. In memory data is clean and synced to disk
2. In memory data is dirty, waiting before syncing snapshot to disk
3. Memory clean, writing of snapshot in progress
4. Memory dirty, writing of snapshot in progress

With the API that Felipe built for AddonRepository, we support clients providing a callback when they mark the data dirty, and that callback will be invoked after the change in question is written to disk.

In normal operation, the state transitions are:

Clean/Synced –> (modify data) –> Dirty/Waiting
Dirty/Waiting –> (write starts) –> Clean/InProgress
Clean/InProgress –> (write ends) –> Clean/Synced

When operations overlap, we see:

Dirty/Waiting –> (modify data) –> Dirty/Waiting
Clean/InProgress –> (modify data) –> Dirty/InProgress
Dirty/InProgress –> (modify data) –> Dirty/InProgress

Dirty/InProgress –> (write ends) –> Dirty/Waiting

The constraints this meets are:

• We only have one write going at a time
• Data could be modified at any time
• Multiple modifications can be batched into a single write (though the delay could be as short as the next event loop cycle)
• Beginning to write the data takes a snapshot (JSON.stringify) so it’s OK for the in-memory structure to change while the write is in progress
• If the data is modified while we’re writing, we need to write again after the in progress write completes

The presence of the callback makes the control flow a little more complicated; for example, we support the following sequence of events:

saveChanges(callback_1)  (now Dirty/Waiting)
saveChanges(callback_1b) (still Dirty/Waiting)
(possible delay before batched write)
begin writing            (now Clean/InProgress)
saveChanges(callback_2)  (now Dirty/InProgress)
SaveChanges(callback_2b) (still Dirty/InProgress)
end writing
callback_1(result)
callback_1b(result)      (now Dirty/Waiting)
(possible delay before batched write)
begin writing            (now Clean/InProgress)
end writing
callback_2(result)
callback_2b(result)      (now Clean/Synced)

Turns out we may be able to drop the callback from saveChanges, because neither AddonRepository nor XPIDatabase need it. It saves a bit of bookkeeping, but I’m not sure it makes a huge difference to the overall complexity.

The big headache comes in flushing the data at shutdown time. We need to skip all the delays and get the data flushed, and because things are happening asynchronously, we need to be careful that objects we need aren’t destroyed before we use them. We also need to support a final callback to signal the completion of the flush. We assume that it is unsupported to modify the in-memory data once a flush starts; whether we throw an error if someone tries is TBD.

The flows we need here are:

Clean/Synced:

immediately call flush_callback(success)

Dirty/Waiting:

Cancel batched write delay
begin writing
(asynchronous wait)
end writing
call saveChanges callbacks
call flush_callback

Clean/InProgress:

(async wait)
end writing
call saveChanges callbacks
call flush_callback

Dirty/InProgress: It’s easiest to start with the scenario described above for normal operation…

saveChanges(callback_1)  (now Dirty/Waiting)
saveChanges(callback_1b) (still Dirty/Waiting)
(possible delay before batched write)
begin writing            (now Clean/InProgress)
saveChanges(callback_2)  (now Dirty/InProgress)
SaveChanges(callback_2b) (still Dirty/InProgress)
*** flush(flush_callback)
capture snapshot of in-memory data
(async wait)
end writing
callback_1(result)
callback_1b(result)
*** no delay
begin writing saved snapshot
(async wait)
end writing
callback_2(result)
callback_2b(result)
flush_callback(result)

The important differences in the shutdown time flow are:

• Capture the in-memory state immediately, rather than waiting for the “begin writing” event – this protects against the state being cleaned up by other shutdown events while we’re waiting for the first async write to complete.
• No delay between the end of the in-progress write and the start of the second write.
• We could do the final write synchronously, since it has to be complete before Firefox exits, but the flush API would still need to be async to allow for an async write that was already in progress.

At some point we’d like to wrap all this in a module that other parts of the browser could use. First we want to get the behaviour right…

One of the focuses of the performance team this year is to improve start-up time for the browser. We’ve identified that the Add-on Manager has several issues that can delay start up, and can also cause brief user interface hangs (“jank”) during normal operation. This Bugzilla search shows what we’re tracking right now.

After investigating bug 729330, we decided that the best approach to removing the database I/O bottlenecks in the code was to remove the database. The amount of information we store about addons is relatively small (typically tens of kilobytes, a few hundred KB in the worst case). It is not modified very often, and doesn’t really require the sort of random search and update provided by the SQLITE database we’re currently using. We hope that switching the data storage to JSON, with asynchronous I/O to update the persistent copy in the user’s profile, will improve both overall performance and responsiveness.

We hashed out the approach on an Etherpad document at https://etherpad.mozilla.org/snappy-addon-manager, and now Felipe and I are digging in and starting to change code. The work is being done under Bug 853388 and Bug 853389.

I’ll post progress reports here every week or two, or when anything particularly interesting comes up.