http://graphs-new.mozilla.org/graph.html#tests=[[16,27,20],[16,52,20],[16,63,20]]&sel=none&displayrange=14&datatype=running The best Ts numbers before October 18th were ~1600ms after the best are ~1950 Suspect enabling the extension manager.

On first startup the extension manager creates a sqlite db. That may very well cause this regression

(In reply to Fabrice Desré [:fabrice] from comment #1) > On first startup the extension manager creates a sqlite db. That may very > well cause this regression can we confirm that?

I added some timing to the add-on startup, here's a typical run on a G2: W/PluginManager(29568): zerdatime 1319225175239 - runGecko E/nsConsoleService(29568): Could not read chrome manifest file '/data/data/org.mozilla.fennec_fabrice/chrome.manifest'. E/nsConsoleService(29568): LOG addons.manager: Application has been upgraded E/nsConsoleService(29568): LOG addons.xpi: startup E/nsConsoleService(29568): LOG addons.xpi: checkForChanges E/nsConsoleService(29568): LOG addons.xpi: Opening database E/nsConsoleService(29568): LOG addons.xpi: Opening database took 8 ms E/nsConsoleService(29568): LOG addons.xpi: Migrating data from extensions.rdf E/nsConsoleService(29568): LOG addons.xpi: Migrating data took 1 ms E/nsConsoleService(29568): LOG addons.xpi: Creating database schema E/nsConsoleService(29568): LOG addons.xpi: Creating database took 145 ms E/nsConsoleService(29568): LOG addons.xpi: No changes found E/nsConsoleService(29568): LOG addons.xpi: Add-ons list is missing, recreating E/nsConsoleService(29568): LOG addons.xpi: Writing add-ons list E/nsConsoleService(29568): LOG addons.xpi: Writing add-ons list took 29 ms E/nsConsoleService(29568): LOG addons.xpi: checkForChanges took 398 ms E/nsConsoleService(29568): LOG addons.xpi: startup took 413 ms E/nsConsoleService(29568): fs_handle E/nsConsoleService(29568): fs_handle: about:support E/nsConsoleService(29568): fs_handle: [xpconnect wrapped nsIURI] E/nsConsoleService(29568): fs_handle: done So startup cost is about 400ms on first run, and around 50ms on the following runs.

This database is the largest file in my profile: -rw------- app_109 app_109 393216 2011-10-22 08:34 extensions.sqlite -rw------- app_109 app_109 512 2011-10-22 08:34 extensions.sqlite-journal

Taking care of needlessly creating the database in bug 697246

It's probably worth listing the different types of startup that will have different amounts of Ts impact for the add-ons manager: 1. First run, no extensions installed 2. First run, some extensions installed 3. App updated, no extensions installed 4. App updated, some extensions installed 5. Normal startup, no extensions installed 6. Normal startup, some extensions installed 7. Startup following the installation/uninstallation of an extension Of these all except 5 and 6 will open the database. Bug 697246 stops us touching the database for 1 giving a decent saving for the first run. Bug 697314 has impact on 1 and 2 and unless we fix pref saving all the rest too. Bug 697312 mainly affects 1 and 3. Bug 697331 has a small impact on all. If we get patches landed for all those then 1 and 3 will be about the same as 5 (around 30ms currently). I don't think we have measurements of the other cases yet.

Just to record this somewhere (is there a better bug?), the thread that spawned this bug also noted some concern with a 2.5MB increase in RSS from using add-ons mgr. Most of that looks to be sqlite overhead (shocker!) -- even with basically empty DBs, I see lots of memory (~.5 MB in about:memory) being used for DB that are essentially empty. addons.sqlite and extensions.sqlite my desktop profile, as well as permissions.sqlite (see also bug 697314).

I see lots of work deferring the problem until an addon has been installed. My worry is that many of the fennec users have addons installed, so they will all see this big memory and time hit. any progress here?

I'd bounce this to Dave, but Blair is the new module owner, so... :) AFAIK, this bug is basically fixed, by Dave either deferring work or speeding up the work it does do. Do we have fennec data that indicates this is still a problem (with or without an installed addon), and what those costs are?

(In reply to Justin Dolske [:Dolske] from comment #9) > Do we have fennec data that indicates this is still a problem (with or > without an installed addon), and what those costs are? Indeed: need more (recent) data.

Blair, that data you need, you are collecting, right? Is there anything you need?

(In reply to Doug Turner (:dougt) from comment #11) > Blair, that data you need, you are collecting, right? Not unless you don't mind waiting a few months (I'm rather backed up). > Is there anything you need? Replication of comment 3, for the scenarios listed in comment 6, using the latest on mozilla-central.

The problem continues. And the core problem needs to be fixed. Try this: 1) install beta. 2) load about:memory 3) look at a values for storage 4) go to https://addons.mozilla.org/en-US/android/ 5) install *any* add-on 6) restart if required 7) load about:memory What you will see is that after installing the first add-on, you get a large memory hit: .53MB extensions.sqlite .48MB addons.sqlite some large percentage of the "other" 1.22MB Taking a 1MB+ hit for a single add-on seems really bad. The good news is that it looks like it is a one time charge - that is, we don't use 1MB per add-on -- just 1mb for all add ons.

