Status

()

enhancement
P3
normal
a year ago
10 days ago

People

(Reporter: lina, Unassigned)

Tracking

(Depends on 3 bugs, Blocks 2 bugs, {meta})

Firefox Tracking Flags

(Not tracked)

Details

This bug covers remaining work to flip the `services.sync.engine.bookmarks.buffer` pref to true, and have it ride to Release.
Depends on: 1433178
Depends on: 1433180
Depends on: 1433182
Depends on: 1433697
Depends on: 1433698
Depends on: 1433806
Depends on: 1433807
Depends on: 1433827
Priority: -- → P3
Summary: Enable structured bookmark application by default → [Meta] Enable structured bookmark application by default
Depends on: 1434800
Depends on: 1435166
Depends on: 1435553
Depends on: 1435556
Depends on: 1435588

Comment 1

a year ago
Continuing the discussion from Bug 1305563 comment 221,
I tried uploading/sending my ~40k bookmarks to the server, but it repeatedly fails after ~20 minutes with a Transaction timeout error you can see below from the sync log file (there was no problem syncing 2238 bookmarks)

Before that sync, I deleted all bookmarks in the bookmarks menu and toolbar while connected to Sync to make sure all bookmarks were deleted on the server (although it might keep deleted records marked as deleted). Waited for the changes to sync until the sync icon stops cycling, then disconnected from Sync, imported my ~40k bookmarks from a backup file, and reconnected to Sync to make it upload/send the bookmarks to the server, which fails :

> 1517845670008	Sync.Engine.Bookmarks.Mirror	DEBUG	Applying merged tree
> 1517845670026	Sync.Engine.Bookmarks.Mirror	DEBUG	Setting up merge states table
> 1517845672686	Sync.Engine.Bookmarks.Mirror	DEBUG	Rewriting tag queries in mirror
> 1517845672718	Sync.Engine.Bookmarks.Mirror	DEBUG	Inserting new URLs into Places
> 1517845708719	Sync.Engine.Bookmarks.Mirror	DEBUG	Updating value states for local bookmarks
> 1517845725195	Sync.Engine.Bookmarks.Mirror	DEBUG	Updating structure states for local bookmarks
> 1517845727827	Sync.Engine.Bookmarks.Mirror	DEBUG	Removing remotely deleted items from Places
> 1517845728614	Sync.Engine.Bookmarks.Mirror	DEBUG	Flagging remotely deleted items as merged
> 1517845728614	Sync.Engine.Bookmarks.Mirror	DEBUG	Recording observer notifications
> 1517845728614	Sync.Engine.Bookmarks.Mirror	DEBUG	Recording observer notifications for removed items
> 1517845728614	Sync.Engine.Bookmarks.Mirror	DEBUG	Recording observer notifications for changed GUIDs
> 1517845730111	Sync.Engine.Bookmarks.Mirror	DEBUG	Recording observer notifications for new items
> 1517845730121	Sync.Engine.Bookmarks.Mirror	DEBUG	Recording observer notifications for moved items
> 1517845730147	Sync.Engine.Bookmarks.Mirror	DEBUG	Recording observer notifications for changed items
> 1517845730897	Sync.Engine.Bookmarks.Mirror	DEBUG	Recording observer notifications for changed annos
> 1517845730900	Sync.Engine.Bookmarks.Mirror	DEBUG	Recording notifications for changed keywords
> 1517845730902	Sync.Engine.Bookmarks.Mirror	DEBUG	Staging locally changed items for upload
> 1517845898497	Sync.Engine.Bookmarks.Mirror	DEBUG	Fetching records for local items to upload
> 1517845906449	Sync.Engine.Bookmarks.BookmarkSyncUtils	DEBUG	pushChanges: Processed change records: {"weak":0,"skipped":0,"updated":0}
> 1517845906450	Sync.Status	DEBUG	Status for engine bookmarks: error.engine.reason.unknown_fail
> 1517845906450	Sync.Status	DEBUG	Status.service: success.status_ok => error.sync.failed_partial
> 1517845906450	Sync.ErrorHandler	DEBUG	bookmarks failed: Error: Transaction timeout, most likely caused by unresolved pending work. (resource://gre/modules/Sqlite.jsm:641:33) JS Stack trace: executeTransaction/promise</timeoutPromise</<@Sqlite.jsm:641:33 < notify@Timer.jsm:47:7
> 1517845906455	Sync.Doctor	INFO	Skipping validation of bookmarks: Probability threshold not met
> 1517845906455	Sync.Doctor	INFO	Skipping validation: no engines qualify
> 1517845906458	Sync.Doctor	INFO	bookmarks reparier did not advance.
> 1517845906459	Sync.Synchronizer	INFO	Sync completed at 2018-02-05 17:51:46 after 1285.84 secs.
Let's consolidate our perf discussions in bug 1433806. Thanks very much for trying this out, you are the person with the second-highest number of bookmarks I've seen. :-) The highest I've ever seen is 48k, and they reported frequent UI hangs due to the volume, even without Sync.

