Note: There are a few cases of duplicates in user autocompletion which are being worked on.

NS_ERROR_ILLEGAL_VALUE in nsINavBookmarksService.insertBookmark while inserting query

RESOLVED FIXED in Firefox 17

Status

Cloud Services
Firefox Sync: Backend
P1
normal
RESOLVED FIXED
5 years ago
4 years ago

People

(Reporter: rnewman, Assigned: rnewman)

Tracking

unspecified
mozilla19
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox16 affected, firefox17 fixed, firefox18 fixed)

Details

(Whiteboard: [verified in services][qa+])

Attachments

(3 attachments, 1 obsolete attachment)

(Assignee)

Description

5 years ago
Sync.Store.Bookmarks	TRACE	Number of rows matching GUID AAAAAAAAAAAA: 0
	Sync.Engine.Bookmarks	TRACE	Reconciling AAAAAAAAAAAA. exists=false; modified=false; local age=null; incoming age=35772.10000014305
	Sync.Engine.Bookmarks	TRACE	Finding mapping: All Bookmarks, bundefined:undefined
	Sync.Engine.Bookmarks	TRACE	No parent => no dupe.
	Sync.Engine.Bookmarks	TRACE	No duplicate found for incoming item: AAAAAAAAAAAA
	Sync.Engine.Bookmarks	TRACE	Applying incoming because local item does not exist and was not deleted.
	Sync.Store.Bookmarks	TRACE	Number of rows matching GUID BBBBBBBBBBBB: 1
	Sync.Store.Bookmarks	TRACE	Number of rows matching GUID AAAAAAAAAAAA: 0
	Sync.Store.Bookmarks	WARN	Failed to apply incoming record AAAAAAAAAAAA
	Sync.Store.Bookmarks	WARN	Encountered exception: Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsINavBookmarksService.insertBookmark] Stack trace: BStore_create()@resource://gre/modules/services-sync/engines/bookmarks.js:635 < Store_applyIncoming()@resource://services-sync/engines.js:250 < BStore_applyIncoming()@resource://gre/modules/services-sync/engines/bookmarks.js:523 < applyIncomingBatch()@resource://services-sync/engines.js:218 < doApplyBatch()@resource://services-sync/engines.js:782 < resource://services-sync/engines.js:893 < resource://gre/modules/services-sync/record.js:625 < Channel_onDataAvail()@resource://gre/modules/services-sync/resource.js:524 < <file:unknown>
(Assignee)

Comment 1

5 years ago
Record is:

 Sync.Engine.Bookmarks	TRACE	Incoming: { id: AAAAAAAAAAAA  index: 0  modified: 1351468990.35  ttl: undefined  payload: {"id":"AAAAAAAAAAAA","folderName":"","parentid":"BBBBBBBBBBBB","title":"Downloads","queryId":"","type":"query","parentName":""}  collection: bookmarks }


Happens to a bunch of records in this log.
(Assignee)

Comment 2

5 years ago
I will look at this today.
Assignee: nobody → rnewman
Status: NEW → ASSIGNED
Priority: -- → P1
(Assignee)

Comment 3

5 years ago
Trivial failing test:

function test_empty_query() {
  let record = new BookmarkQuery("bookmarks", "8xoDGqKrXf1P");
  record.folderName    = "";
  record.queryId       = "";
  record.parentName    = "Toolbar";
  record.parentid      = "toolbar";
  store.applyIncoming(record);
}
(Assignee)

Comment 4

5 years ago
If we introduce a bmkUri:

0.91 TEST-UNEXPECTED-FAIL| xpcshell/head.js | [Exception... "'Illegal value' when calling method: [nsITaggingService::tagURI]"  nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)"  location: "JS frame :: resource://services-sync/engines/bookmarks.js :: preprocessTagQuery :: line 455"  data: no]

If we introduce a title (still no queryId), it passes.

So somehow a query record is being created on the server without a URI (which causes the primary bug), and without a non-empty title (which would cause a different error).

