867205 - Sync can take a really long time to initially connect

Status: RESOLVED WORKSFORME

(Firefox for Metro Graveyard :: Sync, defect)

Description

[Jim Mathies [:jimm]]

spun off from grab bag bug 865318:

> - When initially starting Firefox Metro and then going under "Sync" in the
> "Settings" charm once you have paired two devices together, it will display
> the "Connecting.." message and this can take up to 5 minutes at times.

Comment 1

[Jim Mathies [:jimm]]

Kamil, what kind of a network connection are you on? Sync for me can seem a bit slow when syncing (looking at the trace) but overall it's not that bad. I believe it is supposed to be metered such that it doesn't use a lot of cpu time.

Comment 2

[Kamil Jozwiak [:kjozwiak]]

Jim,

I am using the Cable 28 package from TekSavvy:
Up to 28 Mbps Down / 1 Mbps Up

The machine that I was testing on (my main Desktop) is plugged directly into a dlink router.

I can try this a few more times throughout the day on lets say Saturday (as I am at work during the weekdays) and see if it improves when internet loads are lower.

Is there any logs or anything that I can provide to help you out?

Comment 3

[Brian R. Bondy [:bbondy]]

I'm sure his internet connection is fine, I've seen it take a long time before as well.

Comment 4

[Richard Newman [:rnewman]]

On desktop, "Connecting" in the settings wizard is displayed during J-PAKE pairing. Is that the case for the Metro UI, or does it also show during the first sync?

If the former, perhaps J-PAKE pairing is taking unduly long.

If the latter, it's probably the first sync.

Note that if you have a large profile -- hundreds of bookmarks, thousands or tens of thousands of history entries, etc. -- then you're downloading, decrypting, and processing upwards of 10MB of data, and that can indeed take several minutes.

A log with 

  services.sync.log.logger.service.jpakeclient
  services.sync.log.logger.network.resources
  services.sync.log.logger.engine.history

set to "Trace" (capital T), and

  services.sync.log.appender.file.logOnSuccess

set to 'true' will help clarify. You'll need to set these, restart the browser (swipe from the top), and then set up Sync. Wait for the sync to finish (five minutes), then check about:sync-log for a success log.

(Can we capture dump or console logs from Metro?)

Comment 5

[Jim Mathies [:jimm]]

Also in about:sync-log logs the number column on the left is in msecs, so (last number - first) / 1000 = seconds for the sync. Might be useful to find one that took a really really long time and post it.

Comment 6

[Jim Mathies [:jimm]]

(In reply to Richard Newman [:rnewman] from comment #4)
> On desktop, "Connecting" in the settings wizard is displayed during J-PAKE
> pairing. Is that the case for the Metro UI, or does it also show during the
> first sync?

http://mxr.mozilla.org/mozilla-central/source/browser/metro/base/content/sync.js#511

From 'weave:service:login:start' to 'weave:service:sync:start'.

> (Can we capture dump or console logs from Metro?)

Sure, we have a console. Also from a remote debugger you can see all console output.

Comment 7

[Jim Mathies [:jimm]]

So I'm not sure if we are seeing simple network latency here or something more serious. I regularly get around 10 second connect times while testing. 

1367441487715	Sync.Service	DEBUG	Fetching and verifying -- or generating -- symmetric keys.
1367441498631	Sync.Resource	DEBUG	mesg: GET success 200 https://phx-sync622.services.mozilla.com/1.1/uvcuqnsa6naewnv55uggbps2a5mixdgf/info/collections

I don't know if that's normal.

Comment 8

[Richard Newman [:rnewman]]

(In reply to Jim Mathies [:jimm] from comment #7)

> I don't know if that's normal.

PHX is under load, but those two times are not the start and end of the network fetch; they're the end times of two different phases in initial setup. You need to set the resource logger to Trace and restart Firefox to get more detailed times.

(You might find it interesting to search for "logger" in prefs and set them all to Trace, then restart and sync.)

But overall, my recollection (without measuring) is that Metro fx seems to be about five times slower loading pages than desktop -- slightly worse than browsing in Fennec on my Android phone. (And nothing makes the fan go on on my Surface Pro other than sitting idle on Saveur.com in MetroFox.)

There might be some underlying perf issue here, either network or JS or both.

Comment 9

[Jim Mathies [:jimm]]

Hmm, right startup we seem drag down a bit, but after a few seconds we get the same response times as desktop - 

desktop:
7.17
0.35
0.16
0.27
0.13
0.24
0.55
0.13

metro:
9.04
8.76
8.08
8.81
0.36
0.21
0.19
0.22
0.73
0.23
0.16
0.20

Do we have a stand alone local dummy sync server in services we can use to do testing?

Comment 10

[Jim Mathies [:jimm]]

Performance times today seem much improved compared to yesterday.

Comment 11

[Richard Newman [:rnewman]]

(In reply to Jim Mathies [:jimm] from comment #9)

> Do we have a stand alone local dummy sync server in services we can use to
> do testing?

We have a great one... for Sync 2.0 :/

Running services/sync/tests/unit/test_syncengine_sync.js in xpcshell-tests should be approximately equivalent.

Comment 12

[Jim Mathies [:jimm]]

The connecting indicator has been removed so this should grab people's attention anymore.