The RSS issue from the plugin sqlite database looks like it could be solved by reducing the pages size or the amount of pages cached for SQLite. It makes no sense to have 0.5M databases and caches that likely contain maybe 10k of data. Given that *Gecko* SQLite is irrelevant in Fennec, I think this might be as simple as turning those settings down? The main users that are still left would be the SQLiteBridge users. Migration is one time and not actually limited on the Gecko DB side, and then there's password manager, which I presume isn't performance limited at all.

(In reply to Gian-Carlo Pascutto (:gcp) from comment #14) > Given that *Gecko* SQLite is irrelevant in Fennec, I think this might be as > simple as turning those settings down? Just to clarify, we still have more than a few consumers of Gecko's sqlite (passwords, form history, addons manager, indexed-db, and any addons that create their own storage databases like adblock, stylish, or greasemonkey). We really only knocked out one db that I know of, places (although it was a big one).

I suspect those aren't as performance sensitive, so it may still be fine. Also, we have no idea if the current value is optimal on Android. That said, once a database is created you can't really change the page size, so for old profiles this is a pain. We might be able to tune the cache sizes, though. And we can do that per-database.

Oops, forgot to follow up here. Talked with Blair earlier in the week, and have a plan to gather some data to help figure out what's going on and exactly what to fix.

dolske, does the plan include what gcp suggested in comment #14?

Yes. I looked at the SQLite docs and got a bit confused, but I believe it's doable per-database. Filed bug 726556 to look into that separately.

For future reference, this patch adds a bunch of additional logging that includes timing for startup related functions, as well as other API calls.

to add to the slow startup path, XPIProvider.jsm still uses synchronous Storage, so if it's used on startup could be expensive (Bug 699839).

I need to stop bitrotting myself...

Found some unexpected results, where startup of XPIProvider was small compared to overall AddonManager startup. This adds logging to time other providers too.

I tried to test the different types of startup Mossop mentioned in comment 6, but I wasn't sure how to test app updates, or how to have an add-on installed before first run.

That shows that loading the code for the providers is taking ages. Far longer than actually starting them up. Which is interesting. But I guess XPIProvider is ~8k LoC. Wonder how much of that code we could easily lazy-load (such as XPIDatabase). checkForChanges also takes ages, but that was expected - it's a bunch of unavoidable IO. Thankfully it would be relatively rare to hit that during real-world usage (few people install/uninstall an extension *every time* they use the browser).

Touched this in triage - it remains a final blocker for Fennec, but there's some confusion about our current state (is there still a Ts hit? Is there a memory hit?)

(In reply to Johnathan Nightingale [:johnath] from comment #26) > Touched this in triage - it remains a final blocker for Fennec, but there's > some confusion about our current state (is there still a Ts hit? Is there a > memory hit? I have some worked planned here, but I'm blocked on not having enough hours in the day. Gonna push everything else aside later today, and work on this. Some Ts hit in unavoidable, it's just a matter of if anything can be done to reduce it. We have measurements that say just loading of code is the biggest part of the Addons Manager startup time (for typical startups). So I'm going to try do some refactoring to lazy-load as much code as possible. Same deal with memory. See bug 726556 for reducing database memory usage, which is the main issue, and fixable in the short-term. I have some other things planned (AddonRepoistory isn't smart about caching), but that requires a partial rewrite of older code, so is longer term work.

Blair - Any update on this? I thought I remembered you mentioned an improvement with some patches in IRC,

Oof, yeah this is overdue for an update although plenty of work's been going on. Sorry for not communicating more. Blair's been doing some debugging, has a number of devices to test with, and the last update IIRC was that there's a ~30% win by refactoring things so that much less code is pulled in on startup (even when an addon in installed).

There is potential for improvement if bug 729330 is addressed.

This has taken too long, but we can't hold the release on it. I'd really like to see this land soon, though, so that it rides a future Fennec train early out the gate.

Blair, can you attach and/or mark dependent bugs that contain the stuff you'd found so far?

Treating like meta. Looks like dependent bugs have been fixed. If this is finished, please close.

Moving to p3 because no activity for at least 24 weeks.

We have completed our launch of our new Firefox on Android. The development of the new versions use GitHub for issue tracking. If the bug report still reproduces in a current version of [Firefox on Android nightly](https://play.google.com/store/apps/details?id=org.mozilla.fenix) an issue can be reported at the [Fenix GitHub project](https://github.com/mozilla-mobile/fenix/). If you want to discuss your report please use [Mozilla's chat](https://wiki.mozilla.org/Matrix#Connect_to_Matrix) server https://chat.mozilla.org and join the [#fenix](https://chat.mozilla.org/#/room/#fenix:mozilla.org) channel.