Add-ons Manager is broken after installing an extension with browser restart

VERIFIED FIXED in Firefox 12

Status

()

defect
P1
major
VERIFIED FIXED
8 years ago
3 years ago

People

(Reporter: gaubugzilla, Assigned: mbrubeck)

Tracking

({regression})

Trunk
Firefox 13
ARM
Android
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox10 unaffected, firefox11+ wontfix, firefox12 verified, firefox13 fixed, firefox14 verified, firefox15 verified, blocking-fennec1.0 beta+, fennec11+)

Details

Attachments

(1 attachment)

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).
Blocks: aom, abp
(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.
(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
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.
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.
this sounds like it may track 11.  mfinkle, does this effect all addons that require a restart?
Assignee: nobody → mark.finkle
Priority: -- → P1
tracking fennec 11, not desktop 11
tracking-fennec: --- → 11+
Duplicate of this bug: 721784
Bug 721784 says this happens for XUL too. I asked for help in getting a regression range in the XUL version of Fennec.
No, bug 721784 states that installing extensions in XUL Fennec then upgrading to Fennec Native results in the extensions being marked as disabled.
Assignee: mark.finkle → mbrubeck
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}]
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}]
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.
Duplicate of this bug: 729954
I'm bisecting nightlies to narrow down a regression range.
Status: NEW → ASSIGNED
It might be useful to just debug into the C++ for the getService call for Services.storage and see why it is failing.
(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").
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.
@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.
Severity: normal → major
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.
(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.
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.
Blocks: 704973
Keywords: regression
Posted patch band-aidSplinter Review
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...
Attachment #600419 - Flags: review?(dtownsend+bugmail)
blocking-fennec1.0: --- → beta+
Depends on: 730495
Filed bug 730495 for the long-term fix.
Whiteboard: [has patch]
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.
Attachment #600419 - Flags: review?(dtownsend+bugmail) → review+
Can this land on XUL-Beta prior to tagging preferably today or tomorrow?
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.
Attachment #600419 - Flags: approval-mozilla-beta?
Attachment #600419 - Flags: approval-mozilla-aurora?
https://hg.mozilla.org/mozilla-central/rev/9a3da4d27d13
Status: ASSIGNED → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Whiteboard: [has patch]
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.
Attachment #600419 - Flags: approval-mozilla-beta?
Attachment #600419 - Flags: approval-mozilla-beta-
Attachment #600419 - Flags: approval-mozilla-aurora?
Attachment #600419 - Flags: approval-mozilla-aurora+
Verified fixed in XUL Android Mobile 12.0b1 (build #2) (20120314194604)
Verified fixed on:

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

Device: Samsung Captivate
OS: Android 2.2
Status: RESOLVED → VERIFIED
You need to log in before you can comment on or make changes to this bug.