Open Bug 1433177 Opened 3 years ago Updated 9 months ago

[Meta] New bookmark sync

Categories

(Firefox :: Sync, enhancement, P3)

enhancement

Tracking

()

People

(Reporter: lina, Unassigned)

References

(Depends on 5 open bugs, Blocks 4 open bugs)

Details

(Keywords: meta)

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
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
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.
(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: 1438675
Depends on: 1443388
Depends on: 1437153
Depends on: 1440518
Depends on: 1436888
Depends on: 1443619
No longer depends on: 1435556
Blocks: 1449730
Depends on: 1456221
Blocks: PlacesIO
Depends on: 1461009
Depends on: 1462072
Depends on: 1471988
Depends on: 1472963
Depends on: 1472965
Depends on: 1473382
Depends on: 1473384
Depends on: 1472241
Depends on: 1463938
Depends on: 1472435
Depends on: 1478918
Depends on: 1478922
Depends on: 1485480
Depends on: 1496878
Keywords: meta
Depends on: 1506287
Depends on: 1515784
Depends on: 1521840
Depends on: 1482608
Summary: [Meta] Enable structured bookmark application by default → [Meta] New bookmark sync
Depends on: 1548884
Depends on: 1551062
Depends on: 1552382
Depends on: 1555173
Depends on: 1557551
Depends on: 1561467
Blocks: 1586421

Is it feasible to be implemented in Firefox 72 next year, or are the 'Depends on' required to be fixed first?

Depends on: 1587357
Depends on: 1587359
Duplicate of this bug: 1577691

I am using version 70.0 US English. Is the new Sync already deployed in this version? Sync is disabled since I reported this issue.

You need to log in before you can comment on or make changes to this bug.