618179 - Changing the Sync Key fails: meta is null

Status: RESOLVED FIXED

(Firefox :: Sync, defect)

Description

[Philipp von Weitershausen [:philikon]]

Running the 2010-12-09 nightlies on OSX. Changing my Sync Key works, but then the subsequent Sync fails:

2010-12-09 17:10:21	Service.Main         INFO	In sync().
2010-12-09 17:10:21	Net.Resource         DEBUG	GET success 200 https://phx-sync426.services.mozilla.com/1.0/knxg3omhbaoozvoarrvwqrzs6utkkxcb/info/collections
2010-12-09 17:10:21	Service.Main         DEBUG	Fetching global metadata record
2010-12-09 17:10:21	Net.Resource         DEBUG	GET fail 404 https://phx-sync426.services.mozilla.com/1.0/knxg3omhbaoozvoarrvwqrzs6utkkxcb/storage/meta/global
2010-12-09 17:10:21	Service.Main         DEBUG	Exception: meta is null JS Stack trace: WeaveSvc__remoteSetup([object String])@service.js:1093 < ()@service.js:1460 < WrappedNotify()@util.js:147 < WrappedLock()@util.js:119 < WrappedCatch()@util.js:97 < sync(true)@service.js:1410 < ()@service.js:854 < WrappedNotify()@util.js:147 < WrappedCatch()@util.js:97 < WeaveSvc_changePassphrase("az6k7kksbpvt5rnxwb72inr4mq")@service.js:842 < Change_doChangePassphrase()@syncGenericChange.js:199 < ()@syncGenericChange.js:169 < anonymous([object Event])@dialog.xml:357 < _fireButtonEvent("accept")@dialog.xml:358 < _doButtonCommand("accept")@dialog.xml:332 < _handleButtonCommand([object XULCommandEvent])@dialog.xml:321

Restarting the browser fixes it.

I recall that this was reported by somebody on IRC as well.

Comment 1

[Tony Chung [:tchung]]

I also hit the same error, when Generating a new Sync key, then saving it. 

Tested on Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:2.0b8pre) Gecko/20101209 Firefox/4.0b8pre

