Open Bug 1234400 Opened 4 years ago Updated 2 years ago

Investigate failures to sync addons.

Categories

(Firefox :: Sync, defect, P3)

defect

Tracking

()

People

(Reporter: markh, Unassigned)

References

(Depends on 1 open bug)

Details

Of 23.35 million Syncs, 1.73k times a "new" addon failed to Sync. These failures accumulate (ie, next Sync the addon is tried again and fails) leading to 23k total submissions for addon failures.

Compare this with 6.4k total/267 new for bookmarks, which is the next worst engine and theoretically more prone to failures (eg, database corruption, etc), it's unclear why addons would fail to apply. We should try and work out what kinds of failures we see here and either fix it or handle it more gracefully such that it's not reported as a failure.
Flags: firefox-backlog+
Bug 1055616 looks like a good start.
Priority: -- → P2
With bug 1055616 fixed, we hope to see WEAVE_ENGINE_APPLY_[NEW_]FAILURES for the addons engine to be roughly the same as for other engines - from the earlier analysis:

Of the 23.35M syncs started, we recorded (WEAVE_ENGINE_APPLY_FAILURES) 23k submissions for addons failing to apply, 6.4k for bookmarks, 1.7K for passwords and 98 for history. However, Sync always retries failed records, so these figures are cumulative (ie, it almost certainly records the same record failing to apply multiple times.) The WEAVE_ENGINE_APPLY_NEW_FAILURES probe records how many “new” records fail to apply each sync (ie, only recording items that didn’t fail in the previous sync), so is probably of more interest - it records 1.73k submissions for addons, 267 for bookmarks, 102 for passwords and 231 for history. We should try and investigate why addons fail to apply but the other figures seem relatively low.

This bug remains open until we can get new figures from telemetry to tell us if further investigation is necessary.
Marking this as the P1 to prioritize looking at the new telemetry data soon.
Priority: P2 → P1
Depends on: 1271186
Depends on: 1275139
Priority: P1 → P3
<https://discourse.mozilla.org/t/-/17748/5?u=grahamperrin> tl;dr there's a remarkable, maybe consistent, failure to sync: 

Sea Containers <https://addons.mozilla.org/firefox/addon/sea-containers/>

> … /addon-813862-latest.xpi?src=dp-btn-primary
Present with Firefox 55.0.3 (64-bit) on FreeBSD-CURRENT, not present following the most recent sync to Firefox 54.0.1 (64-bit) on build 17A352a of pre-release Mac OS X 10.13 (macOS High Sierra): 

Slim Add-ons Manager
<https://addons.mozilla.org/firefox/addon/slim-add-ons-manager/>

> Works with Firefox 35.0 - 56.*, …

– so it _should_ be installed at the Mac with 54.x. 

Maybe worth noting that the Mac is very slow (booting from USB 2.0, Apple File System performs dreadfully with rotational media). 

A few minutes later, before restarting Firefox (to 55.x) at the Mac, for a better overview I enabled: 

Cleanest Addon Manager
<https://addons.mozilla.org/thunderbird/addon/cam/>

– then compared the numbers of extensions at both computers. 

At 55.0.3 on FreeBSD-CURRENT: 

*  58  enabled
* 121 disabled

At 54.0.1 on High Sierra: 

*  69  enabled
* 103 disabled

– unfortunately the Australis and overflow menus have ceased working at the Mac, and so on, so I can't get `about:support`. I hope to get it with 55.x …
After launching 55.0.3 on High Sierra then observing (in the Australis menu) an apparently complete sync: 

*  56  enabled
* 114 disabled

– including Slim Add-ons Manager
– still omitting Sea Containers. 

Closer (I assume that Test Pilot extensions are not synced), but not close enough. 

Sea Containers
==============

At 55.0.3 on FreeBSD-CURRENT: 

$ date ; uname -v
Mon 28 Aug 2017 11:12:49 BST
FreeBSD 12.0-CURRENT #0 r320869: Mon Jul 10 13:57:55 UTC 2017     root@releng3.nyi.freebsd.org:/usr/obj/usr/src/sys/GENERIC 
$ pwd
/home/grahamperrin/.mozilla/firefox/5fiaf2mq.everyday-1500052394988/weave/logs
$ grep -R Sea\ Containers .
./error-sync-1503776130076.txt:1503776130073    Sync.ErrorHandler       DEBUG    - Sea Containers, version 0.5, id {d975a11d-08cd-4aea-b7c0-989209ad860f}
./error-sync-1503723248424.txt:1503723245112    Sync.AddonsReconciler   DEBUG   Rectifying state for addon Sea Containers (version=0.5, id={d975a11d-08cd-4aea-b7c0-989209ad860f})
$ 

At 55.0.3 on the Mac: 

* there's a sole error-sync-….txt file from 07:21 this morning
  with _no mention_ of Sea Containers.
For reference: today's messages at and under <https://mozilla.logbot.info/firefox/20171031#c13787906>. 

Ideally: I'd like to obtain and provide logs. 

Realistically (sorry): I can't give the time to getting what's required, where Apple File System is making this particular Mac so slow and unreliable. I might find more time to devote to Firefox Sync in … spring 2018.
A few days ago, with some help from About Sync <https://addons.mozilla.org/addon/about-sync/> I found lines such as this: 

1519302016769	Sync.Engine.Extension-Storage	ERROR	Syncing storage-sync-crypto: request failed: Error: HTTP 507; Error: HTTP 507 Insufficient Storage: Resource access is forbidden for this user (Maximum bytes per object exceeded (19185 > 16384 Bytes.) (resource://services-common/kinto-http-client.js:2353:21) JS Stack trace: formatResponse@kinto-http-client.js:2376:21 < processResponse@kinto-http-client.js:2351:14

I made a guess, ceased to include add-ons and since then … at a glance, no more errors of that type. 

Would it be useful to identify the excessive object? It's mostly gobbledygook to me :-)
(In reply to Graham Perrin from comment #8)
> A few days ago, with some help from About Sync
> <https://addons.mozilla.org/addon/about-sync/> I found lines such as this: 
> 
> 1519302016769	Sync.Engine.Extension-Storage	ERROR	Syncing
> storage-sync-crypto: request failed: Error: HTTP 507; Error: HTTP 507
> Insufficient Storage: Resource access is forbidden for this user (Maximum
> bytes per object exceeded (19185 > 16384 Bytes.)
> (resource://services-common/kinto-http-client.js:2353:21) JS Stack trace:
> formatResponse@kinto-http-client.js:2376:21 <
> processResponse@kinto-http-client.js:2351:14

Thanks Graham - I opened bug 1442519 and added you to the CC list.

> I made a guess, ceased to include add-ons and since then … at a glance, no
> more errors of that type. 

The error you are seeing is related to syncing addon *data*, where this bug is about syncing the addons themselves. I'm not familiar with the details of how addon data is synced (although I can confirm that the "Addons" option in about:preferences controls both), hence the other bug - hopefully someone will followup there.
You need to log in before you can comment on or make changes to this bug.