Let's filter these out for sanity, and figure out how they're happening…
(Assignee)

Comment 5

5 years ago
Created attachment 676347 [details] [diff] [review]
Band-Aid. v1

This patch skips malformed query records. The traditional Sync solution to this is to throw, as we do for bad parent IDs, but that will cause clients to perpetually refetch the failed record (and report a failure, too).

I think it's better to quietly skip, until a client uploads a correct one (which will be fetched then due to its new timestamp).

Test included.

I kept this small, because I want to get it in ALL THE CHANNELS.
Attachment #676347 - Flags: review?(gps)

Comment 6

5 years ago
Comment on attachment 676347 [details] [diff] [review]
Band-Aid. v1

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

Code looks good. See nits.

::: services/sync/tests/unit/test_bookmark_store.js
@@ +4,5 @@
>  Cu.import("resource://services-sync/engines.js");
>  Cu.import("resource://services-sync/engines/bookmarks.js");
>  Cu.import("resource://services-sync/service.js");
>  Cu.import("resource://services-sync/util.js");
> +Cu.import("resource://services-common/utils.js");

Why?

@@ +377,5 @@
> +  record.folderName    = "";
> +  record.queryId       = "";
> +  record.parentName    = "Toolbar";
> +  record.parentid      = "toolbar";
> +  

Trailing whitespace.

@@ +397,5 @@
>    test_reparentOrphans();
>    if (engine._tracker._lazySave) {
>      engine._tracker._lazySave.clear();
>    }
> +  test_empty_query_doesnt_die();

Would you mind adding the new test with add_test() and calling run_next_test()? I know it breaks convention in this file but I'd rather not add more engineering debt.
Attachment #676347 - Flags: review?(gps) → review+
(Assignee)

Comment 7

5 years ago
Created attachment 676358 [details] [diff] [review]
Part 0: modernize test. (Mechanical change.)
Attachment #676358 - Flags: review+
(Assignee)

Comment 8

5 years ago
Created attachment 676360 [details] [diff] [review]
Part 1: nits addressed. v2

Nits addressed. Uploaded for landing approval.
(Assignee)

Comment 9

5 years ago
https://hg.mozilla.org/services/services-central/rev/e9418e7f4ab5
https://hg.mozilla.org/services/services-central/rev/8bc890ed3683
Whiteboard: [fixed in services][qa-]
(Assignee)

Comment 10

5 years ago
Created attachment 676417 [details] [diff] [review]
Part 1: revised. v3

Busted another test. Made this a little more nuanced!
Attachment #676360 - Attachment is obsolete: true
(Assignee)

Comment 11

5 years ago
Fix was here:

https://hg.mozilla.org/services/services-central/rev/424592561c43
(Assignee)

Updated

5 years ago
Depends on: 806656
(Assignee)

Comment 12

5 years ago
   https://hg.mozilla.org/integration/mozilla-inbound/rev/ea46051fdc77
   https://hg.mozilla.org/integration/mozilla-inbound/rev/561c637077fa

This affects all released versions; handling of malformed records has been poor back to Firefox 4.

I'd like to land this fix in Aurora and Beta, once we've had some verification on Nightly, because this will affect users who've been using Firefox for Android for a while.

Tracy, would you mind verifying with a services-central build (rather than waiting for Nightly)?

Things to check:

* Ordinary syncing between two profiles. Make sure that queries -- "Recent" etc. -- work, and there are no errors. (Do a "Sync Now" to make sure they get reported.)

* Syncing to Android.


Precise STR:

* Once you've synced with Android, quit desktop and delete all of your data from the Sync server (from another browser). You should be able to do this through Account Portal; if not, an HTTP DELETE to the storage URL will do the trick.

* Now force a sync on Android: Settings > Accounts & sync > your account > Menu > Sync Now. Wait for it to finish. This'll put bad data on the server.

