Closed Bug 861016 Opened 12 years ago Closed 11 years ago

sync failing since April 10

Categories

(Cloud Services :: Operations: Miscellaneous, task)

Product:
Cloud Services
Component:
Operations: Miscellaneous
Platform:
x86_64
Linux
Type:
task
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED FIXED

People

(Reporter: dustin, Assigned: jlaz)

Details

My syncs are failing on two systems since yesterday's maintenance. I get the "Sync encountered an error while syncing: Failed to connect to the server" gray bar. I don't know much about what the logs are telling me, but this doesn't seem to correspond to that error message, despite the times matching up: 1365724770439 Sync.ErrorHandler DEBUG Flushing file log. 1365724770448 Sync.Status DEBUG Status.service: error.sync.failed_partial => success.status_ok 1365724770462 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365724770585 Sync.ErrorHandler DEBUG Log cleanup threshold time: 1364860770585 1365724770655 Sync.ErrorHandler DEBUG Done deleting files. 1365725341720 Sync.ErrorHandler DEBUG Beginning user-triggered sync. 1365725341769 Sync.Service DEBUG User-Agent: Firefox/20.0 FxSync/1.22.0.20130401133302. 1365725341770 Sync.Service INFO Starting sync at 2013-04-11 20:09:01 1365725341771 Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. 1365725341772 Sync.Status INFO Resetting Status. 1365725341773 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365725342190 Sync.Resource DEBUG mesg: GET success 200 https://phx-sync021.services.mozilla.com/1.1/djmitche/info/collections 1365725342190 Sync.Resource DEBUG GET success 200 https://phx-sync021.services.mozilla.com/1.1/djmitche/info/collections 1365725342191 Sync.Service DEBUG Fetching global metadata record 1365725342192 Sync.Service DEBUG Weave Version: 1.22.0 Local Storage: 5 Remote Storage: 5 1365725342192 Sync.Service INFO Sync key is up-to-date: no need to upgrade. 1365725342192 Sync.Service DEBUG Fetching and verifying -- or generating -- symmetric keys. 1365725342193 Sync.Service INFO Testing info/collections: {"passwords":1365716120.03,"addons":1364910648.85,"tabs":1365724770.11,"clients":1365697158.23,"crypto":1364867029.17,"forms":1365718741.95,"meta":1364910649.06,"bookmarks":1365360906.94,"prefs":1365602433.51,"history":1365724373.08} 1365725342193 Sync.CollectionKeyManager INFO Testing for updateNeeded. Last modified: 1364867029.17 1365725342193 Sync.Synchronizer DEBUG Refreshing client list. 1365725342195 Sync.Engine.Clients INFO 0 outgoing items pre-reconciliation 1365725342197 Sync.Engine.Clients INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365725342199 Sync.Synchronizer INFO Updating enabled engines: 3 clients. 1365725342203 Sync.Engine.Bookmarks INFO 0 outgoing items pre-reconciliation 1365725342205 Sync.Engine.Bookmarks INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365725342211 Sync.Engine.Forms INFO 0 outgoing items pre-reconciliation 1365725342213 Sync.Engine.Forms INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365725342215 Sync.Engine.History INFO 99 outgoing items pre-reconciliation 1365725353247 Sync.SyncScheduler DEBUG Next sync in 3600000 ms. 1365725642228 Sync.Status DEBUG Status.sync: success.sync => error.login.reason.network 1365725642228 Sync.Status DEBUG Status.service: success.status_ok => error.sync.failed 1365725642228 Sync.Status DEBUG Status for engine history: error.engine.reason.unknown_fail 1365725642228 Sync.Status DEBUG Status.service: error.sync.failed => error.sync.failed_partial 1365725642229 Sync.ErrorHandler DEBUG history failed: Aborting due to channel inactivity. JS Stack trace: Res_get@resource.js:413 < @engines.js:931 < SyncEngine__sync@engines.js:1342 < WrappedNotify@util.js:142 < Engine_sync@engines.js:519 < _syncEngine@enginesync.js:192 < sync@enginesync.js:147 < onNotify@service.js:1185 < WrappedNotify@util.js:142 < WrappedLock@util.js:97 < _lockedSync@service.js:1179 < @service.js:1170 < WrappedCatch@util.js:71 < sync@service.js:1158 1365725642231 Sync.Engine.Passwords INFO 0 outgoing items pre-reconciliation 1365725642233 Sync.Engine.Passwords INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365725642236 Sync.Engine.Prefs INFO 0 outgoing items pre-reconciliation 1365725642238 Sync.Engine.Prefs INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365725642240 Sync.Engine.Tabs INFO 1 outgoing items pre-reconciliation 1365725642242 Sync.Engine.Tabs INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365725642505 Sync.Engine.Tabs INFO Uploading all of 1 records 1365725642507 Sync.Collection DEBUG POST Length: 1488 1365725643110 Sync.Collection DEBUG mesg: POST success 200 https://phx-sync021.services.mozilla.com/1.1/djmitche/storage/tabs 1365725643110 Sync.Collection DEBUG POST success 200 https://phx-sync021.services.mozilla.com/1.1/djmitche/storage/tabs 1365725643112 Sync.Engine.Addons DEBUG Refreshing reconciler state 1365725643112 Sync.AddonsReconciler INFO Refreshing global state from AddonManager. 1365725643289 Sync.AddonsReconciler DEBUG Rectifying state for addon: perlformatter@aivector.com 1365725643289 Sync.AddonsReconciler DEBUG Rectifying state for addon: firebug@software.joehewitt.com 1365725643289 Sync.AddonsReconciler DEBUG Rectifying state for addon: compatibility@addons.mozilla.org 1365725643289 Sync.AddonsReconciler DEBUG Rectifying state for addon: jid0-qBnIpLfDFa4LpdrjhAC6vBqN20Q@jetpack 1365725643289 Sync.AddonsReconciler DEBUG Rectifying state for addon: jid0-NgMDcEu2B88AbzZ6ulHodW9sJzA@jetpack 1365725643289 Sync.AddonsReconciler DEBUG Rectifying state for addon: {96118df2-0d02-4dbc-9ad5-98995dc7d977} 1365725643289 Sync.AddonsReconciler DEBUG Rectifying state for addon: new-tabs-at-end@forerunnerdesigns.com 1365725643290 Sync.AddonsReconciler DEBUG Rectifying state for addon: masspasswordreset@johnathan.nightingale 1365725643290 Sync.AddonsReconciler DEBUG Rectifying state for addon: hidefindbar@jaredmcateer.com 1365725643290 Sync.AddonsReconciler DEBUG Rectifying state for addon: jid1-0LUk0G25IhTJ0g@jetpack 1365725643290 Sync.AddonsReconciler DEBUG Rectifying state for addon: {c0c588b6-b11d-4898-af00-079fed05aa32} 1365725643290 Sync.AddonsReconciler DEBUG Rectifying state for addon: {972ce4c6-7e08-4474-a285-3208198ce6fd} 1365725643290 Sync.AddonsReconciler DEBUG Rectifying state for addon: skipcerterror@foudil.fr 1365725643290 Sync.AddonsReconciler DEBUG Rectifying state for addon: {8f8fe09b-0bd3-4470-bc1b-8cad42b8203a} 1365725643290 Sync.AddonsReconciler DEBUG Rectifying state for addon: {d10d0bf8-f5b5-c8b4-a8b2-2b9879e08c5d} 1365725643290 Sync.AddonsReconciler DEBUG Rectifying state for addon: 360072@personas.mozilla.org 1365725643291 Sync.AddonsReconciler DEBUG Rectifying state for addon: 54707@personas.mozilla.org 1365725643291 Sync.AddonsReconciler DEBUG Rectifying state for addon: {3050f584-f0fb-1a0d-6e4f-c4c1d0f1ecec} 1365725643292 Sync.AddonsReconciler DEBUG Rectifying state for addon: {d461bff3-f642-80f9-5196-92a6c19eae1c} 1365725643292 Sync.AddonsReconciler DEBUG Rectifying state for addon: {d181fcc2-7e61-f01e-e320-c6941c607cf4} 1365725643292 Sync.AddonsReconciler DEBUG Rectifying state for addon: {f2d261dc-c5c4-ca3c-ae02-ccb3ff227c7f} 1365725643292 Sync.AddonsReconciler DEBUG Rectifying state for addon: {32663cac-7d74-71ab-c69a-75e165acfb8a} 1365725643292 Sync.AddonsReconciler DEBUG Rectifying state for addon: {932c5889-7fd3-ac18-cb35-53ba8da9f0b1} 1365725643292 Sync.AddonsReconciler DEBUG Rectifying state for addon: {e1ae91e8-2771-fa2b-e67f-54f5822e65a1} 1365725643292 Sync.AddonsReconciler DEBUG Rectifying state for addon: {35a24673-293b-024d-c2a1-4c44885ad94b} 1365725643292 Sync.AddonsReconciler DEBUG Rectifying state for addon: {81483a79-4662-220f-c0b3-08db1c26b031} 1365725643295 Sync.AddonsReconciler INFO Saving reconciler state to file: addonsreconciler 1365725643302 Sync.Store.Addons DEBUG {972ce4c6-7e08-4474-a285-3208198ce6fd} not syncable: not installed in profile. 1365725643302 Sync.Store.Addons DEBUG 360072@personas.mozilla.org not syncable: add-on not found in add-on repository. 1365725643302 Sync.Store.Addons DEBUG {972ce4c6-7e08-4474-a285-3208198ce6fd} not syncable: not installed in profile. 1365725643303 Sync.Store.Addons DEBUG 360072@personas.mozilla.org not syncable: add-on not found in add-on repository. 1365725643303 Sync.Engine.Addons INFO 0 outgoing items pre-reconciliation 1365725643305 Sync.Engine.Addons INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365725643307 Sync.Synchronizer INFO Sync completed at 2013-04-11 20:14:03 after 301.54 secs. 1365725643308 Sync.SyncScheduler DEBUG Next sync in 3600000 ms. 1365725643308 Sync.ErrorHandler DEBUG Some engines did not sync correctly. Clicking "Sync Now" or just waiting doesn't seem to help.
Connection is timing out.
Component: Firefox Sync: Backend → Operations
Hey Dustin, We've migrated that DB node this morning due to some hardware related issues, which means you should be re-assigned a new node. Are you still experiencing the problems above?
Yep, as of 30m ago: 1365788103638 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788103639 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788103639 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788103639 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788248820 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788249489 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788267431 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788268078 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788350969 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788351587 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788354865 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788355597 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788579086 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788579765 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788584300 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788604623 Sync.SyncScheduler DEBUG Global Score threshold hit, triggering sync. 1365788604623 Sync.Service DEBUG User-Agent: Firefox/20.0 FxSync/1.22.0.20130326150557. 1365788604623 Sync.Service INFO Starting sync at 2013-04-12 13:43:24 1365788604625 Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. 1365788604626 Sync.Status INFO Resetting Status. 1365788604626 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788604987 Sync.Resource DEBUG mesg: GET success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/info/collections?v=1.22.0 1365788604987 Sync.Resource DEBUG GET success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/info/collections?v=1.22.0 1365788604987 Sync.Service DEBUG Fetching global metadata record 1365788604987 Sync.Service DEBUG Weave Version: 1.22.0 Local Storage: 5 Remote Storage: 5 1365788604988 Sync.Service INFO Sync key is up-to-date: no need to upgrade. 1365788604988 Sync.Service DEBUG Fetching and verifying -- or generating -- symmetric keys. 1365788604988 Sync.Service INFO Testing info/collections: {"passwords":1365788103.3,"addons":1365776415.84,"tabs":1365788103.54,"clients":1365775776.76,"crypto":1365770362.13,"forms":1365787823.91,"meta":1365770744.2,"bookmarks":1365775777.97,"prefs":1365776518.43,"history":1365788102.99} 1365788604988 Sync.CollectionKeyManager INFO Testing for updateNeeded. Last modified: 1365770362.13 1365788604988 Sync.Synchronizer DEBUG Refreshing client list. 1365788604989 Sync.Engine.Clients INFO 0 outgoing items pre-reconciliation 1365788604990 Sync.Engine.Clients INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365788604990 Sync.Synchronizer INFO Updating enabled engines: 2 clients. 1365788604992 Sync.Engine.Bookmarks INFO 0 outgoing items pre-reconciliation 1365788604993 Sync.Engine.Bookmarks INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365788604995 Sync.Engine.Forms INFO 2 outgoing items pre-reconciliation 1365788604995 Sync.Engine.Forms INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365788605010 Sync.Engine.Forms INFO Uploading all of 2 records 1365788605011 Sync.Collection DEBUG POST Length: 617 1365788605177 Sync.Collection DEBUG mesg: POST success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/storage/forms 1365788605177 Sync.Collection DEBUG POST success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/storage/forms 1365788605179 Sync.Engine.History INFO 6 outgoing items pre-reconciliation 1365788605180 Sync.Engine.History INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365788605190 Sync.Engine.History INFO Uploading all of 6 records 1365788605191 Sync.Collection DEBUG POST Length: 3668 1365788605347 Sync.SyncScheduler DEBUG Global Score threshold hit, triggering sync. 1365788605347 Sync.Service DEBUG User-Agent: Firefox/20.0 FxSync/1.22.0.20130326150557. 1365788605347 Sync.Service INFO Starting sync at 2013-04-12 13:43:25 1365788605347 Sync.Service DEBUG Exception: Could not acquire lock. Label: "service.js: sync". No traceback available 1365788605347 Sync.Service INFO Cannot start sync: already syncing? 1365788605437 Sync.Collection DEBUG mesg: POST success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/storage/history 1365788605437 Sync.Collection DEBUG POST success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/storage/history 1365788605438 Sync.Engine.Passwords INFO 0 outgoing items pre-reconciliation 1365788605439 Sync.Engine.Passwords INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365788605440 Sync.Engine.Prefs INFO 1 outgoing items pre-reconciliation 1365788605440 Sync.Engine.Prefs INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365788605453 Sync.Engine.Prefs INFO Uploading all of 1 records 1365788605454 Sync.Collection DEBUG POST Length: 12755 1365788605719 Sync.Collection DEBUG mesg: POST success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/storage/prefs 1365788605719 Sync.Collection DEBUG POST success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/storage/prefs 1365788605720 Sync.Engine.Tabs INFO 1 outgoing items pre-reconciliation 1365788605721 Sync.Engine.Tabs INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365788605831 Sync.Engine.Tabs INFO Uploading all of 1 records 1365788605832 Sync.Collection DEBUG POST Length: 4152 1365788615662 Sync.SyncScheduler DEBUG Global Score threshold hit, triggering sync. 1365788615662 Sync.Service DEBUG User-Agent: Firefox/20.0 FxSync/1.22.0.20130326150557. 1365788615662 Sync.Service INFO Starting sync at 2013-04-12 13:43:35 1365788615663 Sync.Service DEBUG Exception: Could not acquire lock. Label: "service.js: sync". No traceback available 1365788615663 Sync.Service INFO Cannot start sync: already syncing? 1365788621875 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788622818 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1365788623471 Sync.SyncScheduler DEBUG Global Score threshold hit, triggering sync. 1365788623528 Sync.Service DEBUG User-Agent: Firefox/20.0 FxSync/1.22.0.20130326150557. 1365788623528 Sync.Service INFO Starting sync at 2013-04-12 13:43:43 1365788623528 Sync.Service DEBUG Exception: Could not acquire lock. Label: "service.js: sync". No traceback available 1365788623528 Sync.Service INFO Cannot start sync: already syncing? 1365788657179 Sync.Status DEBUG Status for engine tabs: error.engine.reason.unknown_fail 1365788657179 Sync.Status DEBUG Status.service: success.status_ok => error.sync.failed_partial 1365788657179 Sync.ErrorHandler DEBUG tabs failed: NS_ERROR_FAILURE JS Stack trace: Res_post@resource.js:427 < @engines.js:1246 < innerBind@util.js:477 < SyncEngine__uploadOutgoing@engines.js:1294 < SyncEngine__sync@engines.js:1344 < WrappedNotify@util.js:142 < Engine_sync@engines.js:519 < _syncEngine@enginesync.js:192 < sync@enginesync.js:147 < onNotify@service.js:1185 < WrappedNotify@util.js:142 < WrappedLock@util.js:97 < _lockedSync@service.js:1179 < @service.js:1170 < WrappedCatch@util.js:71 < sync@service.js:1158 1365788657179 Sync.Engine.Addons DEBUG Refreshing reconciler state 1365788657179 Sync.AddonsReconciler INFO Refreshing global state from AddonManager. 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: compatibility@addons.mozilla.org 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: hidefindbar@jaredmcateer.com 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: jid0-qBnIpLfDFa4LpdrjhAC6vBqN20Q@jetpack 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: masspasswordreset@johnathan.nightingale 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: new-tabs-at-end@forerunnerdesigns.com 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: old-lion-fullscreen@flyingtealeaf.com 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: openwebapps@mozillalabs.com 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: perlformatter@aivector.com 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: {96118df2-0d02-4dbc-9ad5-98995dc7d977} 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: jid0-NgMDcEu2B88AbzZ6ulHodW9sJzA@jetpack 1365788657226 Sync.AddonsReconciler DEBUG Rectifying state for addon: firebug@software.joehewitt.com 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: jid1-0LUk0G25IhTJ0g@jetpack 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {c0c588b6-b11d-4898-af00-079fed05aa32} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {972ce4c6-7e08-4474-a285-3208198ce6fd} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: skipcerterror@foudil.fr 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {8f8fe09b-0bd3-4470-bc1b-8cad42b8203a} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {d10d0bf8-f5b5-c8b4-a8b2-2b9879e08c5d} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: 360072@personas.mozilla.org 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: 54707@personas.mozilla.org 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {f7bc8076-12cd-09c3-7f36-94287a9880f9} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {477826d8-03c2-5b5f-59fc-d0ff7462f6b5} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {847b0e9f-cbcf-443c-c9ff-cce5ce6a1de7} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {b14169e2-11ed-f9d5-279a-9754401447dd} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {07b90314-1e79-c84a-4b47-fb7e1853be39} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {d95f2237-07c7-b389-7956-65e6f1ce8e0a} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {0bc151fc-4895-269c-2acf-f91a439f6804} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {127ff364-3b9e-f80e-7d7e-e7b461a317a9} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {97509d10-2acb-f507-9f5e-786b9ad26665} 1365788657227 Sync.AddonsReconciler DEBUG Rectifying state for addon: {5ea60f7e-7eef-6fb6-03fc-6bb8b4b1aed4} 1365788657229 Sync.AddonsReconciler INFO Saving reconciler state to file: addonsreconciler 1365788657232 Sync.Engine.Addons INFO 0 outgoing items pre-reconciliation 1365788657232 Sync.Engine.Addons INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1365788657233 Sync.Synchronizer INFO Sync completed at 2013-04-12 13:44:17 after 52.61 secs. 1365788657233 Sync.SyncScheduler DEBUG Next sync in 3600000 ms. 1365788657233 Sync.ErrorHandler DEBUG Some engines did not sync correctly.
I've been having very similar problems. 1366105467418 Sync.ErrorHandler DEBUG Flushing file log. 1366105467421 Sync.Status DEBUG Status.service: error.sync.failed_partial => success.status_ok 1366105467421 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366105467436 Sync.ErrorHandler DEBUG Log cleanup threshold time: 1365241467436 1366105467438 Sync.ErrorHandler DEBUG No logs to clean up. 1366105467621 Sync.Tracker.History DEBUG Saving changed IDs to history 1366105467621 Sync.Tracker.Passwords DEBUG Saving changed IDs to passwords 1366105468425 Sync.Tracker.Addons DEBUG Saving changed IDs to addons 1366105499301 Sync.Tracker.History DEBUG Saving changed IDs to history 1366105505053 Sync.Tracker.Forms DEBUG Saving changed IDs to forms 1366105505911 Sync.Tracker.History DEBUG Saving changed IDs to history 1366105507333 Sync.ErrorHandler DEBUG Beginning user-triggered sync. 1366105507333 Sync.Service DEBUG User-Agent: Firefox/22.0a2 FxSync/1.24.0.20130414004015. 1366105507333 Sync.Service INFO Starting sync at 2013-04-16 11:45:07 1366105507334 Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. 1366105507334 Sync.Status INFO Resetting Status. 1366105507334 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366105507580 Sync.Tracker.History DEBUG Saving changed IDs to history 1366105507845 Sync.Resource DEBUG mesg: GET success 200 https://phx-sync583.services.mozilla.com/1.1/djc/info/collections 1366105507845 Sync.Resource DEBUG GET success 200 https://phx-sync583.services.mozilla.com/1.1/djc/info/collections 1366105507845 Sync.Service DEBUG Fetching global metadata record 1366105507845 Sync.Service DEBUG Weave Version: 1.24.0 Local Storage: 5 Remote Storage: 5 1366105507846 Sync.Service INFO Sync key is up-to-date: no need to upgrade. 1366105507846 Sync.Service DEBUG Fetching and verifying -- or generating -- symmetric keys. 1366105507846 Sync.Service INFO Testing info/collections: {"passwords":1360746772.57,"addons":1365494439.52,"tabs":1366105466.97,"clients":1366103659.31,"crypto":1360744285.31,"forms":1366104021.45,"meta":1360746774.57,"bookmarks":1365934399.84,"prefs":1365406183.76,"history":1366105167.03} 1366105507846 Sync.CollectionKeyManager INFO Testing for updateNeeded. Last modified: 1360744285.31 1366105507846 Sync.Synchronizer DEBUG Refreshing client list. 1366105507846 Sync.Engine.Clients INFO 0 outgoing items pre-reconciliation 1366105507847 Sync.Engine.Clients INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366105507847 Sync.Synchronizer INFO Updating enabled engines: 3 clients. 1366105507942 Sync.Engine.Bookmarks INFO 0 outgoing items pre-reconciliation 1366105507944 Sync.Engine.Bookmarks INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366105507948 Sync.Engine.Forms INFO 1 outgoing items pre-reconciliation 1366105507950 Sync.Engine.Forms INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366105507974 Sync.Engine.Forms INFO Uploading all of 1 records 1366105507975 Sync.Collection DEBUG POST Length: 297 1366105508860 Sync.Tracker.Clients DEBUG Saving changed IDs to clients 1366105508952 Sync.Tracker.Bookmarks DEBUG Saving changed IDs to bookmarks 1366105508953 Sync.Tracker.Forms DEBUG Saving changed IDs to forms 1366105516939 Sync.SyncScheduler DEBUG Next sync in 3600000 ms. 1366105517829 Sync.Tracker.History DEBUG Saving changed IDs to history 1366105531421 Sync.Collection DEBUG mesg: POST success 200 https://phx-sync583.services.mozilla.com/1.1/djc/storage/forms 1366105531421 Sync.Collection DEBUG POST success 200 https://phx-sync583.services.mozilla.com/1.1/djc/storage/forms 1366105531424 Sync.Engine.History INFO 112 outgoing items pre-reconciliation 1366105532430 Sync.Tracker.History DEBUG Saving changed IDs to history 1366105535489 Sync.Tracker.History DEBUG Saving changed IDs to history 1366105559591 Sync.Tracker.History DEBUG Saving changed IDs to history 1366105560380 Sync.Collection DEBUG mesg: GET success 200 https://phx-sync583.services.mozilla.com/1.1/djc/storage/history?newer=1366104767.66&full=1 1366105560380 Sync.Collection DEBUG GET success 200 https://phx-sync583.services.mozilla.com/1.1/djc/storage/history?newer=1366104767.66&full=1 1366105560381 Sync.Engine.History INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 57 reconciled. 1366105560507 Sync.Engine.History INFO Uploading all of 55 records 1366105560509 Sync.Collection DEBUG POST Length: 33750 1366105561153 Sync.Collection DEBUG mesg: POST fail 503 https://phx-sync583.services.mozilla.com/1.1/djc/storage/history 1366105561153 Sync.Collection DEBUG POST fail 503 https://phx-sync583.services.mozilla.com/1.1/djc/storage/history 1366105561153 Sync.Engine.History DEBUG Uploading records failed: "server issue: database is not healthy" 1366105561157 Sync.ErrorHandler DEBUG Got Retry-After: 600 1366105561157 Sync.Status DEBUG Status.sync: success.sync => error.sync.reason.serverMaintenance 1366105561157 Sync.Status DEBUG Status.service: success.status_ok => error.sync.failed 1366105561158 Sync.SyncScheduler DEBUG Got backoff notification: 600000ms 1366105561158 Sync.SyncScheduler DEBUG Fuzzed minimum next sync: 1366106161158 1366105561158 Sync.Status DEBUG Status for engine history: error.engine.reason.record_upload_fail 1366105561158 Sync.Status DEBUG Status.service: error.sync.failed => error.sync.failed_partial 1366105561158 Sync.ErrorHandler DEBUG history failed: "server issue: database is not healthy" No traceback available 1366105561158 Sync.Synchronizer INFO Aborting sync for failure in history 1366105561158 Sync.Synchronizer INFO Sync completed at 2013-04-16 11:46:01 after 53.82 secs. 1366105561159 Sync.SyncScheduler DEBUG Starting client-initiated backoff. Next sync in 1367272 ms. 1366105561159 Sync.SyncScheduler DEBUG Next sync in 1367272 ms. 1366105561159 Sync.ErrorHandler DEBUG Some engines did not sync correctly.
Sync seems to be working correctly for me since about the time I posted comment 3. :djc, from the logs it looks like you're having a different issue ("database is not healthy")
I'm having these infobars pop up, too. Here's the most recent sync-log content: 1366130154835 Sync.ErrorHandler DEBUG Flushing file log. 1366130154879 Sync.Status DEBUG Status.service: error.sync.failed_partial => success.status_ok 1366130154879 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366130154880 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366130154905 Sync.ErrorHandler DEBUG Log cleanup threshold time: 1365266154904 1366130154910 Sync.ErrorHandler DEBUG No logs to clean up. 1366130155971 Sync.Tracker.History DEBUG Saving changed IDs to history 1366130156012 Sync.Tracker.Passwords DEBUG Saving changed IDs to passwords 1366133333467 Sync.Tracker.History DEBUG Saving changed IDs to history 1366133445434 Sync.Tracker.History DEBUG Saving changed IDs to history 1366133740628 Sync.Tracker.History DEBUG Saving changed IDs to history 1366133749889 Sync.Tracker.History DEBUG Saving changed IDs to history 1366133754835 Sync.Service DEBUG User-Agent: Firefox/23.0a1 FxSync/1.25.0.20130415030812. 1366133754836 Sync.Service INFO Starting sync at 2013-04-16 10:35:54 1366133754836 Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. 1366133754837 Sync.Status INFO Resetting Status. 1366133754837 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366133755623 Sync.Resource DEBUG mesg: GET success 200 https://phx-sync045.services.mozilla.com/1.1/kwierso/info/collections 1366133755623 Sync.Resource DEBUG GET success 200 https://phx-sync045.services.mozilla.com/1.1/kwierso/info/collections 1366133755624 Sync.Service DEBUG Fetching global metadata record 1366133755624 Sync.Service DEBUG Weave Version: 1.25.0 Local Storage: 5 Remote Storage: 5 1366133755624 Sync.Service INFO Sync key is up-to-date: no need to upgrade. 1366133755624 Sync.Service DEBUG Fetching and verifying -- or generating -- symmetric keys. 1366133755624 Sync.Service INFO Testing info/collections: {"passwords":1366132827.7,"clients":1366080443.44,"crypto":1365889125.64,"forms":1366132519.1,"meta":1365890370.9,"bookmarks":1365966376.12,"prefs":1366110586.18,"history":1366129856.03} 1366133755624 Sync.CollectionKeyManager INFO Testing for updateNeeded. Last modified: 1365889125.64 1366133755624 Sync.Synchronizer DEBUG Refreshing client list. 1366133755625 Sync.Engine.Clients INFO 0 outgoing items pre-reconciliation 1366133755626 Sync.Engine.Clients INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366133755626 Sync.Synchronizer INFO Updating enabled engines: 3 clients. 1366133755627 Sync.Engine.Bookmarks INFO 0 outgoing items pre-reconciliation 1366133755628 Sync.Engine.Bookmarks INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366133755630 Sync.Engine.Forms INFO 0 outgoing items pre-reconciliation 1366133756625 Sync.Tracker.Clients DEBUG Saving changed IDs to clients 1366133756629 Sync.Tracker.Bookmarks DEBUG Saving changed IDs to bookmarks 1366133756631 Sync.Tracker.Forms DEBUG Saving changed IDs to forms 1366133776791 Sync.Collection DEBUG mesg: GET success 200 https://phx-sync045.services.mozilla.com/1.1/kwierso/storage/forms?newer=1366100926.41&full=1 1366133776791 Sync.Collection DEBUG GET success 200 https://phx-sync045.services.mozilla.com/1.1/kwierso/storage/forms?newer=1366100926.41&full=1 1366133776857 Sync.Engine.Forms INFO Records: 1 applied, 1 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366133776858 Sync.Engine.History INFO 4751 outgoing items pre-reconciliation 1366133776950 Sync.SyncScheduler DEBUG Next sync in 3600000 ms. 1366133777892 Sync.Tracker.History DEBUG Saving changed IDs to history 1366133784879 Sync.Tracker.History DEBUG Saving changed IDs to history 1366133806609 Sync.Tracker.History DEBUG Saving changed IDs to history 1366133823679 Sync.Tracker.History DEBUG Saving changed IDs to history 1366133826717 Sync.Tracker.History DEBUG Saving changed IDs to history 1366133830309 Sync.Tracker.History DEBUG Saving changed IDs to history 1366133891904 Sync.Engine.History WARN DATA LOSS: Both local and remote changes to record: AzaXPzy-0cPw 1366133892829 Sync.Engine.History WARN DATA LOSS: Both local and remote changes to record: GzwpsdXoTqdn 1366133892887 Sync.Engine.History WARN DATA LOSS: Both local and remote changes to record: SlJzI3O9AIMK 1366133892903 Sync.Engine.History WARN DATA LOSS: Both local and remote changes to record: _8uGw-Rc7H7L 1366133892918 Sync.Engine.History WARN DATA LOSS: Both local and remote changes to record: cmpeSAhebwpL 1366133892986 Sync.Collection DEBUG mesg: GET success 200 https://phx-sync045.services.mozilla.com/1.1/kwierso/storage/history?newer=1366119085.46&full=1 1366133892986 Sync.Collection DEBUG GET success 200 https://phx-sync045.services.mozilla.com/1.1/kwierso/storage/history?newer=1366119085.46&full=1 1366133893029 Sync.Engine.History INFO Records: 5 applied, 5 successfully, 0 failed to apply, 0 newly failed to apply, 95 reconciled. 1366133893282 Sync.Engine.History INFO Uploading 0 - 100 out of 4656 records 1366133893285 Sync.Collection DEBUG POST Length: 58579 1366133923734 Sync.Tracker.History DEBUG Saving changed IDs to history 1366134193379 Sync.Status DEBUG Status.sync: success.sync => error.login.reason.network 1366134193379 Sync.Status DEBUG Status.service: success.status_ok => error.sync.failed 1366134193379 Sync.Status DEBUG Status for engine history: error.engine.reason.unknown_fail 1366134193379 Sync.Status DEBUG Status.service: error.sync.failed => error.sync.failed_partial 1366134193379 Sync.ErrorHandler DEBUG history failed: Aborting due to channel inactivity. JS Stack trace: Res_post@resource.js:427 < @engines.js:1247 < innerBind@util.js:554 < SyncEngine__uploadOutgoing@engines.js:1288 < SyncEngine__sync@engines.js:1345 < WrappedNotify@util.js:142 < Engine_sync@engines.js:520 < _syncEngine@enginesync.js:192 < sync@enginesync.js:147 < onNotify@service.js:1193 < WrappedNotify@util.js:142 < WrappedLock@util.js:97 < _lockedSync@service.js:1187 < @service.js:1178 < WrappedCatch@util.js:71 < sync@service.js:1166 1366134193380 Sync.Engine.Passwords INFO 0 outgoing items pre-reconciliation 1366134194379 Sync.Tracker.History DEBUG Saving changed IDs to history 1366134194382 Sync.Tracker.Passwords DEBUG Saving changed IDs to passwords 1366134219134 Sync.Collection DEBUG mesg: GET success 200 https://phx-sync045.services.mozilla.com/1.1/kwierso/storage/passwords?newer=1366082637.2&full=1 1366134219134 Sync.Collection DEBUG GET success 200 https://phx-sync045.services.mozilla.com/1.1/kwierso/storage/passwords?newer=1366082637.2&full=1 1366134219134 Sync.Engine.Passwords INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 1 reconciled. 1366134219135 Sync.Engine.Prefs INFO 0 outgoing items pre-reconciliation 1366134219136 Sync.Engine.Prefs INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366134219136 Sync.Synchronizer INFO Sync completed at 2013-04-16 10:43:39 after 464.30 secs. 1366134219136 Sync.SyncScheduler DEBUG Next sync in 3600000 ms. 1366134219136 Sync.ErrorHandler DEBUG Some engines did not sync correctly. There are other variants of this where it fails in forms instead of history.
I was wrong - I am still seeing this problem. Apparently I'm just staring at the console enough that I didn't notice the gray bars. 1366146702366 Sync.ErrorHandler DEBUG Flushing file log. 1366146702389 Sync.Status DEBUG Status.service: error.sync.failed_partial => success.status_ok 1366146702389 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702389 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702389 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702390 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702390 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702390 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702390 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702391 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702391 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702391 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702391 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702392 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702392 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702392 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702392 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702393 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702393 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702393 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702393 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702393 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702394 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702394 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702394 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702394 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702394 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702395 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702395 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702395 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702395 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702395 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702396 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702396 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366146702429 Sync.ErrorHandler DEBUG Log cleanup threshold time: 1365282702429 1366146702432 Sync.ErrorHandler DEBUG No logs to clean up. 1366150302295 Sync.Service DEBUG User-Agent: Firefox/20.0 FxSync/1.22.0.20130326150557. 1366150302295 Sync.Service INFO Starting sync at 2013-04-16 18:11:42 1366150302300 Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. 1366150302300 Sync.Status INFO Resetting Status. 1366150302300 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1366150303310 Sync.Resource DEBUG mesg: GET success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/info/collections 1366150303310 Sync.Resource DEBUG GET success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/info/collections 1366150303310 Sync.Service DEBUG Fetching global metadata record 1366150303310 Sync.Service DEBUG Weave Version: 1.22.0 Local Storage: 5 Remote Storage: 5 1366150303310 Sync.Service INFO Sync key is up-to-date: no need to upgrade. 1366150303311 Sync.Service DEBUG Fetching and verifying -- or generating -- symmetric keys. 1366150303311 Sync.Service INFO Testing info/collections: {"passwords":1366035849.99,"addons":1365776415.84,"tabs":1366147011.21,"clients":1365803220.51,"crypto":1365770362.13,"forms":1366065236.61,"meta":1365770744.2,"bookmarks":1365816048.66,"prefs":1365788730.8,"history":1366146401.39} 1366150303311 Sync.CollectionKeyManager INFO Testing for updateNeeded. Last modified: 1365770362.13 1366150303311 Sync.Synchronizer DEBUG Refreshing client list. 1366150303311 Sync.Engine.Clients INFO 0 outgoing items pre-reconciliation 1366150303312 Sync.Engine.Clients INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366150303312 Sync.Synchronizer INFO Updating enabled engines: 3 clients. 1366150303314 Sync.Engine.Bookmarks INFO 0 outgoing items pre-reconciliation 1366150303314 Sync.Engine.Bookmarks INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366150303316 Sync.Engine.Forms INFO 0 outgoing items pre-reconciliation 1366150303316 Sync.Engine.Forms INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366150303317 Sync.Engine.History INFO 41 outgoing items pre-reconciliation 1366150303317 Sync.Engine.History INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366150303394 Sync.Engine.History INFO Uploading all of 41 records 1366150303395 Sync.Collection DEBUG POST Length: 28372 1366150304450 Sync.Collection DEBUG mesg: POST success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/storage/history 1366150304450 Sync.Collection DEBUG POST success 200 https://phx-sync121.services.mozilla.com/1.1/djmitche/storage/history 1366150304452 Sync.Engine.Passwords INFO 0 outgoing items pre-reconciliation 1366150304453 Sync.Engine.Passwords INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366150304453 Sync.Engine.Prefs INFO 0 outgoing items pre-reconciliation 1366150304454 Sync.Engine.Prefs INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366150304455 Sync.Engine.Tabs INFO 1 outgoing items pre-reconciliation 1366150350435 Sync.Status DEBUG Status for engine tabs: error.engine.reason.unknown_fail 1366150350435 Sync.Status DEBUG Status.service: success.status_ok => error.sync.failed_partial 1366150350435 Sync.ErrorHandler DEBUG tabs failed: NS_ERROR_FAILURE JS Stack trace: Res_get@resource.js:413 < @engines.js:931 < SyncEngine__sync@engines.js:1342 < WrappedNotify@util.js:142 < Engine_sync@engines.js:519 < _syncEngine@enginesync.js:192 < sync@enginesync.js:147 < onNotify@service.js:1185 < WrappedNotify@util.js:142 < WrappedLock@util.js:97 < _lockedSync@service.js:1179 < @service.js:1170 < WrappedCatch@util.js:71 < sync@service.js:1158 1366150350436 Sync.Engine.Addons DEBUG Refreshing reconciler state 1366150350436 Sync.AddonsReconciler INFO Refreshing global state from AddonManager. 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: compatibility@addons.mozilla.org 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: hidefindbar@jaredmcateer.com 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: jid0-qBnIpLfDFa4LpdrjhAC6vBqN20Q@jetpack 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: masspasswordreset@johnathan.nightingale 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: new-tabs-at-end@forerunnerdesigns.com 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: old-lion-fullscreen@flyingtealeaf.com 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: openwebapps@mozillalabs.com 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: perlformatter@aivector.com 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: {96118df2-0d02-4dbc-9ad5-98995dc7d977} 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: jid0-NgMDcEu2B88AbzZ6ulHodW9sJzA@jetpack 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: firebug@software.joehewitt.com 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: jid1-0LUk0G25IhTJ0g@jetpack 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: {c0c588b6-b11d-4898-af00-079fed05aa32} 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: {972ce4c6-7e08-4474-a285-3208198ce6fd} 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: skipcerterror@foudil.fr 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: {8f8fe09b-0bd3-4470-bc1b-8cad42b8203a} 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: {d10d0bf8-f5b5-c8b4-a8b2-2b9879e08c5d} 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: 360072@personas.mozilla.org 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: 54707@personas.mozilla.org 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: {f7bc8076-12cd-09c3-7f36-94287a9880f9} 1366150350494 Sync.AddonsReconciler DEBUG Rectifying state for addon: {477826d8-03c2-5b5f-59fc-d0ff7462f6b5} 1366150350495 Sync.AddonsReconciler DEBUG Rectifying state for addon: {847b0e9f-cbcf-443c-c9ff-cce5ce6a1de7} 1366150350495 Sync.AddonsReconciler DEBUG Rectifying state for addon: {b14169e2-11ed-f9d5-279a-9754401447dd} 1366150350495 Sync.AddonsReconciler DEBUG Rectifying state for addon: {07b90314-1e79-c84a-4b47-fb7e1853be39} 1366150350495 Sync.AddonsReconciler DEBUG Rectifying state for addon: {d95f2237-07c7-b389-7956-65e6f1ce8e0a} 1366150350495 Sync.AddonsReconciler DEBUG Rectifying state for addon: {0bc151fc-4895-269c-2acf-f91a439f6804} 1366150350495 Sync.AddonsReconciler DEBUG Rectifying state for addon: {127ff364-3b9e-f80e-7d7e-e7b461a317a9} 1366150350495 Sync.AddonsReconciler DEBUG Rectifying state for addon: {97509d10-2acb-f507-9f5e-786b9ad26665} 1366150350495 Sync.AddonsReconciler DEBUG Rectifying state for addon: {5ea60f7e-7eef-6fb6-03fc-6bb8b4b1aed4} 1366150350497 Sync.AddonsReconciler INFO Saving reconciler state to file: addonsreconciler 1366150350551 Sync.Engine.Addons INFO 0 outgoing items pre-reconciliation 1366150350552 Sync.Engine.Addons INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1366150350552 Sync.Synchronizer INFO Sync completed at 2013-04-16 18:12:30 after 48.25 secs. 1366150350552 Sync.SyncScheduler DEBUG Next sync in 3600000 ms. 1366150350552 Sync.ErrorHandler DEBUG Some engines did not sync correctly. (looks like about three such failures per day per browser instance)
Summary: sync failing since yesterday → sync failing since April 10
So, this is still failing. I don't know if providing additional logs helps. I don't know what I'm looking for. But in the interim, I basically have no sync between my various Firefox instances, which is impeding my work. Can I be helpful, or should I close this as INVALID and just get along without sync until the underlying problem is fixed?
See if unchecking "tabs" in Sync preferences, waiting a little while, then re-checking it allows things to proceed. It's possible that you're seeing something that isn't part of the ongoing service disruption.
"Tabs" isn't checked.
It was in your April 16 log. New log, please!
Ah, sorry, I bet that was from a different system (laptop). Here on my desktop: 1370255951127 Sync.ErrorHandler DEBUG Flushing file log. 1370255951129 Sync.Status DEBUG Status.sync: error.login.reason.network => error.sync.prolonged_failure 1370255951129 Sync.Status DEBUG Status.service: error.sync.failed_partial => error.sync.failed 1370255951139 Sync.Status DEBUG Status.service: error.sync.failed => success.status_ok 1370255951144 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1370255951642 Sync.ErrorHandler DEBUG Log cleanup threshold time: 1369391951642 1370255952158 Sync.Tracker.History DEBUG Saving changed IDs to history 1370255952159 Sync.ErrorHandler DEBUG Done deleting files. 1370272629019 Sync.Tracker.Passwords DEBUG Saving changed IDs to passwords 1370272629717 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272630988 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272650145 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272654276 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272656129 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272661815 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272673566 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272687313 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272727987 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272753289 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272888843 Sync.Tracker.History DEBUG Saving changed IDs to history 1370272896167 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273002578 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273003882 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273009266 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273642391 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273731853 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273733990 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273774733 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273776802 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273779034 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273791232 Sync.Tracker.History DEBUG Saving changed IDs to history 1370273804226 Sync.Tracker.History DEBUG Saving changed IDs to history 1370274196351 Sync.Tracker.History DEBUG Saving changed IDs to history 1370274198683 Sync.Tracker.History DEBUG Saving changed IDs to history 1370274424729 Sync.ErrorHandler DEBUG Beginning user-triggered sync. 1370274424741 Sync.Service DEBUG User-Agent: Firefox/21.0 FxSync/1.23.0.20130511120803. 1370274424741 Sync.Service INFO Starting sync at 2013-06-03 11:47:04 1370274424742 Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. 1370274424742 Sync.Status INFO Resetting Status. 1370274424742 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1370274425241 Sync.Resource DEBUG mesg: GET success 200 https://phx-sync604.services.mozilla.com/1.1/djmitche/info/collections 1370274425241 Sync.Resource DEBUG GET success 200 https://phx-sync604.services.mozilla.com/1.1/djmitche/info/collections 1370274425241 Sync.Resource DEBUG Got X-Weave-Backoff: 43200 1370274425242 Sync.SyncScheduler DEBUG Got backoff notification: 43200000ms 1370274425242 Sync.SyncScheduler DEBUG Fuzzed minimum next sync: 1370317625242 1370274425242 Sync.Service DEBUG Fetching global metadata record 1370274425242 Sync.Service DEBUG Weave Version: 1.23.0 Local Storage: 5 Remote Storage: 5 1370274425243 Sync.Service INFO Sync key is up-to-date: no need to upgrade. 1370274425243 Sync.Service DEBUG Fetching and verifying -- or generating -- symmetric keys. 1370274425243 Sync.Service INFO Testing info/collections: {"clients":1370182003.82,"crypto":1369746879.19,"forms":1370202974.36,"meta":1369747568.57,"bookmarks":1369887123.62,"history":1370255651.45} 1370274425243 Sync.CollectionKeyManager INFO Testing for updateNeeded. Last modified: 1369746879.19 1370274425243 Sync.Synchronizer DEBUG Refreshing client list. 1370274425244 Sync.Engine.Clients INFO 0 outgoing items pre-reconciliation 1370274425245 Sync.Engine.Clients INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1370274425245 Sync.Synchronizer INFO Updating enabled engines: 3 clients. 1370274425247 Sync.Engine.Bookmarks INFO 0 outgoing items pre-reconciliation 1370274425248 Sync.Engine.Bookmarks INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1370274425249 Sync.Engine.Forms INFO 0 outgoing items pre-reconciliation 1370274425250 Sync.Engine.Forms INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1370274425251 Sync.Engine.History INFO 439 outgoing items pre-reconciliation 1370274426250 Sync.Tracker.Clients DEBUG Saving changed IDs to clients 1370274426252 Sync.Tracker.Bookmarks DEBUG Saving changed IDs to bookmarks 1370274426253 Sync.Tracker.Forms DEBUG Saving changed IDs to forms 1370274426254 Sync.Tracker.History DEBUG Saving changed IDs to history 1370274426980 Sync.SyncScheduler DEBUG Next sync in 44936148.927955836 ms. 1370274431511 Sync.Tracker.History DEBUG Saving changed IDs to history 1370274435746 Sync.Tracker.History DEBUG Saving changed IDs to history 1370274569932 Sync.Collection DEBUG mesg: GET success 200 https://phx-sync604.services.mozilla.com/1.1/djmitche/storage/history?newer=1370203291.7&full=1 1370274569932 Sync.Collection DEBUG GET success 200 https://phx-sync604.services.mozilla.com/1.1/djmitche/storage/history?newer=1370203291.7&full=1 1370274569932 Sync.Collection DEBUG Got X-Weave-Backoff: 43200 1370274569932 Sync.SyncScheduler DEBUG Got backoff notification: 43200000ms 1370274569932 Sync.SyncScheduler DEBUG Fuzzed minimum next sync: 1370317769932 1370274569932 Sync.Engine.History INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 100 reconciled. 1370274570104 Sync.Engine.History INFO Uploading 0 - 100 out of 341 records 1370274570107 Sync.Collection DEBUG POST Length: 65934 1370274756364 Sync.Tracker.History DEBUG Saving changed IDs to history 1370274779168 Sync.Tracker.History DEBUG Saving changed IDs to history 1370274782297 Sync.Tracker.History DEBUG Saving changed IDs to history 1370274870111 Sync.Status DEBUG Status.sync: success.sync => error.login.reason.network 1370274870111 Sync.Status DEBUG Status.service: success.status_ok => error.sync.failed 1370274870111 Sync.Status DEBUG Status for engine history: error.engine.reason.unknown_fail 1370274870111 Sync.Status DEBUG Status.service: error.sync.failed => error.sync.failed_partial 1370274870111 Sync.ErrorHandler DEBUG history failed: Aborting due to channel inactivity. JS Stack trace: Res_post@resource.js:427 < @engines.js:1247 < innerBind@util.js:554 < SyncEngine__uploadOutgoing@engines.js:1288 < SyncEngine__sync@engines.js:1345 < WrappedNotify@util.js:142 < Engine_sync@engines.js:520 < _syncEngine@enginesync.js:192 < sync@enginesync.js:147 < onNotify@service.js:1193 < WrappedNotify@util.js:142 < WrappedLock@util.js:97 < _lockedSync@service.js:1187 < @service.js:1178 < WrappedCatch@util.js:71 < sync@service.js:1166 1370274870111 Sync.Synchronizer INFO Sync completed at 2013-06-03 11:54:30 after 445.37 secs. 1370274870112 Sync.SyncScheduler DEBUG Next sync in 50468671.50270731 ms. 1370274870112 Sync.ErrorHandler DEBUG Some engines did not sync correctly.
Server is buckling under the load of your history upload, by the look of it.
Oops! If I turn that off, sync succesfully, and then turn it back on, will that be better?
It's likely to finish syncing if you turn it off. Whether it continues to work after you turn it back on -- which requires uploading all of your history again -- is another matter. Worth a shot, though.
We should be golden now. Infra has been restored to working order, and new hardware is on the way. sync30.db was serviced last week, so if you are encountering any new errors, please reopen the bug with a pastebin of your latest Sync debug output
Assignee: nobody → jlaz
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.