Last Comment Bug 717904 - Add-ons Manager is broken after installing an extension with browser restart
: Add-ons Manager is broken after installing an extension with browser restart
Status: VERIFIED FIXED
: regression
Product: Firefox for Android
Classification: Client Software
Component: General (show other bugs)
: Trunk
: ARM Android
: P1 major (vote)
: Firefox 13
Assigned To: Matt Brubeck (:mbrubeck)
:
Mentors:
: 729954 (view as bug list)
Depends on: 730495
Blocks: abp aom 704973
  Show dependency treegraph
 
Reported: 2012-01-13 06:01 PST by Wladimir Palant
Modified: 2016-07-29 14:21 PDT (History)
16 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---
unaffected
+
wontfix
verified
fixed
verified
verified
beta+
11+


Attachments
band-aid (1.09 KB, patch)
2012-02-24 09:50 PST, Matt Brubeck (:mbrubeck)
blair: review+
akeybl: approval‑mozilla‑aurora+
akeybl: approval‑mozilla‑beta-
Details | Diff | Splinter Review

Description Wladimir Palant 2012-01-13 06:01:48 PST
Steps to reproduce:

* Install an extension requiring a browser restart, e.g. https://adblockplus.org/devbuilds/adblockplus/adblockplus-2.0.4a.3399.xpi
* Restart the browser (manually, because of bug 704406)

Expected results:

Installed extension is listed in the Add-ons Manager and functions correctly.

Actual results:

Installed extension is active but not listed in the Add-ons Manager. Also, some other extensions are missing in the list as well (and inactive). It looks like Add-ons Manager initialization was interrupted while it was loading add-ons. Restarting the browser "fixes" the issue.

Some unusual errors have been logged to the console:

> E/GeckoConsole( 8201): [JavaScript Warning: "Duplicate resource declaration for 'services-sync' ignored." {file: "jar:jar:file:///data/app/org.mozilla.fennec_aurora-1.apk!/omni.ja!/components/components.manifest" line: 168}]
> E/GeckoConsole( 8201): [JavaScript Warning: "Duplicate resource declaration for 'services-crypto' ignored." {file: "jar:jar:file:///data/app/org.mozilla.fennec_aurora-1.apk!/omni.ja!/components/components.manifest" line: 169}]
> E/GeckoConsole( 8201): [JavaScript Warning: "Duplicate resource declaration for 'gre-resources' ignored." {file: "jar:jar:file:///data/app/org.mozilla.fennec_aurora-1.apk!/omni.ja!/chrome/nonlocalized.manifest" line: 11}]
> E/GeckoConsole( 8201): [JavaScript Warning: "WARN addons.manager: InstallListener threw exception when calling onInstallEnded: ReferenceError: AddonManager is not defined" {file: "chrome://browser/content/browser.js" line: 2721}]
> E/GeckoConsole( 8326): [JavaScript Error: "ERROR addons.xpi: Failed to open database (1st attempt): [Exception... "Component returned failure code: 0x80570016 (NS_ERROR_XPC_GS_RETURNED_FAILURE) [nsIJSCID.getService]"  nsresult: "0x80570016 (NS_ERROR_XPC_GS_RETURNED_FAILURE)"  location: "JS frame :: resource://gre/modules/XPCOMUtils.jsm :: XPCU_serviceLambda :: line 232"  data: no]" {file: "resource://gre/modules/XPCOMUtils.jsm" line: 232}]
> E/GeckoConsole( 8326): [JavaScript Error: "ERROR addons.xpi: Failed to open database (2nd attempt): TypeError: Services.storage is undefined" {file: "resource://gre/modules/XPIProvider.jsm" line: 4228}]
> E/GeckoConsole( 8326): [JavaScript Error: "ERROR addons.xpi: Error during startup file checks, rolling back any database changes: TypeError: Services.storage is undefined" {file: "resource://gre/modules/XPIProvider.jsm" line: 4236}]
> E/GeckoConsole( 8326): [JavaScript Error: "ERROR addons.xpi: Error creating statement rollbackSavepoint (ROLLBACK TO SAVEPOINT 'default')" {file: "resource://gre/modules/XPIProvider.jsm" line: 4591}]
> E/GeckoConsole( 8326): [JavaScript Error: "ERROR addons.manager: Exception calling provider startup: TypeError: this.connection is undefined" {file: "resource://gre/modules/XPIProvider.jsm" line: 4588}]

The log is from an Aurora nightly (11.0a2 build 20120112) but I have the same problem in a trunk nightly as well (12.0a1 build 20120112).
Comment 1 Mark Finkle (:mfinkle) (use needinfo?) 2012-01-14 21:13:48 PST
(In reply to Wladimir Palant from comment #0)

> * Restart the browser (manually, because of bug 704406)

> > E/GeckoConsole( 8201): [JavaScript Warning: "WARN addons.manager: InstallListener threw exception when calling onInstallEnded: ReferenceError: AddonManager is not defined" {file: "chrome://browser/content/browser.js" line: 2721}]

The missing restart doorhanger is from this error. The actual problem was an undeclared variable in the method: "buttons"

With that syntax error fixed, the restart doorhanger appears and will restart the app. Unfortunately, the other "ERROR adons.xpi" errors still exist on restart.
Comment 2 Mark Finkle (:mfinkle) (use needinfo?) 2012-01-14 21:17:44 PST
(In reply to Mark Finkle (:mfinkle) from comment #1)
> (In reply to Wladimir Palant from comment #0)
> 
> > * Restart the browser (manually, because of bug 704406)
> 
> > > E/GeckoConsole( 8201): [JavaScript Warning: "WARN addons.manager: InstallListener threw exception when calling onInstallEnded: ReferenceError: AddonManager is not defined" {file: "chrome://browser/content/browser.js" line: 2721}]
> 
> The missing restart doorhanger is from this error. The actual problem was an
> undeclared variable in the method: "buttons"
> 
> With that syntax error fixed, the restart doorhanger appears and will
> restart the app.

Filed bug 718257 with a fix
Comment 3 Mark Finkle (:mfinkle) (use needinfo?) 2012-01-15 08:54:53 PST
Dave, Blair - Any idea as to what Fennec is not doing correctly to get all the "ERROR addons.xip" errors? They happen during startup, after an add-on install restart.
Comment 4 Dave Townsend [:mossop] 2012-01-15 10:24:12 PST
These are pretty troubling:

> E/GeckoConsole( 8326): [JavaScript Error: "ERROR addons.xpi: Failed to open database (1st attempt): [Exception... "Component returned failure code: 0x80570016 (NS_ERROR_XPC_GS_RETURNED_FAILURE) [nsIJSCID.getService]"  nsresult: "0x80570016 (NS_ERROR_XPC_GS_RETURNED_FAILURE)"  location: "JS frame :: resource://gre/modules/XPCOMUtils.jsm :: XPCU_serviceLambda :: line 232"  data: no]" {file: "resource://gre/modules/XPCOMUtils.jsm" line: 232}]
> E/GeckoConsole( 8326): [JavaScript Error: "ERROR addons.xpi: Failed to open database (2nd attempt): TypeError: Services.storage is undefined" {file: "resource://gre/modules/XPIProvider.jsm" line: 4228}]
> E/GeckoConsole( 8326): [JavaScript Error: "ERROR addons.xpi: Error during startup file checks, rolling back any database changes: TypeError: Services.storage is undefined" {file: "resource://gre/modules/XPIProvider.jsm" line: 4236}]

It suggests that Services.storage is undefined, the first error is possibly the getService call for mozIStorageService failing or possibly something else but it suggests something very wrong in XPCOM land.
Comment 5 Doug Turner (:dougt) 2012-01-23 18:40:26 PST
this sounds like it may track 11.  mfinkle, does this effect all addons that require a restart?
Comment 6 Brad Lassey [:blassey] (use needinfo?) 2012-01-24 15:28:43 PST
tracking fennec 11, not desktop 11
Comment 7 Mark Finkle (:mfinkle) (use needinfo?) 2012-01-27 09:53:00 PST
*** Bug 721784 has been marked as a duplicate of this bug. ***
Comment 8 Mark Finkle (:mfinkle) (use needinfo?) 2012-01-27 09:53:58 PST
Bug 721784 says this happens for XUL too. I asked for help in getting a regression range in the XUL version of Fennec.
Comment 9 Kevin Brosnan [:kbrosnan] 2012-01-27 12:45:35 PST
No, bug 721784 states that installing extensions in XUL Fennec then upgrading to Fennec Native results in the extensions being marked as disabled.
Comment 10 Matt Brubeck (:mbrubeck) 2012-02-16 09:25:13 PST
In addition to the above errors, I get:

E/GeckoConsole(23232): [JavaScript Error: "ERROR addons.xpi: Failed to remove database that could not be opened: [Exception... "Component returned failure code: 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST) [nsILocalFile.remove]"  nsresult: "0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST)"  location: "JS frame :: resource://gre/modules/XPIProvider.jsm :: XPIDB_openDatabaseFile :: line 4222"  data: no]" {file: "resource://gre/modules/XPIProvider.jsm" line: 4222}]
Comment 11 Matt Brubeck (:mbrubeck) 2012-02-16 09:28:57 PST
and the first time I try to download an add-on, I get:

E/GeckoConsole(23542): [JavaScript Warning: "WARN addons.xpi: Download failed: TypeError: this.connection is undefined" {file: "resource://gre/modules/AddonRepository.jsm" line: 1551}]
Comment 12 Matt Brubeck (:mbrubeck) 2012-02-16 14:39:00 PST
I don't see these errors in a clean (empty profile) installation of native Fennec, but I do see them after following these steps:

1. Install XUL Fennec.
2. Install at least one add-on.
3. Quit XUL Fennec.
4. Install Native Fennec.
5. Error messages appear at startup and when installing an add-on.

I can reproduce the errors only during the first run of Native Fennec after upgrading from XUL Fennec.  If I quit and restart Native Fennec, the errors do not occur.
Comment 13 Aaron Train [:aaronmt] 2012-02-23 10:05:52 PST
*** Bug 729954 has been marked as a duplicate of this bug. ***
Comment 14 Matt Brubeck (:mbrubeck) 2012-02-23 10:52:07 PST
I'm bisecting nightlies to narrow down a regression range.
Comment 15 Dave Townsend [:mossop] 2012-02-23 10:57:40 PST
It might be useful to just debug into the C++ for the getService call for Services.storage and see why it is failing.
Comment 17 Matt Brubeck (:mbrubeck) 2012-02-23 14:27:12 PST
(In reply to Dave Townsend (:Mossop) from comment #15)
> It might be useful to just debug into the C++ for the getService call for
> Services.storage and see why it is failing.

This line in mozilla::storage::Service::initialize:
http://hg.mozilla.org/mozilla-central/file/13b571bde26a/storage/src/mozStorageService.cpp#l634

> rc = ::sqlite3_quota_initialize("telemetry-vfs", 0);

is returning a result code of 21 (SQLITE_MISUSE: "Library used incorrectly").
Comment 18 Matt Brubeck (:mbrubeck) 2012-02-23 16:12:42 PST
Actually, now it appears to be this line causing the error:
http://mxr.mozilla.org/mozilla-central/source/storage/src/mozStorageService.cpp#614

> rc = ::sqlite3_config(SQLITE_CONFIG_MALLOC, &memMethods);

(Maybe I was just confused before, or maybe it was because I was running an opt build before and the code got shuffled around a bit.)

What I know so far is that this happens because sqlite3_initialize is called earlier in startup by sqlite3_mprintf, which is called here during NSS initialization:
http://mxr.mozilla.org/mozilla-central/source/security/nss/lib/softoken/sdb.c#367

Then mozilla::storage::Service::initialize calls sqlite3_config, which returns SQLITE_MISUSE if it is called *after* sqlite3_initialize.
Comment 19 Aaron Train [:aaronmt] 2012-02-24 05:33:08 PST
@Akeybl - This bug is in 11.0b4; bug 729954 as a duplicate of this. This is a major loss of functionality for those using add-ons, at least in XUL, they will not install properly.
Comment 20 Aaron Train [:aaronmt] 2012-02-24 05:48:49 PST
STR on XUL:

1) Install 11.0b4 build candidate
2) Install Ad-block Plus
3) Restart

Notice no Ad-Block Plus listed after re-start in installed add-ons; can't install any other-addons.
Comment 21 Alex Keybl [:akeybl] 2012-02-24 08:50:34 PST
(In reply to Aaron Train [:aaronmt] from comment #19)
> @Akeybl - This bug is in 11.0b4; bug 729954 as a duplicate of this. This is
> a major loss of functionality for those using add-ons, at least in XUL, they
> will not install properly.

Given that, tracking for FF11. This should not block sign-off for Fennec Beta 4, however, since it's not a regression from b3.

Once we've driven to resolution, please nominate for Aurora/Beta uplift to resolve both the XUL and Native cases.
Comment 22 Matt Brubeck (:mbrubeck) 2012-02-24 09:42:41 PST
The first bad revision is:

http://hg.mozilla.org/mozilla-central/rev/91881c0cf3f3
Gregory Szorc <gps@mozilla.com>
Bug 704973 - syncGUID defined earlier, not always call to database; r=Mossop

This patch makes XPIProvider.jsm's loadManifestFromRDF function create an nsIRandomNumberGenerator, which I am guessing causes NSS to be initialized earlier, causing the problem described in comment 18.
Comment 23 Matt Brubeck (:mbrubeck) 2012-02-24 09:50:26 PST
Created attachment 600419 [details] [diff] [review]
band-aid

This is not a proper fix, but it papers over the problem and is probably a good candidate to ship in Beta and Aurora.

I don't know yet what the real long-term fix should look like...
Comment 24 Matt Brubeck (:mbrubeck) 2012-02-24 16:26:01 PST
Filed bug 730495 for the long-term fix.
Comment 25 Blair McBride [:Unfocused] (UNAVAILABLE) 2012-02-27 16:26:44 PST
Comment on attachment 600419 [details] [diff] [review]
band-aid

Review of attachment 600419 [details] [diff] [review]:
-----------------------------------------------------------------

::: toolkit/mozapps/extensions/XPIProvider.jsm
@@ +822,5 @@
>    }
>  
>    addon.applyBackgroundUpdates = AddonManager.AUTOUPDATE_DEFAULT;
>  
> +  // Load the storage service before NSS, to avoid a SQLite initialization error

Should explicitly mention nsIRandomGenerator here, as it's not obvious.
Comment 26 Aaron Train [:aaronmt] 2012-02-28 06:11:13 PST
Can this land on XUL-Beta prior to tagging preferably today or tomorrow?
Comment 28 Matt Brubeck (:mbrubeck) 2012-02-28 09:18:05 PST
Comment on attachment 600419 [details] [diff] [review]
band-aid

[Approval Request Comment]
Regression caused by (bug #): bug 704973

User impact if declined: Add-on installation for non-bootstrapped extensions is broken in XUL Fennec, and various add-on operations fail silently after installing an add-on.

Testing completed (on m-c, etc.): Landed on inbound 2/27.

Risk to taking this patch (and alternatives if risky): Very low-risk one-line patch that just changes the order that some code runs during startup.

String changes made by this patch: None.
Comment 29 Matt Brubeck (:mbrubeck) 2012-02-28 09:56:03 PST
https://hg.mozilla.org/mozilla-central/rev/9a3da4d27d13
Comment 30 Alex Keybl [:akeybl] 2012-02-28 13:19:26 PST
Comment on attachment 600419 [details] [diff] [review]
band-aid

[Triage Comment]
When suggesting we nominate for Beta, I didn't realize that this would require a change in shared code. Given the fact that we're not shipping XUL Fennec 11 and FF12 will soon be on Beta, approving for Aurora 12 only.
Comment 31 Matt Brubeck (:mbrubeck) 2012-02-28 13:26:11 PST
https://hg.mozilla.org/releases/mozilla-aurora/rev/8e997efa140b
Comment 32 Aaron Train [:aaronmt] 2012-03-16 08:35:56 PDT
Verified fixed in XUL Android Mobile 12.0b1 (build #2) (20120314194604)
Comment 33 Cristian Nicolae (:xti) 2012-04-30 08:21:06 PDT
Verified fixed on:

Firefox 15.0a1 (2012-04-30)
Firefox 14.0a2 (2012-04-30)

Device: Samsung Captivate
OS: Android 2.2

Note You need to log in before you can comment on or make changes to this bug.