Closed Bug 1382666 Opened 7 years ago Closed 3 years ago

Do not collect sync telemetry for self-hosted clients

Categories

(Firefox for Android Graveyard :: Android Sync, defect, P3)

54 Branch
defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: crybaby667, Unassigned)

References

Details

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:54.0) Gecko/20100101 Firefox/54.0
Build ID: 20170628075643

Steps to reproduce:

Install Fx on Android device and change parameter 'identity.sync.tokenserver.uri' to my Fx Sync 1.5 server.
If I put my URL into the address bar, I get the following (correct) message:
"'{"status": "error", "errors": [{"location": "body", "name": "", "description": "Unauthorized"}]}'."

If I then logon to my Mozilla account, my device appears in 'Devices and apps' in my account.




Actual results:

When I try to launch a new URL, I go 'History' and then to synchronized devices.
I then receive the message 'Welcome to Sync. Logon to sync passwords, history etc.".
But I'm already logged on!

I see some pages in my history from other Windows devices, but they're not linked to any specific device!


Expected results:

Sync for password, history etc. should be performed.
Component: Firefox Accounts → Android Sync
Product: Firefox for Android → Android Background Services
Flags: needinfo?(gkruglov)
Could you please clarify what you're seeing:

- you configure your device to sync against your custom server
- you login, and sync seems to succeed? You mention that you can see history records from desktop, which indicates that sync worked - at least partially?
- and yet somewhere in Android UI, you're seeing indication that you're not logged in?
- what do you see in Settings->Sync?
Flags: needinfo?(gkruglov) → needinfo?(crybaby667)
(In reply to :Grisha Kruglov from comment #1)
> Could you please clarify what you're seeing:
> 
> - you configure your device to sync against your custom server
YES, Fx Sync 1.5 is running on my Synology NAS.
And I'm not the only one facing issues:
https://github.com/SynoCommunity/spksrc/issues/2816#issuecomment-316666394
With Fx on Windows it still works without problems.

> - you login, and sync seems to succeed? You mention that you can see history
> records from desktop, which indicates that sync worked - at least partially?
YES, sync seems to work under Settings->Sync. Fx states "Last synchronization: X minutes ago".
But sync goes very fast, before it always took longer...

> - and yet somewhere in Android UI, you're seeing indication that you're not
> logged in? 
YES, if I tab on the URL bar and go to history and click then on "Synchronized devices (0 devices)", it states "Welcome to Sync" with a logon button. If I tap on it, it jumps to the Sync settings where my account is already logged in.
But I've now seen that the history is not synchronized anymore.

> - what do you see in Settings->Sync?
"Logged on as my@mail.com
Sync: activated
Last sync: 4 minutes ago"

Please note that I use the German version, so maybe the texts on the English version are slightly different.

I've also tried to create a new account, but I faced the same issues.
Flags: needinfo?(crybaby667)
With Fx 55.0 I see the following in the ADB logs:

08-14 10:33:10.075 17468 18168 I FxAccounts: firefox :: LoginStateMachineDelegate :: Fetching profile avatar information.
08-14 10:33:10.078 17468 17967 E FxAccounts: firefox :: FxAccountSyncAdapter :: Failed to get token.
08-14 10:33:10.078 17468 17967 E FxAccounts: org.mozilla.gecko.tokenserver.TokenServerException$TokenServerMalformedResponseException: org.mozilla.gecko.sync.UnexpectedJSONException$BadRequiredFieldJSONException: Expected key not present in result: hashed_fxa_uid
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.tokenserver.TokenServerClient.processResponse(TokenServerClient.java:226)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.tokenserver.TokenServerClient$TokenFetchResourceDelegate.handleHttpResponse(TokenServerClient.java:281)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.tokenserver.TokenServerClient.getTokenFromBrowserIDAssertion(TokenServerClient.java:329)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.sync.FxAccountSyncAdapter.syncWithAssertion(FxAccountSyncAdapter.java:484)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.sync.FxAccountSyncAdapter$3.handleMarried(FxAccountSyncAdapter.java:688)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.authenticator.FxADefaultLoginStateMachineDelegate.handleFinal(FxADefaultLoginStateMachineDelegate.java:81)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.login.FxAccountLoginStateMachine$ExecuteDelegate.handleTransition(FxAccountLoginStateMachine.java:64)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.login.Cohabiting$1.handleSuccess(Cohabiting.java:46)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.login.Cohabiting$1.handleSuccess(Cohabiting.java:28)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.background.fxa.FxAccountClient20$5.handleSuccess(FxAccountClient20.java:580)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.background.fxa.FxAccountClient20$ResourceDelegate$2.run(FxAccountClient20.java:280)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 10:33:10.078 17468 17967 E FxAccounts: Caused by: org.mozilla.gecko.sync.UnexpectedJSONException$BadRequiredFieldJSONException: Expected key not present in result: hashed_fxa_uid
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.sync.ExtendedJSONObject.throwIfFieldsMissingOrMisTyped(ExtendedJSONObject.java:397)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	at org.mozilla.gecko.tokenserver.TokenServerClient.processResponse(TokenServerClient.java:223)
08-14 10:33:10.078 17468 17967 E FxAccounts: 	... 16 more
08-14 10:33:10.083 17468 17967 I FxAccounts: firefox :: AndroidFxAccount :: Moving account named like XXXXXXXXXXX@XXXXX.XX to state Cohabiting
08-14 10:33:10.085 17468 17547 I GeckoLogger: firefox :: AndroidFxAccount :: Intent service launched to fetch profile.
08-14 10:33:10.126 17468 17967 D GeckoLogger: Thread with tag and thread id releasing lock: FxAccountSyncAdapter, 3461 ...
08-14 10:33:10.126 17468 17967 D GeckoLogger: Thread with tag and thread id releasing lock: FxAccountSyncAdapter, 3461 ... RELEASED
08-14 10:33:10.127 17468 17967 W FxAccounts: firefox :: FxAccountSyncAdapter :: Global session failed.
08-14 10:33:10.127 17468 17967 E FxAccounts: firefox :: FxAccountSyncAdapter :: Got exception syncing.
08-14 10:33:10.127 17468 17967 E FxAccounts: org.mozilla.gecko.tokenserver.TokenServerException$TokenServerMalformedResponseException: org.mozilla.gecko.sync.UnexpectedJSONException$BadRequiredFieldJSONException: Expected key not present in result: hashed_fxa_uid
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.tokenserver.TokenServerClient.processResponse(TokenServerClient.java:226)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.tokenserver.TokenServerClient$TokenFetchResourceDelegate.handleHttpResponse(TokenServerClient.java:281)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.tokenserver.TokenServerClient.getTokenFromBrowserIDAssertion(TokenServerClient.java:329)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.sync.FxAccountSyncAdapter.syncWithAssertion(FxAccountSyncAdapter.java:484)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.sync.FxAccountSyncAdapter$3.handleMarried(FxAccountSyncAdapter.java:688)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.authenticator.FxADefaultLoginStateMachineDelegate.handleFinal(FxADefaultLoginStateMachineDelegate.java:81)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.login.FxAccountLoginStateMachine$ExecuteDelegate.handleTransition(FxAccountLoginStateMachine.java:64)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.login.Cohabiting$1.handleSuccess(Cohabiting.java:46)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.fxa.login.Cohabiting$1.handleSuccess(Cohabiting.java:28)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.background.fxa.FxAccountClient20$5.handleSuccess(FxAccountClient20.java:580)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.background.fxa.FxAccountClient20$ResourceDelegate$2.run(FxAccountClient20.java:280)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 10:33:10.127 17468 17967 E FxAccounts: Caused by: org.mozilla.gecko.sync.UnexpectedJSONException$BadRequiredFieldJSONException: Expected key not present in result: hashed_fxa_uid
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.sync.ExtendedJSONObject.throwIfFieldsMissingOrMisTyped(ExtendedJSONObject.java:397)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	at org.mozilla.gecko.tokenserver.TokenServerClient.processResponse(TokenServerClient.java:223)
08-14 10:33:10.127 17468 17967 E FxAccounts: 	... 16 more
08-14 10:33:10.128 17468 18167 D GeckoLogger: Thread with tag and thread id releasing lock: FxAccountSyncAdapter, 3474 ...
08-14 10:33:10.128 17468 18167 D GeckoLogger: Thread with tag and thread id releasing lock: FxAccountSyncAdapter, 3474 ... NOT LOCKED
08-14 10:33:10.128 17468 18167 I FxAccounts: firefox :: FxAccountSyncAdapter :: Syncing done.
Deinstalled Fx, installed again and configured Sync again.
Now I get a different error. Sync seems to work, but nothing is synced.
On Windows clients it still works without problems.

My sync server URL looks like that: https://ffsync.example.com/token/1.0/sync/1.5
I've created a let's encrypt certificate and launching the URL gives me a proper {"status": "error", "errors": [{"location": "body", "name": "", "description": "Unauthorized"}]} response.


Here's the log
08-14 11:49:20.120 24459 24459 I FxAccounts: firefox :: FirefoxAccounts :: Requesting sync.
08-14 11:49:20.120 24459 24459 I FxAccounts: firefox :: FirefoxAccounts :: Sync options -- scheduling now: true
08-14 11:49:20.179 24459 24459 I FxAccounts: firefox :: FxAccountStatusFragment :: Got sync started message; refreshing.
08-14 11:49:20.180 24459 24459 I FxAccounts: firefox :: FxAccountStatusFragment :: AvatarURI is empty, skipping profile image fetch.
08-14 11:49:20.221 24459 28175 I FxAccounts: firefox :: FxAccountSyncAdapter :: Syncing FxAccount account named like XXXXXXXXXXX@XXXXX.XX for authority org.mozilla.firefox.db.browser with instance org.mozilla.gecko.fxa.sync.FxAccountSyncAdapter@e43393d.
08-14 11:49:20.225 24459 28175 I FxAccounts: firefox :: FxAccountSyncAdapter :: Account last synced at: 1502704023078
08-14 11:49:20.225 24459 28175 I FxAccounts: firefox :: FirefoxAccounts :: Sync options -- scheduling now: true
08-14 11:49:20.269 24459 28175 D GeckoLogger: Thread with tag and thread id acquiring lock: FxAccountSyncAdapter, 3846 ...
08-14 11:49:20.269 24459 28175 D GeckoLogger: Thread with tag and thread id acquiring lock: FxAccountSyncAdapter, 3846 ... ACQUIRED
08-14 11:49:20.274 24459 28175 I FxAccounts: firefox :: LoginStateMachineDelegate :: handleFinal: in Married
08-14 11:49:20.275 24459 28175 I FxAccounts: firefox :: AndroidFxAccount :: Moving account named like XXXXXXXXXXX@XXXXX.XX to state Married
08-14 11:49:20.311 24459 28175 I FxAccounts: firefox :: FxAccountNotificationManager :: State Married needs no action; cancelling any existing notification.
08-14 11:49:20.311 24459 28175 I FxAccounts: firefox :: LoginStateMachineDelegate :: handleMarried: in Married
08-14 11:49:21.616 24459 28175 I FxAccounts: firefox :: LoginStateMachineDelegate :: Fetching profile avatar information.
08-14 11:49:21.624 24459 24479 I GeckoLogger: firefox :: AndroidFxAccount :: Intent service launched to fetch profile.
08-14 11:49:21.634 24459 25929 I FxAccounts: firefox :: GlobalSession :: Running next stage checkPreconditions (org.mozilla.gecko.sync.stage.CheckPreconditionsStage@878c927)...
08-14 11:49:21.635 24459 25929 I FxAccounts: firefox :: GlobalSession :: Running next stage fetchInfoCollections (org.mozilla.gecko.sync.stage.FetchInfoCollectionsStage@3e1b7d4)...
08-14 11:49:21.729 24459 25929 I FxAccounts: firefox :: GlobalSession :: Running next stage fetchInfoConfiguration (org.mozilla.gecko.sync.stage.FetchInfoConfigurationStage@f160d7d)...
08-14 11:49:21.784 24459 25929 W FxAccounts: firefox :: SSResourceDelegate :: HTTP request failed.
08-14 11:49:21.792 24459 25929 W FxAccounts: firefox :: SSResourceDelegate :: HTTP response body: 0
08-14 11:49:21.794 24459 25929 I FxAccounts: firefox :: GlobalSession :: Running next stage fetchMetaGlobal (org.mozilla.gecko.sync.stage.FetchMetaGlobalStage@2e0472)...
08-14 11:49:21.794 24459 25929 I FxAccounts: firefox :: FetchMetaGlobalStage :: Trying to use persisted meta/global for this session.
08-14 11:49:21.801 24459 25929 I FxAccounts: firefox :: FetchMetaGlobalStage :: Using persisted meta/global for this session.
08-14 11:49:21.803 24459 25929 I FxAccounts: firefox :: GlobalSession :: Running next stage ensureKeysStage (org.mozilla.gecko.sync.stage.EnsureCrypto5KeysStage@b1ed0c3)...
08-14 11:49:21.808 24459 25929 I FxAccounts: firefox :: GlobalSession :: Running next stage syncClientsEngine (org.mozilla.gecko.sync.stage.SyncClientsEngineStage@98c7d40)...
08-14 11:49:21.876  1615  1768 I AutomaticBrightnessControllerEx: [MultiALC] lux = 114.0, time = 90009172
08-14 11:49:21.940 24459 25929 I FxAccounts: firefox :: SyncClientsEngineStage :: Local client GUID exists on server and was downloaded.
08-14 11:49:22.051 24459 25929 I FxAccounts: firefox :: GlobalSession :: Running next stage syncTabs (org.mozilla.gecko.sync.stage.FennecTabsServerSyncStage@b93b61f)...
08-14 11:49:22.115 24459 28180 W FxAccounts: firefox :: SSResourceDelegate :: HTTP request failed.
08-14 11:49:22.122 24459 28180 W FxAccounts: firefox :: SSResourceDelegate :: HTTP response body: Illegal method/protocol
08-14 11:49:22.122 24459 28180 W FxAccounts: firefox :: BatchingDownloaderDelegate :: Got a non-success response.
08-14 11:49:22.135 24459 28180 W FxAccounts: firefox :: BatchingDownloaderDelegate :: Got request error.
08-14 11:49:22.135 24459 28180 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.135 24459 28180 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.138 24459 28180 W FxAccounts: firefox :: RecordsChannel :: onFetchFailed. Calling for immediate stop.
08-14 11:49:22.138 24459 28180 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.138 24459 28180 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.140 24459 28180 W FxAccounts: firefox :: SynchronizerSession :: First RecordsChannel onFlowFetchFailed. Logging remote fetch error.
08-14 11:49:22.140 24459 28180 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.140 24459 28180 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.142 24459 28174 W FxAccounts: firefox :: ServLocSynchronizerSess :: Got 1 failures fetching remote records! Aborting session.
08-14 11:49:22.144 24459 28174 W FxAccounts: firefox :: ServerSyncStage :: Synchronize failed: Got 1 failures fetching remote records!
08-14 11:49:22.144 24459 28174 W FxAccounts: org.mozilla.gecko.sync.repositories.FetchFailedException
08-14 11:49:22.144 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ServerLocalSynchronizerSession.onFirstFlowCompleted(ServerLocalSynchronizerSession.java:47)
08-14 11:49:22.144 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.SynchronizerSession$1.onFlowCompleted(SynchronizerSession.java:163)
08-14 11:49:22.144 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.consumerIsDonePartial(RecordsChannel.java:270)
08-14 11:49:22.144 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ConcurrentRecordConsumer.consumerIsDone(ConcurrentRecordConsumer.java:71)
08-14 11:49:22.144 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ConcurrentRecordConsumer.run(ConcurrentRecordConsumer.java:113)
08-14 11:49:22.144 24459 28174 W FxAccounts: 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
08-14 11:49:22.144 24459 28174 W FxAccounts: 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
08-14 11:49:22.144 24459 28174 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.144 24459 28174 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.144 24459 28174 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.146 24459 28174 I FxAccounts: firefox :: ServerSyncStage :: Advancing session even though stage failed (took 0,09 seconds). Timestamps not persisted.
08-14 11:49:22.146 24459 28174 I FxAccounts: firefox :: GlobalSession :: Running next stage syncPasswords (org.mozilla.gecko.sync.stage.PasswordsServerSyncStage@ac6e22)...
08-14 11:49:22.209 24459 28182 W FxAccounts: firefox :: SSResourceDelegate :: HTTP request failed.
08-14 11:49:22.216 24459 28182 W FxAccounts: firefox :: SSResourceDelegate :: HTTP response body: Illegal method/protocol
08-14 11:49:22.217 24459 28182 W FxAccounts: firefox :: BatchingDownloaderDelegate :: Got a non-success response.
08-14 11:49:22.219 24459 28182 W FxAccounts: firefox :: BatchingDownloaderDelegate :: Got request error.
08-14 11:49:22.219 24459 28182 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.219 24459 28182 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.222 24459 28182 W FxAccounts: firefox :: RecordsChannel :: onFetchFailed. Calling for immediate stop.
08-14 11:49:22.222 24459 28182 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.222 24459 28182 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.225 24459 28182 W FxAccounts: firefox :: SynchronizerSession :: First RecordsChannel onFlowFetchFailed. Logging remote fetch error.
08-14 11:49:22.225 24459 28182 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.225 24459 28182 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.225 24459 28174 W FxAccounts: firefox :: ServLocSynchronizerSess :: Got 1 failures fetching remote records! Aborting session.
08-14 11:49:22.226 24459 28174 W FxAccounts: firefox :: ServerSyncStage :: Synchronize failed: Got 1 failures fetching remote records!
08-14 11:49:22.226 24459 28174 W FxAccounts: org.mozilla.gecko.sync.repositories.FetchFailedException
08-14 11:49:22.226 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ServerLocalSynchronizerSession.onFirstFlowCompleted(ServerLocalSynchronizerSession.java:47)
08-14 11:49:22.226 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.SynchronizerSession$1.onFlowCompleted(SynchronizerSession.java:163)
08-14 11:49:22.226 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.consumerIsDonePartial(RecordsChannel.java:270)
08-14 11:49:22.226 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ConcurrentRecordConsumer.consumerIsDone(ConcurrentRecordConsumer.java:71)
08-14 11:49:22.226 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ConcurrentRecordConsumer.run(ConcurrentRecordConsumer.java:113)
08-14 11:49:22.226 24459 28174 W FxAccounts: 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
08-14 11:49:22.226 24459 28174 W FxAccounts: 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
08-14 11:49:22.226 24459 28174 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.226 24459 28174 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.226 24459 28174 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.226 24459 28174 I FxAccounts: firefox :: ServerSyncStage :: Advancing session even though stage failed (took 0,08 seconds). Timestamps not persisted.
08-14 11:49:22.227 24459 28174 I FxAccounts: firefox :: GlobalSession :: Running next stage syncRecentHistory (org.mozilla.gecko.sync.stage.AndroidBrowserRecentHistoryServerSyncStage@f98121)...
08-14 11:49:22.227 24459 28174 I FxAccounts: firefox :: ServerSyncStage :: Skipping stage history.
08-14 11:49:22.228 24459 28174 I FxAccounts: firefox :: GlobalSession :: Running next stage syncBookmarks (org.mozilla.gecko.sync.stage.AndroidBrowserBookmarksServerSyncStage@630a3d2)...
08-14 11:49:22.294 24459 28185 W FxAccounts: firefox :: SSResourceDelegate :: HTTP request failed.
08-14 11:49:22.297 24459 28185 W FxAccounts: firefox :: SSResourceDelegate :: HTTP response body: Illegal method/protocol
08-14 11:49:22.297 24459 28185 W FxAccounts: firefox :: BatchingDownloaderDelegate :: Got a non-success response.
08-14 11:49:22.298 24459 28185 W FxAccounts: firefox :: BatchingDownloaderDelegate :: Got request error.
08-14 11:49:22.298 24459 28185 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.298 24459 28185 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.300 24459 28185 W FxAccounts: firefox :: RecordsChannel :: onFetchFailed. Calling for immediate stop.
08-14 11:49:22.300 24459 28185 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.300 24459 28185 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.301 24459 28185 W FxAccounts: firefox :: SynchronizerSession :: First RecordsChannel onFlowFetchFailed. Logging remote fetch error.
08-14 11:49:22.301 24459 28185 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.301 24459 28185 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.303 24459 28174 W FxAccounts: firefox :: ServLocSynchronizerSess :: Got 1 failures fetching remote records! Aborting session.
08-14 11:49:22.306 24459 28174 W FxAccounts: firefox :: ServerSyncStage :: Synchronize failed: Got 1 failures fetching remote records!
08-14 11:49:22.306 24459 28174 W FxAccounts: org.mozilla.gecko.sync.repositories.FetchFailedException
08-14 11:49:22.306 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ServerLocalSynchronizerSession.onFirstFlowCompleted(ServerLocalSynchronizerSession.java:47)
08-14 11:49:22.306 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.SynchronizerSession$1.onFlowCompleted(SynchronizerSession.java:163)
08-14 11:49:22.306 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.consumerIsDonePartial(RecordsChannel.java:270)
08-14 11:49:22.306 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ConcurrentRecordConsumer.consumerIsDone(ConcurrentRecordConsumer.java:71)
08-14 11:49:22.306 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ConcurrentRecordConsumer.run(ConcurrentRecordConsumer.java:113)
08-14 11:49:22.306 24459 28174 W FxAccounts: 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
08-14 11:49:22.306 24459 28174 W FxAccounts: 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
08-14 11:49:22.306 24459 28174 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.306 24459 28174 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.306 24459 28174 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.309 24459 28174 I FxAccounts: firefox :: ServerSyncStage :: Advancing session even though stage failed (took 0,08 seconds). Timestamps not persisted.
08-14 11:49:22.310 24459 28174 I FxAccounts: firefox :: GlobalSession :: Running next stage syncFullHistory (org.mozilla.gecko.sync.stage.AndroidBrowserHistoryServerSyncStage@a897ff6)...
08-14 11:49:22.347 24459 24479 I GeckoLogger: firefox :: AndroidFxAccount :: Profile JSON fetch succeeeded!
08-14 11:49:22.348 24459 24459 I FxAccounts: firefox :: FxAccountStatusFragment :: Profile avatar cache update action broadcast received.
08-14 11:49:22.350 24459 24459 I FxAccounts: firefox :: FxAccountStatusFragment :: AvatarURI is empty, skipping profile image fetch.
08-14 11:49:22.397 24459 28188 W FxAccounts: firefox :: SSResourceDelegate :: HTTP request failed.
08-14 11:49:22.405 24459 28188 W FxAccounts: firefox :: SSResourceDelegate :: HTTP response body: Illegal method/protocol
08-14 11:49:22.405 24459 28188 W FxAccounts: firefox :: BatchingDownloaderDelegate :: Got a non-success response.
08-14 11:49:22.408 24459 28188 W FxAccounts: firefox :: BatchingDownloaderDelegate :: Got request error.
08-14 11:49:22.408 24459 28188 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.408 24459 28188 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.413 24459 28188 W FxAccounts: firefox :: RecordsChannel :: onFetchFailed. Calling for immediate stop.
08-14 11:49:22.413 24459 28188 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.413 24459 28188 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.415 24459 28188 W FxAccounts: firefox :: SynchronizerSession :: First RecordsChannel onFlowFetchFailed. Logging remote fetch error.
08-14 11:49:22.415 24459 28188 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.415 24459 28188 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.420 24459 28174 W FxAccounts: firefox :: ServLocSynchronizerSess :: Got 1 failures fetching remote records! Aborting session.
08-14 11:49:22.423 24459 28174 W FxAccounts: firefox :: ServerSyncStage :: Synchronize failed: Got 1 failures fetching remote records!
08-14 11:49:22.423 24459 28174 W FxAccounts: org.mozilla.gecko.sync.repositories.FetchFailedException
08-14 11:49:22.423 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ServerLocalSynchronizerSession.onFirstFlowCompleted(ServerLocalSynchronizerSession.java:47)
08-14 11:49:22.423 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.SynchronizerSession$1.onFlowCompleted(SynchronizerSession.java:163)
08-14 11:49:22.423 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.consumerIsDonePartial(RecordsChannel.java:270)
08-14 11:49:22.423 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ConcurrentRecordConsumer.consumerIsDone(ConcurrentRecordConsumer.java:71)
08-14 11:49:22.423 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ConcurrentRecordConsumer.run(ConcurrentRecordConsumer.java:113)
08-14 11:49:22.423 24459 28174 W FxAccounts: 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
08-14 11:49:22.423 24459 28174 W FxAccounts: 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
08-14 11:49:22.423 24459 28174 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.423 24459 28174 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.423 24459 28174 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.426 24459 28174 I FxAccounts: firefox :: ServerSyncStage :: Advancing session even though stage failed (took 0,11 seconds). Timestamps not persisted.
08-14 11:49:22.426 24459 28174 I FxAccounts: firefox :: GlobalSession :: Running next stage syncFormHistory (org.mozilla.gecko.sync.stage.FormHistoryServerSyncStage@3fe62da)...
08-14 11:49:22.437  1615  2203 V WifiServerServiceExt: checkPollTimer Cnt= 0 rssi =-60 threshold=-100
08-14 11:49:22.503 24459 28191 W FxAccounts: firefox :: SSResourceDelegate :: HTTP request failed.
08-14 11:49:22.506 24459 28191 W FxAccounts: firefox :: SSResourceDelegate :: HTTP response body: Illegal method/protocol
08-14 11:49:22.507 24459 28191 W FxAccounts: firefox :: BatchingDownloaderDelegate :: Got a non-success response.
08-14 11:49:22.508 24459 28191 W FxAccounts: firefox :: BatchingDownloaderDelegate :: Got request error.
08-14 11:49:22.508 24459 28191 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.508 24459 28191 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.509 24459 28191 W FxAccounts: firefox :: RecordsChannel :: onFetchFailed. Calling for immediate stop.
08-14 11:49:22.509 24459 28191 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.509 24459 28191 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.510 24459 28191 W FxAccounts: firefox :: SynchronizerSession :: First RecordsChannel onFlowFetchFailed. Logging remote fetch error.
08-14 11:49:22.510 24459 28191 W FxAccounts: <HTTPFailureException 400 :: (Illegal method/protocol)>
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderDelegate.handleRequestFailure(BatchingDownloaderDelegate.java:85)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest$SyncStorageResourceDelegate.handleHttpResponse(SyncStorageRequest.java:134)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageCollectionRequest$SyncCollectionResourceDelegate.handleHttpResponse(SyncStorageCollectionRequest.java:83)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.execute(BaseResource.java:342)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.go(BaseResource.java:373)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.BaseResource.get(BaseResource.java:379)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.net.SyncStorageRequest.get(SyncStorageRequest.java:178)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchWithParameters(BatchingDownloader.java:124)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloader.fetchSince(BatchingDownloader.java:145)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.downloaders.BatchingDownloaderController.resumeFetchSinceIfPossible(BatchingDownloaderController.java:69)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.Server15RepositorySession.fetchSince(Server15RepositorySession.java:60)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession.fetchSince(Crypto5MiddlewareRepositorySession.java:140)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.flow(RecordsChannel.java:180)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onBeginSucceeded(RecordsChannel.java:335)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionBeginDelegate$1.run(DeferredRepositorySessionBeginDelegate.java:24)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.510 24459 28191 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.511 24459 28174 W FxAccounts: firefox :: ServLocSynchronizerSess :: Got 1 failures fetching remote records! Aborting session.
08-14 11:49:22.514 24459 28174 W FxAccounts: firefox :: ServerSyncStage :: Synchronize failed: Got 1 failures fetching remote records!
08-14 11:49:22.514 24459 28174 W FxAccounts: org.mozilla.gecko.sync.repositories.FetchFailedException
08-14 11:49:22.514 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ServerLocalSynchronizerSession.onFirstFlowCompleted(ServerLocalSynchronizerSession.java:47)
08-14 11:49:22.514 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.SynchronizerSession$1.onFlowCompleted(SynchronizerSession.java:163)
08-14 11:49:22.514 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.consumerIsDonePartial(RecordsChannel.java:270)
08-14 11:49:22.514 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ConcurrentRecordConsumer.consumerIsDone(ConcurrentRecordConsumer.java:71)
08-14 11:49:22.514 24459 28174 W FxAccounts: 	at org.mozilla.gecko.sync.synchronizer.ConcurrentRecordConsumer.run(ConcurrentRecordConsumer.java:113)
08-14 11:49:22.514 24459 28174 W FxAccounts: 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:428)
08-14 11:49:22.514 24459 28174 W FxAccounts: 	at java.util.concurrent.FutureTask.run(FutureTask.java:237)
08-14 11:49:22.514 24459 28174 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
08-14 11:49:22.514 24459 28174 W FxAccounts: 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
08-14 11:49:22.514 24459 28174 W FxAccounts: 	at java.lang.Thread.run(Thread.java:761)
08-14 11:49:22.517 24459 28174 I FxAccounts: firefox :: ServerSyncStage :: Advancing session even though stage failed (took 0,09 seconds). Timestamps not persisted.
08-14 11:49:22.517 24459 28174 I FxAccounts: firefox :: GlobalSession :: Running next stage uploadMetaGlobal (org.mozilla.gecko.sync.stage.UploadMetaGlobalStage@2865239)...
08-14 11:49:22.518 24459 28174 I FxAccounts: firefox :: GlobalSession :: Not uploading updated meta/global record since there are no engines requesting upload.
08-14 11:49:22.519 24459 28174 I FxAccounts: firefox :: GlobalSession :: Running next stage completed (org.mozilla.gecko.sync.stage.CompletedStage@154907e)...
08-14 11:49:22.519 24459 28174 I FxAccounts: firefox :: FxAccountSyncAdapter :: Global session succeeded.
08-14 11:49:22.548 24459 28174 I FxAccounts: firefox :: FxAccountSchedulePolicy :: Scheduling periodic sync for 43200.
08-14 11:49:22.550 24459 28174 I FxAccounts: firefox :: FxAccountSyncAdapter :: Sync succeeded.
08-14 11:49:22.551 24459 28175 D GeckoLogger: Thread with tag and thread id releasing lock: FxAccountSyncAdapter, 3846 ...
08-14 11:49:22.552 24459 28175 D GeckoLogger: Thread with tag and thread id releasing lock: FxAccountSyncAdapter, 3846 ... NOT LOCKED
08-14 11:49:22.552 24459 28175 I FxAccounts: firefox :: FxAccountSyncAdapter :: Syncing done.
08-14 11:49:22.568 24459 24459 I FxAccounts: firefox :: FxAccountStatusFragment :: Got sync finished message; refreshing.
08-14 11:49:22.570 24459 24459 I FxAccounts: firefox :: FxAccountStatusFragment :: AvatarURI is empty, skipping profile image fetch.
Just saw now that it installed version 54.0.1 from Play store...
Before it was 55...
crybaby667: thanks so much for posting these logs.  There's at least one clear issue: the token server is handing back what the client expects:

"Expected key not present in result: hashed_fxa_uid"

Now, this might be:

- a version incompatibility: perhaps you're not running a new enough token server
- a configuration error: perhaps your token server needs to know more about FxA
- a client error: this might be optional and we shouldn't expect it

or something else.

eoger: you know the most about FxA and UIDs on Android, I think.  Can you dig into the client questions?

rfkelly: can you redirect to whoever is working on the token server.  Is this field optional, and the client is being to strict?  Is this field required?  Is there additional configuration needed to provide it?

crybaby667: thanks again -- hopefully we can fix this without client changes so you can get this working quickly.
Flags: needinfo?(rfkelly)
Flags: needinfo?(eoger)
This is a regression from Bug 1308337: https://hg.mozilla.org/mozilla-central/rev/38894ad99464

We've started relying on hashed_fxa_uid being present in the token server's response. From the relevant commit message:

"This is what we (and other platforms) use as part of telemetry payloads in place of either our local FxA Device ID or the sync client ID. Note that this server API is currently undocumented. Parameter introduced in https://github.com/mozilla-services/tokenserver/commit/2021994ca4682acde83242ee0b96140a05c7c4f5"
Flags: needinfo?(eoger)
If I'm reading https://github.com/mozilla-services/tokenserver/blob/a74a721280fe9bad30d9495a9be614ce61e912a3/tokenserver/views.py#L121 correctly, the hashed_fxa_uid value returned by the token server is derived from the email address, and so there do not seem to be any additional dependencies.

