1143473 - Sync to custom server fails on Linux

Status: UNCONFIRMED

(Firefox :: Sync, defect, P4)

Description

[Johannes Wienke]

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:36.0) Gecko/20100101 Firefox/36.0
Build ID: 20150305221847

Steps to reproduce:

I have set up a custom sync server and most devices sync perfectly. Only the firefox version on my Desktop computer running archlinux (36.0.1) refuses to sync with that server. These are the logs I get when enabling logging for the sync process and manually triggering sync after browser startup:

languitar@bird ~/src/chrome-sync-server (master)> firefox 

(process:17010): GLib-CRITICAL **: g_slice_set_config: assertion 'sys_page_size == 0' failed
1426441434657	Sync.Service	INFO	Loading Weave 1.38.0
1426441434659	Sync.Engine.Clients	DEBUG	Engine initialized
1426441434660	Sync.Engine.Clients	DEBUG	Resetting clients last sync time
1426441434664	Sync.Engine.Bookmarks	DEBUG	Engine initialized
1426441434668	Sync.Engine.Forms	DEBUG	Engine initialized
1426441434671	Sync.Engine.History	DEBUG	Engine initialized
1426441434675	Sync.Engine.Passwords	DEBUG	Engine initialized
1426441434677	Sync.Engine.Prefs	DEBUG	Engine initialized
1426441434680	Sync.Engine.Tabs	DEBUG	Engine initialized
1426441434681	Sync.Engine.Tabs	DEBUG	Resetting tabs last sync time
1426441434685	Sync.Engine.Addons	DEBUG	Engine initialized
1426441434687	Sync.Service	INFO	Mozilla/5.0 (X11; Linux x86_64; rv:36.0) Gecko/20100101 Firefox/36.0
WeaveCrypto: Trying NSS library without path
WeaveCrypto: Initializing NSS types and function declarations...
WeaveCrypto: generateRandomBytes() called
1426441434690	Sync.SyncScheduler	TRACE	Setting SyncScheduler policy values to defaults.
1426441434690	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1426441434691	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1426441434691	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1426441434691	Sync.AddonsReconciler	INFO	Registering as Add-on Manager listener.
1426441434692	Sync.AddonsReconciler	DEBUG	Adding change listener.
1426441434692	Sync.Tracker.History	INFO	Adding Places observer.
1426441434723	Sync.SyncScheduler	TRACE	Handling weave:service:ready
1426441434726	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1426441434727	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1426441434747	Sync.Tracker.Clients	WARN	Changed IDs file clients contains non-object value.
1426441434763	Sync.Tracker.Bookmarks	WARN	Changed IDs file bookmarks contains non-object value.
1426441434770	Sync.Tracker.Passwords	WARN	Changed IDs file passwords contains non-object value.
1426441434773	Sync.Tracker.Addons	WARN	Changed IDs file addons contains non-object value.
1426441436084	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441436184	Sync.SyncScheduler	TRACE	clients: score: 0
1426441436185	Sync.SyncScheduler	TRACE	prefs: score: 0
1426441436185	Sync.SyncScheduler	TRACE	tabs: score: 0
1426441436185	Sync.SyncScheduler	TRACE	addons: score: 0
1426441436185	Sync.SyncScheduler	TRACE	forms: score: 0
1426441436185	Sync.SyncScheduler	TRACE	history: score: 1
1426441436185	Sync.SyncScheduler	TRACE	Global score updated: 1
1426441436186	Sync.SyncScheduler	TRACE	_checkSync returned "".
1426441436186	Sync.SyncScheduler	DEBUG	Next sync in 3600000 ms.
1426441436787	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441436889	Sync.SyncScheduler	TRACE	clients: score: 0
1426441436889	Sync.SyncScheduler	TRACE	prefs: score: 0
1426441436890	Sync.SyncScheduler	TRACE	tabs: score: 1
1426441436890	Sync.SyncScheduler	TRACE	addons: score: 0
1426441436890	Sync.SyncScheduler	TRACE	forms: score: 0
1426441436890	Sync.SyncScheduler	TRACE	history: score: 0
1426441436891	Sync.SyncScheduler	TRACE	Global score updated: 2
1426441436891	Sync.SyncScheduler	TRACE	_checkSync returned "".
1426441436891	Sync.SyncScheduler	TRACE	There's already a sync scheduled in 3599109 ms.
1426441436891	Sync.SyncScheduler	TRACE	Ignoring scheduling request for next sync in 3600000 ms.
1426441437084	Sync.Tracker.History	DEBUG	Saving changed IDs to history
1426441443728	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1426441443728	Sync.SyncScheduler	TRACE	There's already a sync scheduled in 3592272 ms.
1426441443729	Sync.SyncScheduler	DEBUG	Next sync in 3592272 ms.
1426441497884	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441497892	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441497993	Sync.SyncScheduler	TRACE	clients: score: 0
1426441497994	Sync.SyncScheduler	TRACE	prefs: score: 0
1426441497994	Sync.SyncScheduler	TRACE	tabs: score: 2
1426441497995	Sync.SyncScheduler	TRACE	addons: score: 0
1426441497995	Sync.SyncScheduler	TRACE	forms: score: 0
1426441497995	Sync.SyncScheduler	TRACE	history: score: 0
1426441497995	Sync.SyncScheduler	TRACE	Global score updated: 4
1426441497996	Sync.SyncScheduler	TRACE	_checkSync returned "".
1426441497996	Sync.SyncScheduler	TRACE	There's already a sync scheduled in 3538004 ms.
1426441497996	Sync.SyncScheduler	TRACE	Ignoring scheduling request for next sync in 3600000 ms.
1426441555289	Sync.RESTResponse	DEBUG	Caught exception fetching HTTP status code:[Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannel.responseStatus]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://services-common/rest.js :: RESTResponse.prototype.status :: line 637"  data: no] Stack trace: RESTResponse.prototype.status()@resource://services-common/rest.js:637 < _onComplete()@resource://services-common/hawkclient.js:194 < onComplete()@resource://services-common/hawkclient.js:251 < onStopRequest()@resource://services-common/rest.js:461 < <file:unknown>
1426441555292	Sync.RESTResponse	DEBUG	Caught exception fetching HTTP status text:[Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannel.responseStatusText]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://services-common/rest.js :: RESTResponse.prototype.statusText :: line 653"  data: no] Stack trace: RESTResponse.prototype.statusText()@resource://services-common/rest.js:653 < _onComplete()@resource://services-common/hawkclient.js:197 < onComplete()@resource://services-common/hawkclient.js:251 < onStopRequest()@resource://services-common/rest.js:461 < <file:unknown>
1426441555293	Sync.RESTResponse	TRACE	Processing response headers.
1426441555293	Sync.RESTResponse	DEBUG	Caught exception processing response headers:[Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannel.visitResponseHeaders]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://services-common/rest.js :: RESTResponse.prototype.headers :: line 687"  data: no] Stack trace: RESTResponse.prototype.headers()@resource://services-common/rest.js:687 < this.HawkClient.prototype._maybeNotifyBackoff()@resource://services-common/hawkclient.js:285 < _onComplete()@resource://services-common/hawkclient.js:204 < onComplete()@resource://services-common/hawkclient.js:251 < onStopRequest()@resource://services-common/rest.js:461 < <file:unknown>
1426441555294	Sync.RESTResponse	TRACE	Processing response headers.
1426441555294	Sync.RESTResponse	DEBUG	Caught exception processing response headers:[Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannel.visitResponseHeaders]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://services-common/rest.js :: RESTResponse.prototype.headers :: line 687"  data: no] Stack trace: RESTResponse.prototype.headers()@resource://services-common/rest.js:687 < this.HawkClient.prototype._maybeNotifyBackoff()@resource://services-common/hawkclient.js:285 < _onComplete()@resource://services-common/hawkclient.js:205 < onComplete()@resource://services-common/hawkclient.js:251 < onStopRequest()@resource://services-common/rest.js:461 < <file:unknown>
1426441555294	Sync.RESTResponse	DEBUG	Caught exception fetching HTTP status text:[Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannel.responseStatusText]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://services-common/rest.js :: RESTResponse.prototype.statusText :: line 653"  data: no] Stack trace: RESTResponse.prototype.statusText()@resource://services-common/rest.js:653 < this.HawkClient.prototype._constructError()@resource://services-common/hawkclient.js:108 < _onComplete()@resource://services-common/hawkclient.js:210 < onComplete()@resource://services-common/hawkclient.js:251 < onStopRequest()@resource://services-common/rest.js:461 < <file:unknown>
1426441555295	Sync.RESTResponse	DEBUG	Caught exception fetching HTTP status code:[Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannel.responseStatus]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://services-common/rest.js :: RESTResponse.prototype.status :: line 637"  data: no] Stack trace: RESTResponse.prototype.status()@resource://services-common/rest.js:637 < this.HawkClient.prototype._constructError()@resource://services-common/hawkclient.js:109 < _onComplete()@resource://services-common/hawkclient.js:210 < onComplete()@resource://services-common/hawkclient.js:251 < onStopRequest()@resource://services-common/rest.js:461 < <file:unknown>
1426441555295	Sync.RESTResponse	DEBUG	Caught exception fetching HTTP status code:[Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannel.responseStatus]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://services-common/rest.js :: RESTResponse.prototype.status :: line 637"  data: no] Stack trace: RESTResponse.prototype.status()@resource://services-common/rest.js:637 < this.HawkClient.prototype._constructError()@resource://services-common/hawkclient.js:110 < _onComplete()@resource://services-common/hawkclient.js:210 < onComplete()@resource://services-common/hawkclient.js:251 < onStopRequest()@resource://services-common/rest.js:461 < <file:unknown>
1426441555295	Sync.RESTResponse	TRACE	Processing response headers.
1426441555295	Sync.RESTResponse	DEBUG	Caught exception processing response headers:[Exception... "Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIHttpChannel.visitResponseHeaders]"  nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)"  location: "JS frame :: resource://services-common/rest.js :: RESTResponse.prototype.headers :: line 687"  data: no] Stack trace: RESTResponse.prototype.headers()@resource://services-common/rest.js:687 < this.HawkClient.prototype._constructError()@resource://services-common/hawkclient.js:113 < _onComplete()@resource://services-common/hawkclient.js:210 < onComplete()@resource://services-common/hawkclient.js:251 < onStopRequest()@resource://services-common/rest.js:461 < <file:unknown>
1426441555296	FirefoxAccounts	ERROR	error POSTing /certificate/sign: {"error":{},"message":null,"code":null,"errno":null}
1426441555296	FirefoxAccounts	ERROR	HAWK.signCertificate error: {"error":{},"message":null,"code":null,"errno":null}
1426441555296	Sync.BrowserIDManager	ERROR	Non-authentication error in _fetchTokenForUser: null: null
1426441555297	Sync.Status	DEBUG	Status.login: success.login => error.login.reason.network
1426441555297	Sync.Status	DEBUG	Status.service: success.status_ok => error.login.failed
1426441555297	Sync.SyncScheduler	TRACE	Handling weave:service:login:error
1426441555297	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1426441555297	Sync.SyncScheduler	TRACE	_checkSync returned "".
1426441555297	Sync.SyncScheduler	DEBUG	Next sync in 3600000 ms.
1426441555298	Sync.ErrorHandler	TRACE	Handling weave:service:login:error
1426441555298	Sync.ErrorHandler	DEBUG	Flushing file log.
1426441555299	Sync.ErrorHandler	TRACE	Beginning stream copy to error-1426441555298.txt: 1426441555299
1426441555299	Sync.ErrorHandler	TRACE	shouldReportError: false (no cluster URL; possible node reassignment).
1426441555300	Sync.BrowserIDManager	ERROR	Background fetch for key bundle failed: null: null
1426441555300	Sync.BrowserIDManager	ERROR	Could not authenticate: null: null
1426441555301	Sync.ErrorHandler	TRACE	Notifying weave:ui:clear-error. Status.login is error.login.reason.network. Status.sync is success.sync
1426441555301	Sync.BrowserIDManager	INFO	currentAuthState returning error.login.reason.network due to previous failure
1426441555301	Sync.Status	DEBUG	Status.login: error.login.reason.network => error.login.reason.network
1426441555301	Sync.Status	DEBUG	Status.service: error.login.failed => error.login.failed
1426441555304	Sync.ErrorHandler	TRACE	onCopyComplete: 1426441555304
1426441555304	Sync.ErrorHandler	TRACE	Output file timestamp: 1426441555000
1426441555304	Sync.ErrorHandler	TRACE	Notified: 1426441555304
1426441555304	Sync.ErrorHandler	TRACE	Scheduling cleanup.
1426441555304	Sync.ErrorHandler	DEBUG	Log cleanup threshold time: 1425577555304
1426441555305	Sync.ErrorHandler	DEBUG	No logs to clean up.
1426441707054	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441707061	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441751080	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441752080	Sync.Tracker.Forms	DEBUG	Saving changed IDs to forms
1426441753146	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441772569	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441773568	Sync.Tracker.Forms	DEBUG	Saving changed IDs to forms
1426441840457	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441841457	Sync.Tracker.History	DEBUG	Saving changed IDs to history
1426441844872	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441844971	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441845873	Sync.Tracker.History	DEBUG	Saving changed IDs to history
1426441921369	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441921456	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated
1426441922369	Sync.Tracker.History	DEBUG	Saving changed IDs to history
1426441973768	Sync.SyncScheduler	TRACE	Handling weave:engine:score:updated


Actual results:

Nothing syncs


Expected results:

Bookmarks etc are synced.