1320772 - Atomic Uploads breaks stylishsync extension

Status: RESOLVED DUPLICATE of bug 1321396

(Firefox :: Sync, defect, P1)

Description

[Benson Wong [:mostlygeek]]

Seeing a lot of these in the nginx logs: 

POST /1.5/xxx/storage/stylishsync?batch=true
POST /1.5/xxx/storage/stylishsync?batch=true
POST /1.5/xxx/storage/stylishsync?batch=true
POST /1.5/xxx/storage/stylishsync?batch=true
...

Stylishsync [1] is an extension that uses Sync to synchronize stylish settings across browsers. 

A few problems arise: 
 

 - batches continue building up until they timeout and are garbage collected
   - one user uploaded more than 500 batches that had to be purged
   - resulted in > 135MB of wasted disk space
 - many, many retries to sync without success

[1] https://addons.mozilla.org/en-US/firefox/addon/stylishsync/

Comment 1

[Benson Wong [:mostlygeek]]

I emailed the author of stylishsync this bug.

Comment 2

[Benson Wong [:mostlygeek]]

The User agent string: 

Firefox/52.0a2 (Intel Mac OS X 10.9) FxSync/1.54.0.20161124004020.desktop

Comment 3

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

Can't repro locally even when i add enough styles so that batching occurs. Everything goes through fine.

Also that build would be long after bug 1308994 has been fixed so it couldn't be that (and you wouldn't expect this behavior if is because of that).

I strongly suspect it's effectively the "non-skippable" version of bug 1273342, which intentionally has this behavior, sort of.

It's intentional we don't clean up on the server for these cases, since the server is expected to clean up after itself (see bug 1295303).

It's also intentional that we *do* retry records for engines which require all their records make it, e.g. bookmarks (although maybe we shouldn't).

To resolve this, we'd probably need to A) have stylish sync set `allowSkippedRecord` to true on it's engine (or maybe this should be true by default for custom engines in some sort of hacky way?), and B) uplift bug 1273342's patch.

Comment 4

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

(In reply to Thom Chiovoloni [:tcsc] from comment #3)
> It's also intentional that we *do* retry records for engines which require
> all their records make it, e.g. bookmarks (although maybe we shouldn't).

To clarify, the alternative here would be to automatically disable the engine in question, since it will never successfully sync again.

Comment 5

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

After some discussion, we decided to change the default here -- most engines shouldn't abort the sync if a single record is too large. That work is in bug 1321396.

Comment 6

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

Marking as fixed since that code has landed (I don't recall my reason for making that a separate bug from this...)

Comment 7

[Benson Wong [:mostlygeek]]

This appears to still be happening: 

I noticed a very large purge job and dug into it a bit deeper for the user. 
Here is the client uploading likely the same batch repeatedly without committing it. 
Each request is 209,646 bytes. 

> UA: Firefox/52.0a2 (Intel Mac OS X 10.9) FxSync/1.54.0.20161228004005.desktop
> 
> [2017-01-25T05:37:32+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1683 HTTP/1.1" 202 97 209646
> [2017-01-25T06:37:34+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1684 HTTP/1.1" 202 97 209646
> [2017-01-25T07:37:36+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1685 HTTP/1.1" 202 97 209646
> [2017-01-25T08:37:38+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1686 HTTP/1.1" 202 97 209646
> [2017-01-25T09:37:41+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1687 HTTP/1.1" 202 97 209646
> [2017-01-25T10:37:43+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1688 HTTP/1.1" 202 97 209646
> [2017-01-25T11:37:45+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1689 HTTP/1.1" 202 97 209646
> [2017-01-25T12:37:47+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1690 HTTP/1.1" 202 97 209646
> [2017-01-25T13:37:51+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1691 HTTP/1.1" 202 97 209646
> [2017-01-25T14:37:53+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1692 HTTP/1.1" 202 97 209646
> [2017-01-25T15:37:55+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1693 HTTP/1.1" 202 97 209646
> [2017-01-25T16:37:57+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1694 HTTP/1.1" 202 97 209646
> [2017-01-25T17:10:42+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1695 HTTP/1.1" 202 97 209646
...

Thom is your fix for bug 1321396 in FF 52.0a2?

Comment 8

[Mark Hammond (PTO; back Oct-3) [:markh] [:mhammond]]

(In reply to Benson Wong [:mostlygeek] from comment #7)
> Thom is your fix for bug 1321396 in FF 52.0a2?

It's not, but I just requested uplift to 52. It's going to live on 51 for this cycle though :(

Initially I thought that the symptoms above were not this bug, but now I think it is - in the first POST we have records that do fit, but then abort the batch when we some to make the second POST and find the oversized record.

Comment 9

[Mark Hammond (PTO; back Oct-3) [:markh] [:mhammond]]

(In reply to Benson Wong [:mostlygeek] from comment #7)
> > UA: Firefox/52.0a2 (Intel Mac OS X 10.9) FxSync/1.54.0.20161228004005.desktop
> > 
> > [2017-01-25T05:37:32+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1683 HTTP/1.1" 202 97 209646
> > [2017-01-25T06:37:34+00:00] "POST /1.5/xxx/storage/stylishsync?batch=b1684 HTTP/1.1" 202 97 209646

Although it does seem odd there's no "batch=true" entries here - are they just missing from your list, or are they actually missing?

If batch=true requests do exist for this client, then:
> in the first POST we have records that do fit, but then abort
> the batch when we some to make the second POST and find the oversized record.

should probably read "the first 2 POSTS in the batch succeed and we find the oversized record in the 3rd"

Comment 10

[Benson Wong [:mostlygeek]]

(In reply to Mark Hammond [:markh] from comment #9)
> Although it does seem odd there's no "batch=true" entries here - are they
> just missing from your list, or are they actually missing?

They're there. I omitted them to make the retry list easier to see.

Comment 11

[Mark Hammond (PTO; back Oct-3) [:markh] [:mhammond]]

This is bug 1321396 which is now on 52 - there's nothing else actionable here.