My guess is that upgrading token server to 1.2.23 (released in July 2016) or newer should get the client unstuck.
> My guess is that upgrading token server to 1.2.23 or newer should get the client unstuck.

I agree with this assessment, updating to the latest server code should fix the issue here.  If you're using the combined `syncserver` package, just `git pull` and rebuild should do the trick.
Flags: needinfo?(rfkelly)
So in your opinion I should update my Fx Sync content server, right?
But why is it still working for Fx pn Desktop, but not on Android?

As I'm using a compiled package for my Synology NAS I'm not able to update it that easily.
But I'm planning to move my Sync server to a RasPi now...
Is it a big thing to install also the authentication server there?
(In reply to crybaby667 from comment #10)
> So in your opinion I should update my Fx Sync content server, right?
> But why is it still working for Fx pn Desktop, but not on Android?

I think the Android client is simply stricter than the desktop client.  We refuse to accept a token without an expected value; Desktop appears to accept a token without an expected value (see http://searchfox.org/mozilla-central/source/services/common/tokenserverclient.js#420).  There's handling for missing hashed UIDs, but it looks like Desktop will throw eventually if it's missing.

> As I'm using a compiled package for my Synology NAS I'm not able to update
> it that easily.
> But I'm planning to move my Sync server to a RasPi now...
> Is it a big thing to install also the authentication server there?

That's unfortunate.  My expectation is that upgrading your NAS package or moving to a different hosting solution will be much faster than updating the client and getting the updates to the release channel, which takes something like 12-18 weeks.

However, I wonder if Android should _require_ the hashed FxA UID at all?  It looks like it's used only for Telemetry, and we probably shouldn't be collecting much (if any!) Sync telemetry for self-hosted endpoints.  grisha, can you comment?
Flags: needinfo?(gkruglov)
(In reply to Nick Alexander :nalexander [parental leave until September 15th] from comment #11)
> I think the Android client is simply stricter than the desktop client.  We
> refuse to accept a token without an expected value; Desktop appears to
> accept a token without an expected value (see
> http://searchfox.org/mozilla-central/source/services/common/
> tokenserverclient.js#420).  There's handling for missing hashed UIDs, but it
> looks like Desktop will throw eventually if it's missing.

FTR, I think desktop should be fine until we go to submit telemetry - but we explicitly do *not* submit telemetry for self-hosted users - so this should be fine from desktop's POV.

> However, I wonder if Android should _require_ the hashed FxA UID at all?  It
> looks like it's used only for Telemetry, and we probably shouldn't be
> collecting much (if any!) Sync telemetry for self-hosted endpoints.  grisha,
> can you comment?

I agree with this, although it's unclear how much that would help the reporter given the time it would take for such a fix to hit release.
Thanks for your help!

I've now installed the latest version of Fx sync on a RasPi and it both works under Windows and Android...
I also tried to install the authentication server, but after some hours I gave up.

I've a suggestion for you:
Provide a Docker container/RasPi image for Fx sync/auth server which allows users to easily host their own servers.
I guess that many users would be interested and in terms of privacy it would be a unique selling point for Firefox...
On one hand, not collecting sync telemetry for self-hosted users is good:
- our client/server dependencies might change, and it's nice to avoid running into bugs such as this one entirely
- data collected might be skewed somewhat, or affected by an unusual local setup which won't occur in production
- privacy considerations? I'm unclear if that's a problem

On another hand, collecting sync telemetry from self-hosted users _and_ tagging it as such so that we can look at it separately could be useful to discover irregularities that occur for those users in particular. We officially support self-hosting sync infra, and so it does seem useful to study how those clients are doing in the wild. In theory, that will help us support such use cases better.

Mark, do you reckon looking at self-hosted sync telemetry separately is useful enough to justify sync schema changes? Are there privacy concerns here that need to be called out first?
Flags: needinfo?(gkruglov) → needinfo?(markh)
(In reply to :Grisha Kruglov from comment #14)
> Mark, do you reckon looking at self-hosted sync telemetry separately is
> useful enough to justify sync schema changes? Are there privacy concerns
> here that need to be called out first?

In general I have no problem with this, although the reason we didn't collect telemetry for self-hosted users was all about privacy. I think the number of self-hosted users is very small, so TBH I'm not sure it's worthwhile and might even mislead us (eg, I'm not sure what an increased failure rate for self-hosted users actually tells us, nor what we could do about it)
Flags: needinfo?(markh)
OK, I'm going to re-purpose this bug disable collection of sync telemetry for self-hosted users.
Blocks: 1308337
Status: UNCONFIRMED → NEW
Ever confirmed: true
Priority: -- → P2
Summary: Sync with Fx Sync server 1.5 does not work → Do not collect sync telemetry for self-hosted clients
Priority: P2 → P3
Product: Android Background Services → Firefox for Android
We have completed our launch of our new Firefox on Android. The development of the new versions use GitHub for issue tracking. If the bug report still reproduces in a current version of [Firefox on Android nightly](https://play.google.com/store/apps/details?id=org.mozilla.fenix) an issue can be reported at the [Fenix GitHub project](https://github.com/mozilla-mobile/fenix/). If you want to discuss your report please use [Mozilla's chat](https://wiki.mozilla.org/Matrix#Connect_to_Matrix) server https://chat.mozilla.org and join the [#fenix](https://chat.mozilla.org/#/room/#fenix:mozilla.org) channel.
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.