Closed Bug 636304 Opened 13 years ago Closed 8 years ago

[meta] Poor XUL mobile first sync experience


(Firefox :: Sync, defect)

Not set





(Reporter: philikon, Unassigned)



      No description provided.
Depends on: 636300
Depends on: 636305
Depends on: 636309
Depends on: 636312
Depends on: 618496
Depends on: 636382
Depends on: 636393
Depends on: 636402
Apart from what look like non-optimal batch sizes for forms and passwords (bug 636312), most of the problems seem to be due to the sheer number of objects that are allocated during a first sync, particularly the history sync portion. Many of the main thread blocking events are in fact GC related.

I have preliminary patches for bug 636382, bug 636402 and bug 618496 that make us simply avoid creating unnecessary objects. With that I've managed to cut the number of allocated objects during a first sync with a large history profile (18k records) from 4.5M to 2.5M (counting strings). Further improvements such as bug 636305 can be made, probably cutting another 0.5M or so. Of course we will obviously level out at some point, syncing down tens of thousands of records takes its toll somewhere.

That said, we can try to push as many object allocations into C++ where the objects will not be have to wait for GC to be freed in one big gulp. Bug 636393 might be a low-hanging fruit, bug 636309 definitely a worthwhile long-term plan.
Depends on: 636478
Depends on: 636603
Depends on: 636631
Some more progress has been made:

* prepared patches for bug 636478 and 636382, got review, will land tomorrow
* prepared patch for bug 636402, awaiting review

We're now down to ca. 2.1M object allocations with my test profile (down from 4.5M). Here's how the various patches contribute to the reduction of object allocations:

Bug 636478:  700k
Bug 636382: 1100k
Bug 618496:  200k (preliminary patch)
Bug 636402:  400k (new)

Next up: bug 636305 and a proper patch for bug 618496.
Depends on: 636673
Depends on: 636676
Depends on: 636677
Any idea about per-invocation costs? The numbers reported in comment 2 are from some profile for the current sync code usage, yeah?

How are you tracking down which functions to optimize?
(In reply to comment #3)
> Any idea about per-invocation costs?

What invocation are you talking about? Function invocations? Or the invocations triggered by object allocations? At any rate, my findings indicate that none are actually a problem. It's the GC for the massive amount of objects that eventually happens that is.

During a Sync of my personal profile (18k history records, 250 bookmarks, 100 passwords, etc.), a first Sync allocates 65 "chunks" as reported by MOZ_GCTIMER (1 chunk = 1 MB!). As a result the periodic GC takes a long time while sweeping and freeing, blocking the main thread for 400-500ms at least 10 times (as reported by javascript.options.mem.log = true). On mobile it's even worse.

> The numbers reported in comment 2 are from
> some profile for the current sync code usage, yeah?


> How are you tracking down which functions to optimize?

With help from Andreas Gal I added some debugging output to Tracemonkey. The above numbers are for invocations of js_NewGCObject (there's also js_NewGCString and js_NewGCFunction which I haven't collected numbers for yet). The following snippet added to one of those functions prints the line that caused the new object to be allocated:

    if (cx->hasfp() && cx->fp()->isScriptFrame()) {
        printf("NewObject %s:%d\n", cx->fp()->script()->filename,
               js_PCToLineNumber(cx, cx->fp()->script(), cx->fp()->pc(cx)));

After running a first sync it's easy to aggregate all that output and find the biggest offenders in terms of object allocations, e.g.:

  56795 resource://services-sync/ext/Sync.js:169
  56796 resource://services-sync/ext/Sync.js:121
  75408 resource://services-sync/ext/Sync.js:80
  75408 resource://services-sync/ext/Sync.js:86
  75408 resource://services-sync/ext/Sync.js:92
  75408 resource://services-sync/ext/Sync.js:95
  90580 resource://services-sync/record.js:242
  96313 resource://services-sync/log4moz.js:210
 115101 resource://services-sync/log4moz.js:152
 150816 resource://services-sync/ext/Sync.js:126
 167439 resource://services-crypto/WeaveCrypto.js:670
 192622 resource://services-sync/log4moz.js:361
 192622 resource://services-sync/log4moz.js:365
 192622 resource://services-sync/log4moz.js:366
 192622 resource://services-sync/log4moz.js:367
 192623 resource://services-sync/log4moz.js:362
 260624 resource://services-crypto/WeaveCrypto.js:713
 674818 resource://services-sync/util.js:408
Depends on: 637576
Small status update: with the patches for bug 636676 and bug 636676 I'm now down to 1.8M object creations when syncing against my personal profile (which keeps growing, too).
With the patches for bug 636305 and bug 636673 we're now down to 1.6M objects. Bug 618496 will probably deliver the final round of improvements in terms of object allocations.
Depends on: 638297
Philipp, do you see any purpose in keeping this bug open, given Android Sync?
Summary: [meta] Poor mobile first sync experience → [meta] Poor XUL mobile first sync experience
lol xul mobile sync.
Closed: 8 years ago
Resolution: --- → WONTFIX
Component: Firefox Sync: Backend → Sync
Product: Cloud Services → Firefox
You need to log in before you can comment on or make changes to this bug.