* Now set up a new desktop profile. Delete all of your bookmarks, turn on logOnSuccess, then pair with your phone. Sync. An older release will fail; with this fix, you'll see log messages in the success log:

  Skipping malformed query bookmark: <some ID>

and those queries won't appear (e.g., smart bookmarks on your toolbar won't appear).


After Bug 806656 lands, those queries should sync successfully.
status-firefox16: --- → affected
status-firefox17: --- → affected
status-firefox18: --- → affected
Whiteboard: [fixed in services][qa-] → [fixed in services][qa+]
Target Milestone: --- → mozilla19
(Assignee)

Updated

5 years ago
Whiteboard: [fixed in services][qa+] → [fixed in services][qa+][waiting for verification before requesting uplift]
Yes, I will check this against s-c build from this morning.
https://hg.mozilla.org/mozilla-central/rev/ea46051fdc77
https://hg.mozilla.org/mozilla-central/rev/561c637077fa
Status: ASSIGNED → RESOLVED
Last Resolved: 5 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Ah, there wasn't a build from this morning but the last s-c build of 1029 had this apparently picked up this fix.  

I reproduced on an older build first, so I'd be sure to know what I was verifying here.  With this fix I see success log with 

Skipping malformed query bookmark: <some ID>

as expected.

good to go for uplift to other channels.
QA Contact: twalker

Updated

5 years ago
Whiteboard: [fixed in services][qa+][waiting for verification before requesting uplift] → [verified in services][qa+][waiting for verification before requesting uplift]
(Assignee)

Comment 16

5 years ago
Thanks, Tracy, that's fantastic.
Whiteboard: [verified in services][qa+][waiting for verification before requesting uplift] → [verified in services][qa+]
(Assignee)

Comment 17

5 years ago
Comment on attachment 676417 [details] [diff] [review]
Part 1: revised. v3

[Approval Request Comment]
Bug caused by (feature/regressing bug #): 
  Combination of long-term lack of robustness (< Fx4) and Bug 806634, which generated bad records.

User impact if declined: 
  Failure to sync bookmarks in some circumstances.

Testing completed (on m-c, etc.): 
  QA verified on s-c.

Risk to taking this patch (and alternatives if risky): 
  Essentially 0.

String or UUID changes made by this patch: 
  None.
Attachment #676417 - Flags: approval-mozilla-beta?
Attachment #676417 - Flags: approval-mozilla-aurora?
(Assignee)

Comment 18

5 years ago
Comment on attachment 676358 [details] [diff] [review]
Part 0: modernize test. (Mechanical change.)

Should be a rubberstamp approval; routine test modernization as a prerequisite for Part 1.
Attachment #676358 - Flags: approval-mozilla-beta?
Attachment #676358 - Flags: approval-mozilla-aurora?
Comment on attachment 676358 [details] [diff] [review]
Part 0: modernize test. (Mechanical change.)

go ahead and uplift to branches now so this gets into 17 b4
Attachment #676358 - Flags: approval-mozilla-beta?
Attachment #676358 - Flags: approval-mozilla-beta+
Attachment #676358 - Flags: approval-mozilla-aurora?
Attachment #676358 - Flags: approval-mozilla-aurora+
Attachment #676417 - Flags: approval-mozilla-beta?
Attachment #676417 - Flags: approval-mozilla-beta+
Attachment #676417 - Flags: approval-mozilla-aurora?
Attachment #676417 - Flags: approval-mozilla-aurora+
(Assignee)

Comment 20

5 years ago
   https://hg.mozilla.org/releases/mozilla-beta/rev/ec9a0c5f41ca
   https://hg.mozilla.org/releases/mozilla-beta/rev/e23a57ca75a9

   https://hg.mozilla.org/releases/mozilla-aurora/rev/018df0692d6a
   https://hg.mozilla.org/releases/mozilla-aurora/rev/cab03de92c7e
status-firefox17: affected → fixed
status-firefox18: affected → fixed

Updated

4 years ago
QA Contact: twalker
You need to log in before you can comment on or make changes to this bug.