602577 - If the database is detected to be corrupt or have the wrong schema then we need to automatically rebuild and attempt to recover

Status: VERIFIED FIXED

(Toolkit :: Add-ons Manager, defect)

Description

[juan becerra [:juanb]]

Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:2.0b7pre) Gecko/20101006 Firefox/4.0b7pre

This morning I checked for updates, and I noticed that the "checking updates" dialog remained in progress for several minutes. I looked in the error console and I saw several errors.

I think I had to force quit the application yesterday, but I didn't notice any problems till this morning.

I'm not sure the first one is related, but here are the errors:

Error: [Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [mozIStorageRow.getResultByName]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://gre/modules/XPIProvider.jsm :: anonymous :: line 834"  data: no]
Source File: resource://gre/modules/XPIProvider.jsm
Line: 834

Error: ERROR addons.xpi: Error creating statement getVisibleAddons (SELECT internal_id, id, location, version, type, internalName, updateURL, updateKey, optionsURL, aboutURL, iconURL, icon64URL, defaultLocale, visible, active, userDisabled, appDisabled, pendingUninstall, descriptor, installDate, updateDate, applyBackgroundUpdates, bootstrap, skinnable, size, sourceURI, releaseNotesURI FROM addon WHERE visible=1)

Error: ERROR addons.manager: Exception calling provider.getAddonsByTypes: [Exception... "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [mozIStorageConnection.createStatement]"  nsresult: "0x80004005 (NS_ERROR_FAILURE)"  location: "JS frame :: resource://gre/modules/XPIProvider.jsm :: XPIDB_getStatement :: line 3147"  data: no]

Comment 1

[juan becerra [:juanb]]

Attachment: extensions sqlite file

Comment 2

[juan becerra [:juanb]]

Attachment: extensions sqlite file (correct profile)

Comment 3

[juan becerra [:juanb]]

Attachment: extensions log

Comment 4

[juan becerra [:juanb]]

It looks like this prevents the application from applying the update.

Comment 5

[Dave Townsend [:mossop]]

What is the value of the preference extensions.databaseSchema?

Comment 6

[juan becerra [:juanb]]

The value is 3.

Comment 7

[Dave Townsend [:mossop]]

Did you copy files from another profile into this one, either preferences or the extensions.sqlite database?

Comment 8

[juan becerra [:juanb]]

I don't think I have. This is the first time I look inside this profile. However I have it setup with Sync, and I have a Namoroka instance that Syncs to the same account (different profiles).

Comment 9

[Dave Townsend [:mossop]]

So the specific problem here is that for some reason your database is of an old schema but your preferences claim it is up to date so it never gets migrated on startup. This is part of a more general problem that if we load the database after startup and find it is the wrong schema or worse corrupt then basically all hell breaks loose and we don't recover sanely.

Comment 10

[juan becerra [:juanb]]

Today I opened a link within a mail in Lanikai and it went ahead and opened the profile manager for Minefield. What I didn't realize is that it opened a 4.0b3 nightly until a minute later. For some reason it keeps trying to open that version instead of the nightly which is set as my default browser. Would opening a 4b3 version cause the schema to revert to an older version?

Comment 11

[Dave Townsend [:mossop]]

(In reply to comment #10)
> Today I opened a link within a mail in Lanikai and it went ahead and opened the
> profile manager for Minefield. What I didn't realize is that it opened a 4.0b3
> nightly until a minute later. For some reason it keeps trying to open that
> version instead of the nightly which is set as my default browser. Would
> opening a 4b3 version cause the schema to revert to an older version?

Yes it would, but it would also mark the schema version in the prefs correctly. The only scenario I can think of where the version in prefs differs from that in the DB is one outlined in bug 604597 comment 4 where a crash in the session that changed the DB schema would leave the prefs unsaved. We can fix that scenario pretty easily, and I'll include that here, but we probably also want to do the more in-depth work for recovering if all else fails.

Comment 12

[Dave Townsend [:mossop]]

Attachment: patch rev 1

This patch hopefully makes some of the startup code a little cleaner by making only one place there that can open the database. The only real change in behaviour is that now if the preference that flags that there are pending operations from the previous session is set then we'll go through a full filesystem check when we wouldn't before. I don't think this is a problem and keeps the code cleaner.

openConnection now handles detecting a bad database or schema and loading any available migration data. If requested it will also then go and load the add-ons from disk into the database and force the currently active ones (based on the data in extensions.ini) to appear so for the current session. It also has some fallback behaviour in the event of being completely unable to open a database it opens an in-memory database so at least for the session the add-ons manager can behave somewhat sensibly.

The migrateData function gets split into two, one for handling RDF migration and one for database. There are no actual code changes except that the database side no longer closes and deletes the database allowing openConnection to do that instead.

When recovering the database we attempt to guess at the userDisabled value based on the appDisabled value and whether the add-on is active. If we have lost updated compatibility information this guess is poor but there is little we can do in that case.

Three tests are included. One tests the case where the database just has a bad schema (even if the schema in the preferences is correct). This recovers all data as we can get the compatibility info out of the old database anyway. The second tests the case where the database has been replaced with a directory. This successfully rebuilds the database although loses compatibility information. The third tests the case where the database cannot be read, this continues to work using the in-memory database and can even in some situations appear to behave mostly normally even across restarts since we flush extensions.ini to disk on shutdown.

Comment 13

[Robert Strong (they/them - no direct email)]

Comment on attachment 486397 [details] [diff] [review]
patch rev 1

>diff --git a/toolkit/mozapps/extensions/XPIProvider.jsm b/toolkit/mozapps/extensions/XPIProvider.jsm
>--- a/toolkit/mozapps/extensions/XPIProvider.jsm
>+++ b/toolkit/mozapps/extensions/XPIProvider.jsm
>@@ -1776,21 +1776,30 @@ var XPIProvider = {
>    * @param  aState
>    *         The array of current install location states
>    * @param  aManifests
>    *         A dictionary of cached AddonInstalls for add-ons that have been
>    *         installed
>    * @param  aUpdateCompatibility
>    *         true to update add-ons appDisabled property when the application
>    *         version has changed
>+   * @param  aMigrateData
>+   *         an object generated from a previous version of the database
>+   *         holding information about what add-ons were previously userDisabled
>+   *         and any updated compatibility information
nit s/and any updated compatibility information/and updated compatibility information if present/

>+   * @param  aActiveBundles
>+   *         When performing recovery after startup this will be an array of
>+   *         persistent descriptors of add-ons that are known to be active,
>+   *         otherwise it will be null
>    * @return true if a change requiring a restart was detected
>    */
>   processFileChanges: function XPI_processFileChanges(aState, aManifests,
>                                                       aUpdateCompatibility,
>-                                                      aMigrateData) {
>+                                                      aMigrateData,
>+                                                      aActiveBundles) {
>     let visibleAddons = {};
> 
>     /**
>      * Updates an add-on's metadata and determines if a restart of the
>      * application is necessary. This is called when either the add-on's
>      * install directory path or last modified time has changed.
>      *
>      * @param  aInstallLocation
>@@ -2008,17 +2017,19 @@ var XPIProvider = {
>      *         contain data that used to be held about this add-on
>      * @return a boolean indicating if restarting the application is required
>      *         to complete changing this add-on
>      */
>     function addMetadata(aInstallLocation, aId, aAddonState, aMigrateData) {
>       LOG("New add-on " + aId + " installed in " + aInstallLocation.name);
> 
>       // Check the updated manifests lists for a manifest for this add-on
This comment is incorrect. Should be something along the lines of check the updated manifests list for the install location name. If the addon isn't present in the manifests list then newAddon will be undefined.

>-      let newAddon = aManifests[aInstallLocation.name][aId];
>+      let newAddon = null;
>+      if (aInstallLocation.name in aManifests)
>+        newAddon = aManifests[aInstallLocation.name][aId];
> 
>       try {
>         // Otherwise load the manifest from the add-on
>         if (!newAddon) {
>           let file = aInstallLocation.getLocationForID(aId);
>           if (file.isFile())
>             newAddon = loadManifestFromZipFile(file);
>           else
>@@ -2059,16 +2070,34 @@ var XPIProvider = {
>         // The version property isn't a perfect check for this but covers the
>         // vast majority of cases.
>         if (aMigrateData.version == newAddon.version) {
>           if ("targetApplications" in aMigrateData)
>             newAddon.applyCompatibilityUpdate(aMigrateData, true);
>         }
>       }
> 
>+      // If we have a list of what add-ons should be marked as active then use it
>+      if (aActiveBundles) {
>+        // For themes we know which is active by the current skin setting
>+        if (newAddon.type == "theme")
>+          newAddon.active = newAddon.internalName == XPIProvider.currentSkin;
>+        else
>+          newAddon.active = aActiveBundles.indexOf(aAddonState.descriptor) != -1;
I wonder if it wouldn't be a good thing to verify that there is an active theme after this is complete?

>+
>+        // If the add-on isn't active and it isn't appDisabled then it is
>+        // probably userDisabled
>+        if (!newAddon.active && newAddon.visible && !newAddon.appDisabled)
>+          newAddon.userDisabled = true;
>+      }
>+      else {
>+        newAddon.active = (newAddon.visible && !newAddon.userDisabled &&
>+                           !newAddon.appDisabled)
>+      }

Comment 14

[Robert Strong (they/them - no direct email)]

Comment on attachment 486397 [details] [diff] [review]
patch rev 1

>diff --git a/toolkit/mozapps/extensions/XPIProvider.jsm b/toolkit/mozapps/extensions/XPIProvider.jsm
>--- a/toolkit/mozapps/extensions/XPIProvider.jsm
>+++ b/toolkit/mozapps/extensions/XPIProvider.jsm
>...
>@@ -2231,84 +2260,83 @@ var XPIProvider = {
>...
>     // If the database exists then the previous file cache can be trusted
>-    // otherwise create an empty database
>+    // otherwise the database needs to be recreated
>     let db = FileUtils.getFile(KEY_PROFILEDIR, [FILE_DATABASE], true);
>     if (db.exists()) {
>-      cache = Prefs.getCharPref(PREF_INSTALL_CACHE, null);
>+      // If the state has changed then we must update the database
>+      let cache = Prefs.getCharPref(PREF_INSTALL_CACHE, null);
>+      updateDatabase |= cache != JSON.stringify(state);
>     }
>     else {
>-      try {
>-        LOG("Database is missing, recreating");
>-        XPIDatabase.openConnection();
>-        XPIDatabase.createSchema();
>-      }
>-      catch (e) {
>-        try {
>-          db.remove(true);
>-        }
>-        catch (e) {
>-        }
>-        return;
>-      }
>+      updateDatabase = true;
>     }
I think the above would be better written as
let db = FileUtils.getFile(KEY_PROFILEDIR, [FILE_DATABASE], true);
updateDatabase |= !db.exists();
if (!updateDatabase) {
  // If the state has changed then we must update the database
  let cache = Prefs.getCharPref(PREF_INSTALL_CACHE, null);
  updateDatabase = cache != JSON.stringify(state);
}

Also, please use dbFile as you do elsewhere for the file.

Comment 15

[Robert Strong (they/them - no direct email)]

Comment on attachment 486397 [details] [diff] [review]
patch rev 1

>diff --git a/toolkit/mozapps/extensions/XPIProvider.jsm b/toolkit/mozapps/extensions/XPIProvider.jsm
>--- a/toolkit/mozapps/extensions/XPIProvider.jsm
>+++ b/toolkit/mozapps/extensions/XPIProvider.jsm
>...
>@@ -3329,161 +3357,289 @@ var XPIDatabase = {
>     if (this.initialized) {
>       this.getStatement("rollbackSavepoint").execute();
>       this.getStatement("releaseSavepoint").execute();
>     }
>     this.transactionCount--;
>   },
> 
>   /**
>+   * Attempts to open the database file. If it fails it will try to delete the
>+   * existing file and create an empty database. If that fails then it will
>+   * open an in-memory database that can be used during this session.
>+   *
>+   * @param  aDBFile
>+   *         The nsIFile to open
>+   * @return the mozIStorageConnection for the database
>+   */
>+  openDatabaseFile: function XPIDB_openDatabaseFile(aDBFile) {
>+    LOG("Opening database");
>+    let connection = null;
>+
>+    // Attempt to open the database
>+    try {
>+      connection = Services.storage.openUnsharedDatabase(aDBFile);
>+    }
>+    catch (e) {
>+      ERROR("Failed to open database (1st attempt): " + e);
>+      try {
>+        aDBFile.remove(true);
>+      }
>+      catch (e) {
>+        ERROR("Failed to remove corrupt database: " + e);
nit: won't this fail when it is already open as well? Perhaps just ("Failed to remove database after failure to open: " + e) or some such

>+      }
>+      try {
>+        connection = Services.storage.openUnsharedDatabase(aDBFile);
>+      }
>+      catch (e) {
>+        ERROR("Failed to open database (2nd attempt): " + e);
>+
>+        // If we have got here there seems to be no way to open the real
>+        // database, instead open a temporary memory database so things will
>+        // work for this session
>+        return Services.storage.openSpecialDatabase("memory");
>+      }
>+    }
>+
>+    connection.executeSimpleSQL("PRAGMA synchronous = FULL");
>+    connection.executeSimpleSQL("PRAGMA locking_mode = EXCLUSIVE");
>+
>+    return connection;
>+  },
>+
>+  /**
>    * Opens a new connection to the database file.
>    *
>-   * @return the mozIStorageConnection for the database
>+   * @param  aRebuildOnError
>+   *         A boolean indicating whether add-on information should be loaded
>+   *         from the install locations if the database needs to be rebuilt.
>+   * @return the migration data from the database if it was an old schema or
>+   *         null otherwise.
>    */
>-  openConnection: function XPIDB_openConnection() {
>+  openConnection: function XPIDB_openConnection(aRebuildOnError) {
>     this.initialized = true;
>     let dbfile = FileUtils.getFile(KEY_PROFILEDIR, [FILE_DATABASE], true);
>     delete this.connection;
>-    this.connection = Services.storage.openUnsharedDatabase(dbfile);
>-    this.connection.executeSimpleSQL("PRAGMA synchronous = FULL");
>-    this.connection.executeSimpleSQL("PRAGMA locking_mode = EXCLUSIVE");
>+
>+    this.connection = this.openDatabaseFile(dbfile);
>+
>+    let migrateData = null;
>+    let schema = this.connection.schemaVersion;
Please add a comment that schema will not equal DB_SCHEMA if there is an error and that under normal circumstances schema changes are handled during startup.

>+    if (schema != DB_SCHEMA) {
>+      // Non-zero schema means there is some schema and data in the database
>+      // so we can get useful information from it
Why "some schema"?

>+      if (schema != 0) {
So, this should only be true if the schema change wasn't handled during startup?

>+        LOG("Migrating data from schema " + schema);
>+        migrateData = this.getMigrateDataFromDatabase();
>+
>+        // Delete the existing database
>+        this.connection.close();
>+        try {
>+          if (dbfile.exists())
>+            dbfile.remove(true);
This should also report an error if it fails just like above

Comment 16

[Robert Strong (they/them - no direct email)]

Comment on attachment 486397 [details] [diff] [review]
patch rev 1

>diff --git a/toolkit/mozapps/extensions/XPIProvider.jsm b/toolkit/mozapps/extensions/XPIProvider.jsm
>--- a/toolkit/mozapps/extensions/XPIProvider.jsm
>+++ b/toolkit/mozapps/extensions/XPIProvider.jsm
>...
> 
>   /**
>-   * Migrates data from a previous database schema.
>+   * Gets the list of active extension directories from the add-ons list.
>+   * This doesn't include themes.
>    *
>-   * @param  oldSchema
>-   *         The previous schema
>+   * @return an array of persisitent descriptors for the directories
>+   */
Please include info regarding packed extensions and why you need to use the ini

>+  getActiveBundles: function XPIDB_getActiveBundles() {
>+    let bundles = [];
>+
>+    let addonsList = FileUtils.getFile(KEY_PROFILEDIR, [FILE_XPI_ADDONS_LIST],
>+                                       true);
>+
>+    let iniFactory = Cc["@mozilla.org/xpcom/ini-parser-factory;1"].
>+                     getService(Ci.nsIINIParserFactory);
>+    let parser = iniFactory.createINIParser(addonsList);
>+
>+    let keys = parser.getKeys("ExtensionDirs");
>+
>+    while (keys.hasMore())
>+      bundles.push(parser.getString("ExtensionDirs", keys.getNext()));
>+
>+    // Also include the list of active bootstrapped extensions
>+    for (let id in XPIProvider.bootstrappedAddons)
>+      bundles.push(XPIProvider.bootstrappedAddons[id].descriptor);
>+
>+    return bundles;
>+  },
>+
>+  /**
>+   * Retrieves migration data from the old extensions.rdf database.
>+   *
>    * @return an object holding information about what add-ons were previously
>-   *         userDisabled
>+   *         userDisabled and any updated compatibility information
>    */
>-  migrateData: function XPIDB_migrateData(aOldSchema) {
>-    LOG("Migrating data from schema " + aOldSchema);
>+  getMigrateDataFromRDF: function XPIDB_getMigrateDataFromRDF(aDbWasMissing) {
>...
>+    return migrateData;
>+  },
>+
>+
nit: extra newline

Comment 17

[Robert Strong (they/them - no direct email)]

Comment on attachment 486397 [details] [diff] [review]
patch rev 1

Would like a quick look at the updated patch.

Comment 18

[Dave Townsend [:mossop]]

(In reply to comment #15)
> >+    let migrateData = null;
> >+    let schema = this.connection.schemaVersion;
> Please add a comment that schema will not equal DB_SCHEMA if there is an error
> and that under normal circumstances schema changes are handled during startup.

I didn't do this, see below.

> >+      if (schema != 0) {
> So, this should only be true if the schema change wasn't handled during
> startup?

No. This is the code that always handles schema changes. The code in startup looks at the schema value in preferences which is an indication of whether the database has the right schema, if that is incorrect it forces us to call openConnection immediately to see if a schema migration is really necessary, otherwise the first attempt to access the database will call openConnection and do the same.

I spotted one problem here, in the case where the database has the right schema version but prefs has it incorrect it would currently force loading the database on every startup. I've corrected that here and also made us flush the preferences to disk after setting it. This is a small cost but should rarely happen and currently the only feasible scenario I have for bug 606970 is where the app crashes after the database has the right schema in it but before the preference change is flushed to disk.

Comment 19

[Dave Townsend [:mossop]]

Attachment: patch rev 2

Updated from comments

Comment 20

[Dave Townsend [:mossop]]

Landed: http://hg.mozilla.org/mozilla-central/rev/20eda5ba6607

Comment 21

[Dave Townsend [:mossop]]

Backed out due to test failures

Comment 22

[Dave Townsend [:mossop]]

Re-landed: http://hg.mozilla.org/mozilla-central/rev/bfda707be9fb

Comment 23

[Dave Townsend [:mossop]]

And backed out again, didn't spot windows debug was failing before.

Comment 24

[Dave Townsend [:mossop]]

Attachment: bustage fix

This fixes the test issue on windows by actually locking the file open for reading rather than relying on permissions which we apparently bypass

Comment 25

[Robert Strong (they/them - no direct email)]

Comment on attachment 488978 [details] [diff] [review]
bustage fix

should work and I am assuming that you verified that it does

Comment 26

[Dave Townsend [:mossop]]

Third times the charm: http://hg.mozilla.org/mozilla-central/rev/7aeaf6d005ec

Comment 27

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Juan, do you still have this profile available? Would be nice if you could check if this broken sqlite file is getting recovered now.

Comment 28

[juan becerra [:juanb]]

I'm using the profile with which I reported this bug, but I'm no longer experiencing this problem. I don't know what fixed it.

Comment 29

[Henrik Skupin [:whimboo][⌚️UTC+1]]

(In reply to comment #28)
> I'm using the profile with which I reported this bug, but I'm no longer
> experiencing this problem. I don't know what fixed it.

Means you haven't made any changes (i.e. deleted the extensions.sqlite file) and just run it with a current Minefield build? If that's the case we can mark this bug as verified fixed based on the patch for this bug.

Comment 30

[Henrik Skupin [:whimboo][⌚️UTC+1]]

Never heard from a situation as reported here since we fixed that bug. Given that and the automated test I think we can safely mark this bug as verified fixed.