1031855 - Check if password engine record application is still flawed

Status: RESOLVED FIXED

(Firefox :: Sync, defect, P2)

Description

[Richard Newman [:rnewman]]

A record that already exists, but has a different GUID, simply fails to be created. It should be reconciled instead.

1403996513250	Sync.Store.Passwords	DEBUG	Adding record {5df990fc-d78a-4566-be16-72006853a39a} resulted in exception [Exception... "This login already exists.'This login already exists.' when calling method: [nsILoginManager::addLogin]"  nsresult: "0x8057001e (NS_ERROR_XPC_JS_THREW_STRING)"  location: "JS frame :: resource://gre/modules/services-sync/engines/passwords.js :: PasswordStore__create :: line 229"  data: no] Stack trace: PasswordStore__create()@resource://gre/modules/services-sync/engines/passwords.js:229 < Store.prototype.applyIncoming()@resource://services-sync/engines.js:329 < Store.prototype.applyIncomingBatch()@resource://services-sync/engines.js:297 < doApplyBatch()@resource://services-sync/engines.js:951 < doApplyBatchAndPersistFailed()@resource://services-sync/engines.js:966 < SyncEngine.prototype._processIncoming()@resource://services-sync/engines.js:1070 < SyncEngine.prototype._sync()@resource://services-sync/engines.js:1481 < WrappedNotify()@resource://services-sync/util.js:141 < Engine.prototype.sync()@resource://services-sync/engines.js:655 < _syncEngine()@resource://services-sync/stages/enginesync.js:199 < sync()@resource://services-sync/stages/enginesync.js:149 < onNotify()@resource://gre/modules/services-sync/service.js:1271 < WrappedNotify()@resource://services-sync/util.js:141 < WrappedLock()@resource://services-sync/util.js:96 < _lockedSync()@resource://gre/modules/services-sync/service.js:1261 < sync/<()@resource://gre/modules/services-sync/service.js:1253 < WrappedCatch()@resource://services-sync/util.js:70 < sync()@resource://gre/modules/services-sync/service.js:1241 < <file:unknown>

Comment 1

[Edouard Oger [:eoger]]

Attachment: bug-1031855.patch

Comment 2

[Mark Hammond [:markh] [:mhammond]]

Comment on attachment 8743074 [details] [diff] [review]
bug-1031855.patch

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

I don't think this is correct - but it's not yet clear to me how we are ending up in this case in the first place. It's certainly possible I'm wrong, but I think I need to understand exactly what is going on (ie, exactly how we are ending up in create() when a dupe exists) before we go ahead with this.

So fundamentally, we seem to be hitting this case because (a) we have an incoming record for a login, (b) our logic tells us we need to create a new one for that record, (c) we fail to create a new one due to a local one already existing. This patch fixes (c), but I think we need to fix (b) instead.

What I think *should* already be happening - but clearly isn't - is: we have an existing login with GUID1, which may or may not already be on the server. An incoming record with GUID2 matches the same login, so the logic in _reconcile should wind up at https://dxr.mozilla.org/mozilla-central/rev/67ac40fb8f680ea5e03805552187ba1b5e8392a1/services/sync/modules/engines.js#1329 - _findDupe() is called, which should find GUID1 (ie, that GUID1 is a dupe for the incoming GUID2). In that case we then should attempt to delete GUID1 from the server and update the existing local item with GUID2 (ie, GUID1 should no longer exist anywhere at this point). Then, if the local and remote versions of the record are identical, _reconcile will return indicating the reconcilliation is done, and processing for the item is complete. If the records are *not* identical and the server copy appears more recent, reconcile says the remote item *does* need to be applied - so we then should end up in applyIncoming(), which checks if the GUID being applied (GUID2) exists locally - which it now should as we gave the existing record GUID2 above as part of the duplicate finding - so we should then end up in update() instead of create().

The above process is important as we've effectively deleted the duplicate item. With this patch, I think we are still likely to end up with GUID1 and GUID2 remaining on the server, and with the local record being GUID1 - so when the local device updates the password it will be uploaded as GUID1, and other devices with the record as GUID2 will not see the change, except via this dupe mapping - which may also result in a "sync loop" - eg, consider:

* On client 1, incoming GUID2 causes us to update GUID1 locally as we found it is a dupe.
* client 1 then uploads the record for GUID1 as it changed locally.
* client 2 sees incoming GUID1, and finds it is a dupe of GUID2, so applies the changes to GUID2 locally.
* client 2 then uploads the record for GUID2 as it changed locally.
* client 1, incoming change for GUID2 - so we repeat the entire process.

(fortunately this probably doesn't happen now as Sync ignores changes made while syncing, meaning the local and server copies of these GUIDs are different - which is bad, but not as bad a a sync loop. But this may change in the future as we move to more reliable trackers.)

tl;dr - ISTM that this will leave us with logical dupes of the same record on the server, but Sync already has logic to avoid that - I think we need to understand better why that isn't working here.

::: services/sync/tests/unit/test_password_reconcile.js
@@ +11,5 @@
> +
> +  return Services.logins.searchLogins({}, prop)[0];
> +}
> +
> +function test_different_guid() {

so I think what this test needs to do is:

* create a record on the server with GUID2
* create a local entry *and* and entry on the server with the same details but with GUID1
* perform a sync.
* verify the local entry has had its GUID changed to GUID2
* verify GUID1 no longer exists locally
* verify GUID1 no longer exists on the server.
* verify the password from GUID2 is updated if the GUID2 timestamp says it is more recent.

and hope the test fails reproduces the original bug report - if it doesn't we need to work out how we can in a less artificial way (ie, how to reproduce it via a full sync given a local state and a set of incoming records)

Comment 3

[Edwin Wong [:edwong]]

eoger isn't currently working on this, removing assignment.

Comment 4

[Mark Hammond [:markh] [:mhammond]]

Re-nominating for triage. It's certainly not a "top error" in telemetry for passwords but there's probably not a huge amount of work in writing the test at the end of comment 2 - the question is whether the new test is worth it, and if not, we should just close this.

Comment 5

[Thom Chiovoloni [:tcsc] (ex-moco)]

Attachment: Bug 1031855 - Add test that sync password application does the right thing for duplicates.

Review commit: https://reviewboard.mozilla.org/r/225900/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/225900/

Comment 6

[Mark Hammond [:markh] [:mhammond]]

Comment on attachment 8956957 [details]
Bug 1031855 - Add test that sync password application does the right thing for duplicates.

https://reviewboard.mozilla.org/r/225900/#review233732

Awesome, thanks Thom (and sorry for the review delay!)

Comment 7

[Mark Hammond [:markh] [:mhammond]]

Updating bug title to reflect current reality - we do handle dupes correctly and this bug is landing a test to verify that fact.

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/58ad264b9b58
Add test that sync password application does the right thing for duplicates. r=markh

Comment 9

[Stefan Hindli [:stefan_hindli]]

https://hg.mozilla.org/mozilla-central/rev/58ad264b9b58