Bug 1359879: add logging and robustness to key syncing, r?kmag draft
authorEthan Glasser-Camp <eglassercamp@mozilla.com>
Mon, 01 May 2017 14:22:51 -0400
changeset 571975 7e38305cbc30e1514ad7205d4f20be6e99e70e1a
parent 570886 57b37213d81150642f5139764e7044b07b9dccc3
child 626936 6b0a55b45a92fd1cdf34368db3fd03d54c84c96f
push id56980
push usereglassercamp@mozilla.com
push dateWed, 03 May 2017 16:34:22 +0000
reviewerskmag
bugs1359879
milestone55.0a1
Bug 1359879: add logging and robustness to key syncing, r?kmag It seems like the server-side keyring is getting deleted somehow. This causes syncing of the keyring to fail. We haven't completely fixed the root problem yet, but this adds logging to try to flag down the dangerous operation of deleting a bucket to make sure we aren't doing that by accident. We also try to recover from the server-keyring-was-deleted situation by wiping all storage.sync data, the same as if we found a keyring that we couldn't decrypt. MozReview-Commit-ID: JMB0IxApbGq
toolkit/components/extensions/ExtensionStorageSync.jsm
toolkit/components/extensions/test/xpcshell/test_ext_storage_sync.js
--- a/toolkit/components/extensions/ExtensionStorageSync.jsm
+++ b/toolkit/components/extensions/ExtensionStorageSync.jsm
@@ -100,16 +100,22 @@ const log = Log.repository.getLogger("Sy
 
 // A global that is fxAccounts, or null if (as on android) fxAccounts
 // isn't available.
 let _fxaService = null;
 if (AppConstants.platform != "android") {
   _fxaService = fxAccounts;
 }
 
+class ServerKeyringDeleted extends Error {
+  constructor() {
+    super("server keyring appears to have disappeared; we were called to decrypt null");
+  }
+}
+
 /**
  * Check for FXA and throw an exception if we don't have access.
  *
  * @param {Object} fxAccounts  The reference we were hoping to use to
  *     access FxA
  * @param {string} action  The thing we were doing when we decided to
  *     see if we had access to FxA
  */
@@ -310,16 +316,38 @@ class KeyRingEncryptionRemoteTransformer
     return Task.spawn(function* () {
       const encoded = yield encodePromise;
       encoded.kbHash = record.kbHash;
       return encoded;
     });
   }
 
   async decode(record) {
+    if (record === null) {
+      // XXX: This is a hack that detects a situation that should
+      // never happen by using a technique that shouldn't actually
+      // work. See
+      // https://bugzilla.mozilla.org/show_bug.cgi?id=1359879 for
+      // the whole gory story.
+      //
+      // For reasons that aren't clear yet,
+      // sometimes the server-side keyring is deleted. When we try
+      // to sync our copy of the keyring, we get a conflict with the
+      // deleted version. Due to a bug in kinto.js, we are called to
+      // decode the deleted version, which is represented as
+      // null. For now, try to handle this by throwing a specific
+      // kind of exception which we can catch and recover from the
+      // same way we would do with any other kind of undecipherable
+      // keyring -- wiping the bucket and reuploading everything.
+      //
+      // Eventually we will probably fix the bug in kinto.js, and
+      // this will have to move somewhere else, probably in the code
+      // that detects a resolved conflict.
+      throw new ServerKeyringDeleted();
+    }
     try {
       return await super.decode(record);
     } catch (e) {
       if (Utils.isHMACMismatch(e)) {
         const currentKBHash = await getKBHash(this._fxaService);
         if (record.kbHash != currentKBHash) {
           // Some other client encoded this with a kB that we don't
           // have access to.
@@ -876,16 +904,17 @@ class ExtensionStorageSync {
   }
 
   /**
    * Helper similar to _syncCollection, but for deleting the user's bucket.
    *
    * @returns {Promise<void>}
    */
   async _deleteBucket() {
+    log.error("Deleting default bucket and everything in it");
     return await this._requestWithToken("Clearing server", async function(token) {
       const headers = {Authorization: "Bearer " + token};
       const kintoHttp = new KintoHttpClient(prefStorageSyncServerURL, {
         headers: headers,
         timeout: KINTO_REQUEST_TIMEOUT,
       });
       return await kintoHttp.deleteBucket("default");
     });
@@ -938,16 +967,17 @@ class ExtensionStorageSync {
    */
   async ensureCanSync(extIds) {
     const keysRecord = await this.cryptoCollection.getKeyRingRecord();
     const collectionKeys = await this.cryptoCollection.getKeyRing();
     if (collectionKeys.hasKeysFor(extIds) && this.hasSaltsFor(keysRecord, extIds)) {
       return collectionKeys;
     }
 
+    log.info(`Need to create keys and/or salts for ${JSON.stringify(extIds)}`);
     const kbHash = await getKBHash(this._fxaService);
     const newKeys = await collectionKeys.ensureKeysFor(extIds);
     const newSalts = await this.ensureSaltsFor(keysRecord, extIds);
     const newRecord = {
       id: STORAGE_SYNC_CRYPTO_KEYRING_RECORD_ID,
       keys: newKeys.asWBO().cleartext,
       salts: newSalts,
       uuid: collectionKeys.uuid,
@@ -1046,21 +1076,23 @@ class ExtensionStorageSync {
 
           // Server version is now correct. Return that result.
           return result;
         }
       }
       // No conflicts, or conflict was just someone else adding keys.
       return result;
     } catch (e) {
-      if (KeyRingEncryptionRemoteTransformer.isOutdatedKB(e)) {
+      if (KeyRingEncryptionRemoteTransformer.isOutdatedKB(e) ||
+          e instanceof ServerKeyringDeleted) {
         // Check if our token is still valid, or if we got locked out
         // between starting the sync and talking to Kinto.
         const isSessionValid = await this._fxaService.sessionStatus();
         if (isSessionValid) {
+          log.error("Couldn't decipher old keyring; deleting the default bucket and resetting sync status");
           await this._deleteBucket();
           await this.cryptoCollection.resetSyncStatus();
 
           // Reupload our keyring, which is the only new keyring.
           // We don't want client_wins here because another device
           // could have uploaded another keyring in the meantime.
           return await this.cryptoCollection.sync(this);
         }
--- a/toolkit/components/extensions/test/xpcshell/test_ext_storage_sync.js
+++ b/toolkit/components/extensions/test/xpcshell/test_ext_storage_sync.js
@@ -739,16 +739,68 @@ add_task(function* ensureCanSync_handles
       ok(body.keys.collections[extensionId],
          `decrypted failed post should have a key for ${extensionId}`);
       notEqual(body.keys.collections[extensionId], RANDOM_KEY.keyPairB64,
                `decrypted failed post should have a randomly-generated key for ${extensionId}`);
     });
   });
 });
 
+add_task(function* ensureCanSync_handles_deleted_conflicts() {
+  // A keyring can be deleted, and this changes the format of the 412
+  // Conflict response from the Kinto server. Make sure we handle it correctly.
+  const extensionId = uuid();
+  const extensionId2 = uuid();
+  yield* withContextAndServer(function* (context, server) {
+    server.installCollection("storage-sync-crypto");
+    server.installDeleteBucket();
+    yield* withSignedInUser(loggedInUser, function* (extensionStorageSync, fxaService) {
+      server.etag = 700;
+      yield extensionStorageSync.cryptoCollection._clear();
+
+      // Generate keys that we can check for later.
+      let collectionKeys = yield extensionStorageSync.ensureCanSync([extensionId]);
+      const extensionKey = collectionKeys.keyForCollection(extensionId);
+      server.clearPosts();
+
+      // This is the response that the Kinto server return when the
+      // keyring has been deleted.
+      server.addRecord({collectionId: "storage-sync-crypto", conflict: true, data: null, etag: 765});
+
+      // Try to add a new extension to trigger a sync of the keyring.
+      let collectionKeys2 = yield extensionStorageSync.ensureCanSync([extensionId2]);
+
+      assertKeyRingKey(collectionKeys2, extensionId, extensionKey,
+                       `syncing keyring should keep our local key for ${extensionId}`);
+
+      deepEqual(server.getDeletedBuckets(), ["default"],
+                "Kinto server should have been wiped when keyring was thrown away");
+
+      let posts = server.getPosts();
+      equal(posts.length, 2,
+            "syncing keyring should have tried to post a keyring twice");
+      // The first post got a conflict.
+      const failedPost = posts[0];
+      assertPostedUpdatedRecord(failedPost, 700);
+      let body = yield assertPostedEncryptedKeys(fxaService, failedPost);
+
+      deepEqual(body.keys.collections[extensionId], extensionKey.keyPairB64,
+                `decrypted failed post should have the key for ${extensionId}`);
+
+      // The second post was after the wipe, and succeeded.
+      const afterWipePost = posts[1];
+      assertPostedNewRecord(afterWipePost);
+      let afterWipeBody = yield assertPostedEncryptedKeys(fxaService, afterWipePost);
+
+      deepEqual(afterWipeBody.keys.collections[extensionId], extensionKey.keyPairB64,
+                `decrypted new post should have preserved the key for ${extensionId}`);
+    });
+  });
+});
+
 add_task(function* checkSyncKeyRing_reuploads_keys() {
   // Verify that when keys are present, they are reuploaded with the
   // new kB when we call touchKeys().
   const extensionId = uuid();
   let extensionKey, extensionSalt;
   yield* withContextAndServer(function* (context, server) {
     yield* withSignedInUser(loggedInUser, function* (extensionStorageSync, fxaService) {
       server.installCollection("storage-sync-crypto");