(In reply to nivtwig from comment #1)
> I tried uploading/sending my ~40k bookmarks to the server, but it repeatedly
> fails after ~20 minutes with a Transaction timeout error you can see below
> from the sync log file (there was no problem syncing 2238 bookmarks)

OK, we at least got as far as staging everything for upload. We may want to break that out into a separate transaction...it's only part of the merge transaction so that it can join on `mergeStates`, and the only reason it needs to do that is to ratchet creation times backward. Given that this is best-effort, anyway, and we'd eventually like to remove it (bug 1407731), I think it's reasonable to use another temp table to store IDs for weak reupload, instead of keeping `mergeStates` around. This will help smaller trees, too.

3 seconds to set up `mergeStates`, 37 seconds to insert URLs, 20 seconds to insert and update is not too bad in your case. We can optimize more once a sync actually finishes for you.

How does Firefox behave for you during those 20 minutes? Can you actually interact with the UI, bookmarks menu, etc., or does everything slow to a crawl?

> I deleted all bookmarks in the bookmarks menu and toolbar
> while connected to Sync to make sure all bookmarks were deleted on the
> server (although it might keep deleted records marked as deleted).

If you delete bookmarks while connected to sync, it'll upload tombstones for all of them, yes.

Comment 3

a year ago
(In reply to Kit Cambridge (they/them) [:kitcambridge] from comment #2)
> Let's consolidate our perf discussions in bug 1433806. Thanks very much for
> trying this out, you are the person with the second-highest number of
> bookmarks I've seen. :-) The highest I've ever seen is 48k, and they
> reported frequent UI hangs due to the volume, even without Sync.

My previous comment was not a perf discussion, the point I was trying to make was about Sync totally failing: that Sync fails consistently when uploading ~40000 bookmarks. Why does it fail?
If there is some preset limit of the server such as max transaction time that triggers a timeout and fail, maybe you should raise it.
On the other hand it failed in another Sync again after 5 minutes, not just 20 minutes, so the time to fail is very variable, therefore if the cause is not a timeout limit , then maybe there is another problem, that you should check in order to let people upload large bookmark sets, without the Sync failing repeatedly or frequently.

> OK, we at least got as far as staging everything for upload. We may want to
> break that out into a separate transaction...it's only part of the merge
> transaction so that it can join on `mergeStates`, and the only reason it
> needs to do that is to ratchet creation times backward. Given that this is
> best-effort, anyway, and we'd eventually like to remove it (bug 1407731), I
> think it's reasonable to use another temp table to store IDs for weak
> reupload, instead of keeping `mergeStates` around. This will help smaller
> trees, too.

I didn't really understand that (and that's ok), and whether it might help with the Sync failing or just with cutting the time (which might also help with Sync failing if the cause is a timeout)

> 3 seconds to set up `mergeStates`, 37 seconds to insert URLs, 20 seconds to
> insert and update is not too bad in your case. We can optimize more once a
> sync actually finishes for you.

For that I need the Sync fails/errors to be fixed ... :)

> How does Firefox behave for you during those 20 minutes? Can you actually
> interact with the UI, bookmarks menu, etc., or does everything slow to a
> crawl?

Generally, it doesn't slow to a crawl and is fine most of the time. 
Sometimes there are some minor lags when switching tabs, or typing text, that I think come from the Sync, but are not too annoying.
(In reply to nivtwig from comment #3)
> My previous comment was not a perf discussion, the point I was trying to
> make was about Sync totally failing: that Sync fails consistently when
> uploading ~40000 bookmarks.

That's fair. I'm grouping it under perf because we know Sync is slow for large trees...if it were faster, the transaction wouldn't time out in the first place.

> Why does it fail?

The short answer: you have a lot of bookmarks, and Sync doesn't handle large trees. We're at a point where we can actually make this better, though.

> If there is some preset limit of the server such as max transaction time
> that triggers a timeout and fail, maybe you should raise it.

For context, the transaction timeout error in your log is a local error, from https://searchfox.org/mozilla-central/rev/f80722d4f3bfb722c5ec53880c4a7efb71285676/toolkit/modules/Sqlite.jsm#13-14,636-643. As I said in the next paragraph, we can break the transaction up to mitigate that. I think we'll try that before raising the timeout, since a multi-minute transaction is more likely to be a bug than just taking too long.

> I didn't really understand that (and that's ok), and whether it might help
> with the Sync failing or just with cutting the time

It should help with the sync failing.

> Generally, it doesn't slow to a crawl and is fine most of the time. 
> Sometimes there are some minor lags when switching tabs, or typing text,
> that I think come from the Sync, but are not too annoying.

That's good to know, if pleasantly surprising, thanks!
Depends on: 1436207
Depends on: 1436215
Depends on: 1436837
Depends on: 1440116

Updated

a year ago
Depends on: 1438675
Depends on: 1443388
Depends on: 1437153
Depends on: 1440518
Depends on: 1436888
Depends on: 1443619
Depends on: 1444262
No longer depends on: 1435556
Blocks: 1449730
Depends on: 1451152
Depends on: 1456221
Blocks: PlacesIO
Depends on: 1461009
Depends on: 1462072
Reporter

Updated

11 months ago
Depends on: 1471988

Updated

11 months ago
Depends on: 1472963

Updated

11 months ago
Depends on: 1472965
Reporter

Updated

11 months ago
Depends on: 1473382
Reporter

Updated

11 months ago
Depends on: 1473384
Reporter

Updated

11 months ago
Depends on: 1472241
Reporter

Updated

11 months ago
Depends on: 1463938
Reporter

Updated

10 months ago
Depends on: 1472435
Reporter

Updated

10 months ago
Depends on: 1478918
Reporter

Updated

10 months ago
Depends on: 1478922
Reporter

Updated

9 months ago
Depends on: 1485480
Reporter

Updated

8 months ago
Depends on: 1496878
Keywords: meta
Reporter

Updated

6 months ago
Depends on: 1506287
Reporter

Updated

5 months ago
Depends on: 1515784
Reporter

Updated

4 months ago
Depends on: 1521840
Reporter

Updated

4 months ago
Depends on: 1482608
Reporter

Updated

19 days ago
Summary: [Meta] Enable structured bookmark application by default → [Meta] New bookmark sync
Reporter

Updated

19 days ago
Depends on: 1548884
Reporter

Updated

10 days ago
Depends on: 1551062
You need to log in before you can comment on or make changes to this bug.