Closed Bug 1220469 Opened 7 years ago Closed 6 years ago

Sync keeps failing

Categories

(Firefox :: Sync, defect)

Product:
Firefox
Component:
Sync
Version:
41 Branch
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED DUPLICATE of bug 1294599

People

(Reporter: chris, Unassigned)

Details

User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:41.0) Gecko/20100101 Firefox/41.0
Build ID: 20151014143721

Steps to reproduce:

retried


Actual results:

1446391271280	Sync.Service	INFO	Loading Weave 1.43.0
1446391271282	Sync.Engine.Clients	DEBUG	Engine initialized
1446391271282	Sync.Engine.Clients	DEBUG	Resetting clients last sync time
1446391271287	Sync.Engine.Bookmarks	DEBUG	Engine initialized
1446391271291	Sync.Engine.Forms	DEBUG	Engine initialized
1446391271293	Sync.Engine.History	DEBUG	Engine initialized
1446391271295	Sync.Engine.Passwords	DEBUG	Engine initialized
1446391271297	Sync.Engine.Prefs	DEBUG	Engine initialized
1446391271299	Sync.Engine.Tabs	DEBUG	Engine initialized
1446391271300	Sync.Engine.Tabs	DEBUG	Resetting tabs last sync time
1446391271303	Sync.Engine.Addons	DEBUG	Engine initialized
1446391271304	Sync.Service	INFO	Mozilla/5.0 (Macintosh; Intel Mac OS X 10.11; rv:41.0) Gecko/20100101 Firefox/41.0
1446391271306	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1446391271307	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1446391271307	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1446391271307	Sync.AddonsReconciler	INFO	Registering as Add-on Manager listener.
1446391271308	Sync.AddonsReconciler	DEBUG	Adding change listener.
1446391271308	Sync.Tracker.History	INFO	Adding Places observer.
1446391271309	Sync.ErrorHandler	DEBUG	Beginning user-triggered sync.
1446391271331	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1446391271331	Sync.Service	DEBUG	User-Agent: Firefox/41.0.2 FxSync/1.43.0.20151014143721.
1446391271331	Sync.Service	INFO	Starting sync at 2015-11-01 07:21:11
1446391271331	Sync.Service	DEBUG	In sync: should login.
1446391271332	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1446391271332	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1446391271333	Sync.Tracker.Clients	WARN	Changed IDs file clients contains non-object value.
1446391271334	FirefoxAccounts	DEBUG	got keyPair
1446391271334	FirefoxAccounts	DEBUG	getCertificateSigned: true true
1446391271342	Sync.Tracker.Bookmarks	WARN	Changed IDs file bookmarks contains non-object value.
1446391271345	Sync.Tracker.Forms	WARN	Changed IDs file forms contains non-object value.
1446391271346	Sync.Tracker.History	WARN	Changed IDs file history contains non-object value.
1446391271347	Sync.Tracker.Passwords	WARN	Changed IDs file passwords contains non-object value.
1446391271349	Sync.Tracker.Addons	WARN	Changed IDs file addons contains non-object value.
1446391271357	FirefoxAccounts	DEBUG	FxAccountsProfileClient: Requested profile
1446391271357	FirefoxAccounts	DEBUG	getOAuthToken enter
1446391271365	FirefoxAccounts	TRACE	getCachedToken returning cached token
1446391271365	FirefoxAccounts	DEBUG	getOAuthToken returning a cached token
1446391271505	Hawk	DEBUG	(Response) /certificate/sign: code: 200 - Status text: OK
1446391271505	Sync.RESTResponse	TRACE	Processing response headers.
1446391271505	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -505
1446391271506	FirefoxAccounts	DEBUG	getCertificate got a new one: true
1446391271506	FirefoxAccounts	DEBUG	getAssertionFromCert
1446391271507	FirefoxAccounts	DEBUG	getAssertionFromCert returning signed: true
1446391271507	Sync.BrowserIDManager	DEBUG	Getting a token
1446391271508	Common.TokenServerClient	DEBUG	Beginning BID assertion exchange: https://token.services.mozilla.com/1.0/sync/1.5
1446391271592	FirefoxAccounts	DEBUG	fetched profile matches cached copy
1446391271692	Common.TokenServerClient	DEBUG	Got token response: 200
1446391271692	Sync.RESTResponse	TRACE	Processing response headers.
1446391271693	Common.TokenServerClient	DEBUG	Successful token response
1446391271693	Sync.BrowserIDManager	DEBUG	Successfully got a sync token
1446391271694	Sync.BulkKeyBundle	INFO	BulkKeyBundle being created for undefined
1446391271694	Sync.BrowserIDManager	INFO	Background fetch for key bundle done
1446391271694	Sync.Status	DEBUG	Status.login: success.login => success.login
1446391271694	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1446391271694	Sync.Service	INFO	Logging in the user.
1446391271695	Sync.BrowserIDManager	DEBUG	unlockAndVerifyAuthState already has (or can fetch) sync keys
1446391271695	Sync.Service	DEBUG	Fetching unlocked auth state returned success.status_ok
1446391271695	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391271696	Sync.BrowserIDManager	DEBUG	_findCluster returning https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/
1446391271696	Sync.Service	DEBUG	Cluster value = https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/
1446391271696	Sync.Service	DEBUG	Setting cluster to https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/
1446391271696	Sync.Service	DEBUG	Caching URLs under storage user base: https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/
1446391271697	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391271949	Sync.Resource	DEBUG	mesg: GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/info/collections
1446391271949	Sync.Resource	DEBUG	GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/info/collections
1446391271949	Sync.Service	DEBUG	Fetching global metadata record
1446391271949	Sync.RecordManager	TRACE	Importing record: https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/meta/global
1446391271950	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391271999	Sync.Resource	DEBUG	mesg: GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/meta/global
1446391271999	Sync.Resource	DEBUG	GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/meta/global
1446391272000	Sync.Service	DEBUG	Clearing cached meta record. metaModified is undefined, setting to 1439518874.53
1446391272000	Sync.RecordManager	TRACE	Importing record: https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/meta/global
1446391272001	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391272051	Sync.Resource	DEBUG	mesg: GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/meta/global
1446391272051	Sync.Resource	DEBUG	GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/meta/global
1446391272051	Sync.Service	DEBUG	Weave Version: 1.43.0 Local Storage: 5 Remote Storage: 5
1446391272052	Sync.Service	INFO	Sync IDs differ. Local is pUlIV6EuAMDv, remote is Rlve7-cir57C
1446391272052	Sync.Service	INFO	Service reset.
1446391272052	Sync.Engine.Clients	DEBUG	Resetting clients last sync time
1446391272053	Sync.Engine.Bookmarks	DEBUG	Resetting bookmarks last sync time
1446391272053	Sync.Engine.Forms	DEBUG	Resetting forms last sync time
1446391272054	Sync.Engine.History	DEBUG	Resetting history last sync time
1446391272054	Sync.Engine.Passwords	DEBUG	Resetting passwords last sync time
1446391272055	Sync.Engine.Prefs	DEBUG	Resetting prefs last sync time
1446391272055	Sync.Engine.Tabs	DEBUG	Resetting tabs last sync time
1446391272055	Sync.Engine.Addons	DEBUG	Resetting addons last sync time
1446391272055	Sync.CollectionKeyManager	INFO	Clearing collection keys...
1446391272056	Sync.Service	DEBUG	Clear cached values and take syncId: Rlve7-cir57C
1446391272056	Sync.Service	INFO	Sync key is up-to-date: no need to upgrade.
1446391272056	Sync.Service	DEBUG	Fetching and verifying -- or generating -- symmetric keys.
1446391272056	Sync.Service	INFO	Testing info/collections: {"passwords":1446343292.38,"clients":1446331697.41,"crypto":1432685032.06,"meta":1439518874.53,"bookmarks":1446236871.88,"prefs":1444365667.89}
1446391272056	Sync.CollectionKeyManager	INFO	Testing for updateNeeded. Last modified: 0
1446391272056	Sync.Service	INFO	collection keys reports that a key update is needed.
1446391272057	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391272124	Sync.Resource	DEBUG	mesg: GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/crypto/keys
1446391272124	Sync.Resource	DEBUG	GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/crypto/keys
1446391272124	Sync.CollectionKeyManager	INFO	Updating collection keys...
1446391272125	Sync.CollectionKeyManager	INFO	Setting collection keys contents. Our last modified: 0, input modified: 1432685032.06.
1446391272126	Sync.BulkKeyBundle	INFO	BulkKeyBundle being created for [default]
1446391272126	Sync.CollectionKeyManager	INFO	Processing downloaded per-collection keys.
1446391272126	Sync.CollectionKeyManager	INFO	Clearing collection keys...
1446391272126	Sync.CollectionKeyManager	INFO	Saving downloaded keys.
1446391272126	Sync.CollectionKeyManager	INFO	Bumping last modified to 1432685032.06
1446391272126	Sync.CollectionKeyManager	INFO	Collection keys updated.
1446391272126	Sync.BrowserIDManager	DEBUG	unlockAndVerifyAuthState already has (or can fetch) sync keys
1446391272127	Sync.Service	DEBUG	Fetching unlocked auth state returned success.status_ok
1446391272127	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391272177	Sync.Resource	DEBUG	mesg: GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/info/collections
1446391272178	Sync.Resource	DEBUG	GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/info/collections
1446391272178	Sync.Service	DEBUG	Fetching global metadata record
1446391272178	Sync.RecordManager	TRACE	Importing record: https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/meta/global
1446391272179	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391272230	Sync.Resource	DEBUG	mesg: GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/meta/global
1446391272231	Sync.Resource	DEBUG	GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/meta/global
1446391272231	Sync.Service	DEBUG	Weave Version: 1.43.0 Local Storage: 5 Remote Storage: 5
1446391272231	Sync.Service	INFO	Sync key is up-to-date: no need to upgrade.
1446391272231	Sync.Service	DEBUG	Fetching and verifying -- or generating -- symmetric keys.
1446391272231	Sync.Service	INFO	Testing info/collections: {"passwords":1446343292.38,"clients":1446331697.41,"crypto":1432685032.06,"meta":1439518874.53,"bookmarks":1446236871.88,"prefs":1444365667.89}
1446391272231	Sync.CollectionKeyManager	INFO	Testing for updateNeeded. Last modified: 1432685032.06
1446391272231	Sync.Status	DEBUG	Status.login: success.login => success.login
1446391272231	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1446391272231	Sync.Status	DEBUG	Status.login: success.login => success.login
1446391272231	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1446391272235	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1446391272237	Sync.Status	INFO	Resetting Status.
1446391272237	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1446391272238	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391272287	Sync.Resource	DEBUG	mesg: GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/info/collections?v=1.43.0
1446391272287	Sync.Resource	DEBUG	GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/info/collections?v=1.43.0
1446391272289	Sync.Service	DEBUG	Fetching global metadata record
1446391272289	Sync.Service	DEBUG	Weave Version: 1.43.0 Local Storage: 5 Remote Storage: 5
1446391272289	Sync.Service	INFO	Sync key is up-to-date: no need to upgrade.
1446391272289	Sync.Service	DEBUG	Fetching and verifying -- or generating -- symmetric keys.
1446391272289	Sync.Service	INFO	Testing info/collections: {"passwords":1446343292.38,"clients":1446331697.41,"crypto":1432685032.06,"meta":1439518874.53,"bookmarks":1446236871.88,"prefs":1444365667.89}
1446391272289	Sync.CollectionKeyManager	INFO	Testing for updateNeeded. Last modified: 1432685032.06
1446391272289	Sync.Synchronizer	DEBUG	Refreshing client list.
1446391272290	Sync.Engine.Clients	DEBUG	Engine syncIDs: HBImNPMitGQo,87cegT3qRvX_
1446391272291	Sync.Engine.Clients	DEBUG	Resetting clients last sync time
1446391272291	Sync.Engine.Clients	DEBUG	First sync, uploading all items
1446391272291	Sync.Engine.Clients	INFO	1 outgoing items pre-reconciliation
1446391272293	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391272349	Sync.Collection	DEBUG	mesg: GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/clients?full=1
1446391272349	Sync.Collection	DEBUG	GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/clients?full=1
1446391272349	Sync.Engine.Clients	INFO	Records: 3 applied, 3 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled.
1446391272351	Sync.Tracker.Clients	DEBUG	client.name preference changed
1446391272352	Sync.Engine.Clients	INFO	Uploading all of 1 records
1446391272353	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391272353	Sync.Collection	DEBUG	POST Length: 529
1446391272442	Sync.Collection	DEBUG	mesg: POST success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/clients
1446391272442	Sync.Collection	DEBUG	POST success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/clients
1446391272443	Sync.SyncScheduler	DEBUG	Client count: 0 -> 4
1446391272444	Sync.Synchronizer	INFO	Updating enabled engines: 4 clients.
1446391272445	Sync.Synchronizer	TRACE	The tabs engine was disabled remotely.
1446391272446	Sync.Synchronizer	TRACE	The addons engine was disabled remotely.
1446391272446	Sync.AddonsReconciler	DEBUG	Removing change listener.
1446391272446	Sync.AddonsReconciler	DEBUG	Stopping listening and removing AddonManager listeners.
1446391272446	Sync.Synchronizer	TRACE	The forms engine was disabled remotely.
1446391272446	Sync.Tracker.History	INFO	Removing Places observer.
1446391272447	Sync.Synchronizer	TRACE	The history engine was disabled remotely.
1446391272448	Sync.Engine.Prefs	DEBUG	Engine syncIDs: NA4a7Zxo4sqp,Y4GZiS0i3N4m
1446391272448	Sync.Engine.Prefs	DEBUG	Resetting prefs last sync time
1446391272449	Sync.Engine.Prefs	DEBUG	First sync, uploading all items
1446391272449	Sync.Engine.Prefs	INFO	1 outgoing items pre-reconciliation
1446391272450	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391272453	Sync.SyncScheduler	DEBUG	Next sync in 90000 ms.
1446391272531	Sync.Engine.Prefs	WARN	DATA LOSS: Both local and remote changes to record: e2VjODAzMGY3LWMyMGEtNDY0Zi05YjBlLTEzYTNhOWU5NzM4NH0=
1446391272781	Sync.Collection	DEBUG	mesg: GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/prefs?full=1
1446391272781	Sync.Collection	DEBUG	GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/prefs?full=1
1446391272781	Sync.Engine.Prefs	INFO	Records: 1 applied, 1 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled.
1446391272807	Sync.SyncScheduler	DEBUG	Global Score threshold hit, triggering sync.
1446391272838	Sync.Engine.Prefs	INFO	Uploading all of 1 records
1446391272839	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391272840	Sync.Collection	DEBUG	POST Length: 11435
1446391272859	Sync.Service	DEBUG	User-Agent: Firefox/41.0.2 FxSync/1.43.0.20151014143721.
1446391272859	Sync.Service	INFO	Starting sync at 2015-11-01 07:21:12
1446391272859	Sync.Service	DEBUG	Exception: Could not acquire lock. Label: "service.js: sync". No traceback available
1446391272859	Sync.Service	INFO	Cannot start sync: already syncing?
1446391273007	Sync.Collection	DEBUG	mesg: POST success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/prefs
1446391273007	Sync.Collection	DEBUG	POST success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/prefs
1446391273008	Sync.Engine.Passwords	DEBUG	Engine syncIDs: ZP1kcYVpWd9e,LDpuFWShMn9p
1446391273008	Sync.Engine.Passwords	DEBUG	Resetting passwords last sync time
1446391273008	Sync.Engine.Passwords	DEBUG	First sync, uploading all items
1446391273164	Sync.Engine.Passwords	INFO	194 outgoing items pre-reconciliation
1446391273165	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391273352	Sync.Tracker.Clients	DEBUG	Saving changed IDs to clients
1446391273447	Sync.Tracker.Addons	DEBUG	Saving changed IDs to addons
1446391273449	Sync.Tracker.History	DEBUG	Saving changed IDs to history
1446391273450	Sync.Tracker.Forms	DEBUG	Saving changed IDs to forms
1446391274172	Sync.Tracker.Passwords	DEBUG	Saving changed IDs to passwords
1446391274238	Sync.Collection	DEBUG	mesg: GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/passwords?full=1
1446391274238	Sync.Collection	DEBUG	GET success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/passwords?full=1
1446391274239	Sync.Store.Passwords	DEBUG	Adding login for http://192.168.0.1
1446391274241	Sync.Engine.Passwords	INFO	Records: 1 applied, 1 successfully, 0 failed to apply, 0 newly failed to apply, 193 reconciled.
1446391274244	Sync.Engine.Passwords	INFO	Uploading all of 1 records
1446391274244	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391274245	Sync.Collection	DEBUG	POST Length: 561
1446391274341	Sync.Collection	DEBUG	mesg: POST success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/passwords
1446391274341	Sync.Collection	DEBUG	POST success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/passwords
1446391274345	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391274426	Sync.Collection	DEBUG	mesg: DELETE success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/passwords?ids={098a857c-b41f-6040-9241-a8b54c288887}
1446391274426	Sync.Collection	DEBUG	DELETE success 200 https://sync-218-us-west-2.sync.services.mozilla.com/1.5/23064669/storage/passwords?ids={098a857c-b41f-6040-9241-a8b54c288887}
1446391274426	Sync.Engine.Passwords	DEBUG	Delete result: {"modified": 1446391274.65}
1446391274428	Sync.Engine.Bookmarks	DEBUG	Engine syncIDs: bXBp2Bc5r-xP,Dh_00BIS4MDd
1446391274428	Sync.Engine.Bookmarks	DEBUG	Resetting bookmarks last sync time
1446391274428	Sync.Engine.Bookmarks	DEBUG	First sync, uploading all items
1446391277334	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1446391277334	Sync.SyncScheduler	DEBUG	Next sync in 84666 ms.
1446391303053	Sync.Engine.Bookmarks	INFO	121960 outgoing items pre-reconciliation
1446391303054	Sync.Engine.Bookmarks	DEBUG	Bookmarks backup starting.
1446391304054	Sync.Tracker.Bookmarks	DEBUG	Saving changed IDs to bookmarks
1446391361997	Sync.Service	DEBUG	User-Agent: Firefox/41.0.2 FxSync/1.43.0.20151014143721.
1446391361997	Sync.Service	INFO	Starting sync at 2015-11-01 07:22:41
1446391361997	Sync.Service	DEBUG	Exception: Could not acquire lock. Label: "service.js: sync". No traceback available
1446391361997	Sync.Service	INFO	Cannot start sync: already syncing?
1446391398493	Sync.Engine.Bookmarks	DEBUG	Bookmarks backup done.
1446391398495	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1446391497459	Sync.SyncScheduler	DEBUG	Global Score threshold hit, triggering sync.
1446391497459	Sync.Service	DEBUG	User-Agent: Firefox/41.0.2 FxSync/1.43.0.20151014143721.
1446391497459	Sync.Service	INFO	Starting sync at 2015-11-01 07:24:57
1446391497459	Sync.Service	DEBUG	Exception: Could not acquire lock. Label: "service.js: sync". No traceback available
1446391497459	Sync.Service	INFO	Cannot start sync: already syncing?
1446391498357	Sync.Tracker.Passwords	DEBUG	Saving changed IDs to passwords
1446391528403	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: menu
1446391528403	Sync.Store.Bookmarks	DEBUG	Applying record menu
1446391528403	Sync.Store.Bookmarks	DEBUG	Processing special node: menu
1446391528408	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: toolbar
1446391528408	Sync.Store.Bookmarks	DEBUG	Applying record toolbar
1446391528408	Sync.Store.Bookmarks	DEBUG	Processing special node: toolbar
1446391528439	Sync.Store.Bookmarks	DEBUG	Applying record unfiled
1446391528439	Sync.Store.Bookmarks	DEBUG	Processing special node: unfiled
1446391528470	Sync.Store.Bookmarks	DEBUG	Applying record -3vQEiY-QRWG
1446391528470	Sync.Store.Bookmarks	DEBUG	Local parent is 5ycNrRUawEZ4
1446391528473	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391528475	Sync.Store.Bookmarks	DEBUG	created folder 136318 under 5 as Rodmaking
1446391528477	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136318
1446391529454	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: -jU_-s4-P5y3
1446391529454	Sync.Store.Bookmarks	DEBUG	Applying record -jU_-s4-P5y3
1446391529454	Sync.Store.Bookmarks	DEBUG	Local parent is oppgvzMtToJF
1446391529454	Sync.Store.Bookmarks	DEBUG	Record -jU_-s4-P5y3 is not an orphan.
1446391529457	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 2061
1446391529645	Sync.Store.Bookmarks	DEBUG	Applying record 02pSEpv-PFkU
1446391529645	Sync.Store.Bookmarks	DEBUG	Local parent is pvc2by1_owbb
1446391529646	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391529646	Sync.Store.Bookmarks	DEBUG	created folder 136319 under 5 as ISC
1446391529648	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136319
1446391529715	Sync.Store.Bookmarks	DEBUG	Applying record 0AKN6V99WRYs
1446391529715	Sync.Store.Bookmarks	DEBUG	Local parent is XCTg_eVyRpux
1446391529715	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391529716	Sync.Store.Bookmarks	DEBUG	created folder 136320 under 5 as Other…
1446391529718	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136320
1446391530118	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 0rXlPW2BCUTq
1446391530118	Sync.Store.Bookmarks	DEBUG	Applying record 0rXlPW2BCUTq
1446391530118	Sync.Store.Bookmarks	DEBUG	Local parent is CsVw6bX2i23g
1446391530118	Sync.Store.Bookmarks	DEBUG	Record 0rXlPW2BCUTq is not an orphan.
1446391530123	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 2217
1446391530313	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 1KbA-M_5lGOE
1446391530313	Sync.Store.Bookmarks	DEBUG	Applying record 1KbA-M_5lGOE
1446391530313	Sync.Store.Bookmarks	DEBUG	Local parent is 4QaP7JrEfQlR
1446391530316	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 104093
1446391530402	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 1TQtZzv6N3vI
1446391530402	Sync.Store.Bookmarks	DEBUG	Applying record 1TQtZzv6N3vI
1446391530402	Sync.Store.Bookmarks	DEBUG	Local parent is j7yYRDEyrj87
1446391530403	Sync.Store.Bookmarks	DEBUG	Record 1TQtZzv6N3vI is not an orphan.
1446391530409	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 1363
1446391530513	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 1iT-rUoyle6d
1446391530514	Sync.Store.Bookmarks	DEBUG	Applying record 1iT-rUoyle6d
1446391530514	Sync.Store.Bookmarks	DEBUG	Local parent is p0pcD8aRVMDE
1446391530519	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136310
1446391530524	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 1ixI1GJDolXO
1446391530524	Sync.Store.Bookmarks	DEBUG	Applying record 1ixI1GJDolXO
1446391530524	Sync.Store.Bookmarks	DEBUG	Local parent is p0pcD8aRVMDE
1446391530529	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136311
1446391530546	Sync.Store.Bookmarks	DEBUG	Applying record 1lu57acX0K3g
1446391530547	Sync.Store.Bookmarks	DEBUG	Local parent is pvc2by1_owbb
1446391530547	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391530547	Sync.Store.Bookmarks	DEBUG	created folder 136321 under 5 as ISC
1446391530550	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136321
1446391531019	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 2eMvzstaSyhs
1446391531019	Sync.Store.Bookmarks	DEBUG	Applying record 2eMvzstaSyhs
1446391531019	Sync.Store.Bookmarks	DEBUG	Local parent is vxSQTlBNd0O6
1446391531020	Sync.Store.Bookmarks	DEBUG	Record 2eMvzstaSyhs is not an orphan.
1446391531023	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 102506
1446391531042	Sync.Store.Bookmarks	DEBUG	Applying record 2i5oLD866iqo
1446391531042	Sync.Store.Bookmarks	DEBUG	Local parent is XCTg_eVyRpux
1446391531042	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391531043	Sync.Store.Bookmarks	DEBUG	created folder 136322 under 5 as Skiing
1446391531045	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136322
1446391531089	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 2loGKVtxkNtX
1446391531089	Sync.Store.Bookmarks	DEBUG	Applying record 2loGKVtxkNtX
1446391531089	Sync.Store.Bookmarks	DEBUG	Local parent is NOlE__F4rwvI
1446391531090	Sync.Store.Bookmarks	DEBUG	Record 2loGKVtxkNtX is not an orphan.
1446391531093	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136281
1446391531312	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 35hb-iPJ3obA
1446391531312	Sync.Store.Bookmarks	DEBUG	Applying record 35hb-iPJ3obA
1446391531313	Sync.Store.Bookmarks	DEBUG	Local parent is toolbar
1446391531313	Sync.Store.Bookmarks	DEBUG	Record 35hb-iPJ3obA is not an orphan.
1446391531315	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 2507
1446391531831	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 491L9iBo_8Vf
1446391531831	Sync.Store.Bookmarks	DEBUG	Applying record 491L9iBo_8Vf
1446391531831	Sync.Store.Bookmarks	DEBUG	Local parent is toolbar
1446391531831	Sync.Store.Bookmarks	DEBUG	Record 491L9iBo_8Vf is not an orphan.
1446391531835	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 104270
1446391532060	Sync.Store.Bookmarks	DEBUG	Applying record 4dYW5xTDT68e
1446391532060	Sync.Store.Bookmarks	DEBUG	Local parent is 5ycNrRUawEZ4
1446391532061	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391532061	Sync.Store.Bookmarks	DEBUG	created folder 136323 under 5 as Destinations
1446391532063	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136323
1446391532185	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 4qinQ-eeYzJo
1446391532185	Sync.Store.Bookmarks	DEBUG	Applying record 4qinQ-eeYzJo
1446391532185	Sync.Store.Bookmarks	DEBUG	Local parent is p0pcD8aRVMDE
1446391532188	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136312
1446391532209	Sync.Store.Bookmarks	DEBUG	Applying record 4s3Q3KP1h57w
1446391532210	Sync.Store.Bookmarks	DEBUG	Local parent is pvc2by1_owbb
1446391532210	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391532210	Sync.Store.Bookmarks	DEBUG	created folder 136324 under 5 as Resources
1446391532213	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136324
1446391532216	Sync.Store.Bookmarks	DEBUG	Applying record 4sLBmEpaBixt
1446391532216	Sync.Store.Bookmarks	DEBUG	Local parent is XCTg_eVyRpux
1446391532216	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391532217	Sync.Store.Bookmarks	DEBUG	created folder 136325 under 5 as Health
1446391532219	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136325
1446391532677	Sync.Store.Bookmarks	DEBUG	Applying record 5WvBifKPGtc1
1446391532677	Sync.Store.Bookmarks	DEBUG	Local parent is nnx3k8i1VLjN
1446391532677	Sync.Store.Bookmarks	DEBUG	Record 5WvBifKPGtc1 is not an orphan.
1446391532678	Sync.Store.Bookmarks	DEBUG	created folder 136326 under 104346 as Notes and References
1446391532686	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136326
1446391532887	Sync.Store.Bookmarks	DEBUG	Applying record 5ycNrRUawEZ4
1446391532887	Sync.Store.Bookmarks	DEBUG	Local parent is XCTg_eVyRpux
1446391532892	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391532892	Sync.Store.Bookmarks	DEBUG	created folder 136327 under 5 as Fishing
1446391532894	Sync.Store.Bookmarks	DEBUG	Reparenting orphans 104316,136318,136323 to 136327
1446391533595	Sync.Store.Bookmarks	DEBUG	Applying record 6YmsNXBOFqPg
1446391533595	Sync.Store.Bookmarks	DEBUG	Local parent is pvc2by1_owbb
1446391533596	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391533597	Sync.Store.Bookmarks	DEBUG	created folder 136328 under 5 as My Sites
1446391533634	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136328
1446391533840	Sync.Store.Bookmarks	DEBUG	Applying record 70ZA1mVlYRRO
1446391533840	Sync.Store.Bookmarks	DEBUG	Local parent is XCTg_eVyRpux
1446391533840	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391533841	Sync.Store.Bookmarks	DEBUG	created folder 136329 under 5 as Other…
1446391533843	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136329
1446391534211	Sync.Store.Bookmarks	DEBUG	Applying record 7qGg_ARpBpXJ
1446391534211	Sync.Store.Bookmarks	DEBUG	Local parent is pvc2by1_owbb
1446391534211	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391534212	Sync.Store.Bookmarks	DEBUG	created folder 136330 under 5 as News
1446391534214	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136330
1446391534313	Sync.Store.Bookmarks	DEBUG	Applying record 86W0DXUBnrdZ
1446391534313	Sync.Store.Bookmarks	DEBUG	Local parent is usXo2EoMOgE0
1446391534314	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391534314	Sync.Store.Bookmarks	DEBUG	created folder 136331 under 5 as ISC
1446391534320	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136331
1446391534373	Sync.Store.Bookmarks	DEBUG	Applying record 8C9bfTwt-12O
1446391534373	Sync.Store.Bookmarks	DEBUG	Local parent is pvc2by1_owbb
1446391534374	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391534374	Sync.Store.Bookmarks	DEBUG	created folder 136332 under 5 as Web Mail
1446391534377	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136332
1446391534463	Sync.Store.Bookmarks	DEBUG	Applying record 8NEuaGbet7Ej
1446391534463	Sync.Store.Bookmarks	DEBUG	Local parent is usXo2EoMOgE0
1446391534464	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391534464	Sync.Store.Bookmarks	DEBUG	created folder 136333 under 5 as Resources
1446391534470	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136333
1446391534630	Sync.Store.Bookmarks	DEBUG	Applying record 8ii1548VDH9c
1446391534630	Sync.Store.Bookmarks	DEBUG	Local parent is XCTg_eVyRpux
1446391534634	Sync.Store.Bookmarks	DEBUG	Parent is undefined; reparenting to unfiled.
1446391534635	Sync.Store.Bookmarks	DEBUG	created folder 136334 under 5 as Software
1446391534636	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 136334
1446391534925	Sync.Engine.Bookmarks	WARN	DATA LOSS: Both local and remote changes to record: 9WwffeCRdX7k
1446391534925	Sync.Store.Bookmarks	DEBUG	Applying record 9WwffeCRdX7k
1446391534925	Sync.Store.Bookmarks	DEBUG	Local parent is usXo2EoMOgE0
1446391534929	Sync.Store.Bookmarks	DEBUG	Reparenting orphans  to 3289
1446391536993	Sync.Status	DEBUG	Status for engine bookmarks: error.engine.reason.unknown_fail
1446391536993	Sync.Status	DEBUG	Status.service: success.status_ok => error.sync.failed_partial
1446391536993	Sync.ErrorHandler	DEBUG	bookmarks failed: Error: NS_ERROR_NET_PARTIAL_TRANSFER (resource://services-sync/resource.js:409:19) JS Stack trace: waitForSyncCallback@async.js:102:7 < Res__request@resource.js:405:14 < Res_get@resource.js:429:12 < SyncEngine.prototype._processIncoming@engines.js:1108:18 < BookmarksEngine.prototype._processIncoming@bookmarks.js:432:7 < SyncEngine.prototype._sync@engines.js:1520:7 < wrappedSync@bookmarks.js:229:11 < _sync@bookmarks.js:226:1 < WrappedNotify@util.js:148:21 < Engine.prototype.sync@engines.js:668:5 < _syncEngine@enginesync.js:199:7 < sync@enginesync.js:149:15 < onNotify@service.js:1298:7 < WrappedNotify@util.js:148:21 < WrappedLock@util.js:103:16 < _lockedSync@service.js:1288:12 < sync/<@service.js:1280:14 < WrappedCatch@util.js:77:16 < sync@service.js:1268:5 < Res_get@resource.js:429:12 < SyncEngine.prototype._processIncoming@engines.js:1108:18 < BookmarksEngine.prototype._processIncoming@bookmarks.js:432:7 < SyncEngine.prototype._sync@engines.js:1520:7 < wrappedSync@bookmarks.js:229:11 < _sync@bookmarks.js:226:1 < WrappedNotify@util.js:148:21 < Engine.prototype.sync@engines.js:668:5 < _syncEngine@enginesync.js:199:7 < sync@enginesync.js:149:15 < onNotify@service.js:1298:7 < WrappedNotify@util.js:148:21 < WrappedLock@util.js:103:16 < _lockedSync@service.js:1288:12 < sync/<@service.js:1280:14 < WrappedCatch@util.js:77:16 < sync@service.js:1268:5
1446391536994	Sync.Synchronizer	INFO	Sync completed at 2015-11-01 07:25:36 after 264.76 secs.
1446391536995	Sync.Declined	DEBUG	Handling remote declined: ["tabs","addons","forms","history"]
1446391536995	Sync.Declined	DEBUG	Handling local declined: []
1446391536995	Sync.Declined	DEBUG	Declined changed? false
1446391536996	Sync.Service	INFO	No change to declined engines. Not reuploading meta/global.
1446391536996	Sync.SyncScheduler	DEBUG	Next sync in 90000 ms.
1446391536996	Sync.ErrorHandler	ERROR	Some engines did not sync correctly.



Expected results:

sync should happen seamlessly, never fail and be INSTANTANEOUS
Sorry for the delay here, but we've fixed this in bug 1294599.
Status: UNCONFIRMED → RESOLVED
Closed: 6 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.