2010-12-09 17:29:42	Net.Resource         DEBUG	GET success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/info/collections
2010-12-09 17:29:42	Net.Resource         DEBUG	DELETE success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/meta
2010-12-09 17:29:42	Net.Resource         DEBUG	DELETE success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/crypto
2010-12-09 17:29:42	Net.Resource         DEBUG	DELETE success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/clients
2010-12-09 17:29:42	Net.Resource         DEBUG	DELETE success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/bookmarks
2010-12-09 17:29:42	Net.Resource         DEBUG	DELETE success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/forms
2010-12-09 17:29:43	Net.Resource         DEBUG	DELETE success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/history
2010-12-09 17:29:43	Net.Resource         DEBUG	DELETE success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/prefs
2010-12-09 17:29:43	Net.Resource         DEBUG	DELETE success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/tabs
2010-12-09 17:29:43	Service.Main         INFO	Logging out
2010-12-09 17:29:43	Service.Main         INFO	Logging in user msvdqjdrj2rglmx26it7rmuoqg3wzjzv
2010-12-09 17:29:43	Net.Resource         DEBUG	GET success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/info/collections
2010-12-09 17:29:43	Service.Main         DEBUG	Fetching global metadata record
2010-12-09 17:29:43	Service.Main         DEBUG	Weave Version: @weave_version@ Local Storage: 4 Remote Storage: 4
2010-12-09 17:29:43	Service.Main         INFO	Sync key is up-to-date: no need to upgrade.
2010-12-09 17:29:43	Service.Main         DEBUG	Fetching and verifying -- or generating -- symmetric keys.
2010-12-09 17:29:43	Net.Resource         DEBUG	GET success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/info/collections
2010-12-09 17:29:43	Service.Main         INFO	Testing info/collections: {"meta":1291944582.92,"crypto":1291944582.96,"clients":1291944582.99,"bookmarks":1291944583.04,"forms":1291944336.02,"history":1291944336.07,"prefs":1291944336.15,"tabs":1291944583.19}
2010-12-09 17:29:43	CollectionKeys       INFO	Testing for updateNeeded. Last modified: 1291944492.5
2010-12-09 17:29:43	Service.Main         INFO	CollectionKeys reports that a key update is needed.
2010-12-09 17:29:43	Net.Resource         DEBUG	GET fail 404 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/crypto/keys
2010-12-09 17:29:43	Service.Main         WARN	Got 404 for crypto/keys, but 'crypto' in info/collections. Regenerating.
2010-12-09 17:29:43	Service.Main         INFO	Generating new keys....
2010-12-09 17:29:43	BulkKeyBundle        INFO	BulkKeyBundle being created for [default]
2010-12-09 17:29:43	Service.Main         INFO	Encrypting new key bundle. Modified time is 1291944583.27
2010-12-09 17:29:43	Service.Main         INFO	Uploading...
2010-12-09 17:29:43	Net.Resource         DEBUG	PUT Length: 402
2010-12-09 17:29:43	Net.Resource         DEBUG	PUT success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/crypto/keys
2010-12-09 17:29:43	Service.Main         INFO	Got status 200
2010-12-09 17:29:43	Service.Main         INFO	In sync().
2010-12-09 17:29:43	Net.Resource         DEBUG	GET success 200 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/info/collections
2010-12-09 17:29:43	Service.Main         DEBUG	Fetching global metadata record
2010-12-09 17:29:43	Service.Main         DEBUG	Clearing cached meta record. metaModified is 1291943528.16, setting to 1291944582.92
2010-12-09 17:29:43	Net.Resource         DEBUG	GET fail 404 https://phx-sync468.services.mozilla.com/1.0/msvdqjdrj2rglmx26it7rmuoqg3wzjzv/storage/meta/global
2010-12-09 17:29:43	Service.Main         DEBUG	Exception: newMeta is null JS Stack trace: WeaveSvc__remoteSetup([object String])@service.js:1082 < ()@service.js:1439 < WrappedNotify()@util.js:147 < WrappedLock()@util.js:119 < WrappedCatch()@util.js:97 < sync(true)@service.js:1389 < ()@service.js:833 < WrappedNotify()@util.js:147 < WrappedCatch()@util.js:97 < WeaveSvc_changePassphrase("uapv62t3z3cdgpqi7jcev8bvqi")@service.js:821 < Change_doChangePassphrase()@syncGenericChange.js:199 < ()@syncGenericChange.js:169 < anonymous([object Event])@dialog.xml:357 < _fireButtonEvent("accept")@dialog.xml:358 < _doButtonCommand("accept")@dialog.xml:332 < _handleButtonCommand([object XULCommandEvent])@dialog.xml:321

Comment 2

[Richard Newman [:rnewman]]

This is why:

    // Checking modified time of the meta record.
    if (infoResponse &&
        (infoResponse.obj.meta != this.metaModified) &&
        !meta.isNew) {
      
      // Delete the cached meta record...
      this._log.debug("Clearing cached meta record. metaModified is " +
          JSON.stringify(this.metaModified) + ", setting to " +
          JSON.stringify(infoResponse.obj.meta));
      Records.del(this.metaURL);
      
      // ... fetch the current record from the server, and COPY THE FLAGS.
      let newMeta       = Records.get(this.metaURL);
      newMeta.isNew     = meta.isNew;
      newMeta.changed   = meta.changed;
      
      // Switch in the new meta object and record the new time.
      meta              = newMeta;
      this.metaModified = infoResponse.obj.meta;
    }

meta is still in info/collections, and we just cleared metaModified, so we clear our cache and try to download the one that the server claims it has.

Comment 3

[Mike Connor [:mconnor]]

This is triggering bug 618068 and other failures.  This is the real blocker for b8.

Comment 4

[Mike Connor [:mconnor]]

rnewman knows what to do here.

Comment 5

[Richard Newman [:rnewman]]

Attachment: Create a meta record if one doesn't exist. v1

Tested with addon on top of recent Minefield (thanks for great STR). Tests and CrossWeave pass.

Comment 6

[Philipp von Weitershausen [:philikon]]

Comment on attachment 496715 [details] [diff] [review]
Create a meta record if one doesn't exist. v1

Great work! I verified manually that this fixes the problem. But eventually we need automated tests for this. Filed bug 618214.

>+      }
>+      else {
>+        // If newMeta, then it stands to reason that meta != null.
>       newMeta.isNew   = meta.isNew;
>       newMeta.changed = meta.changed;
>+      }

Nit: Please fix indention and cuddle the else.

Comment 7

[Richard Newman [:rnewman]]

Pushed:

http://hg.mozilla.org/services/fx-sync/rev/5cf9cbfdf7a1

Thanks Philipp.