Closed Bug 1060850 Opened 10 years ago Closed 10 years ago

Sync not possible- Post fail 503

Categories

(Firefox :: Sync, defect)

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

Tracking

()

Status:
RESOLVED FIXED

People

(Reporter: lagu, Unassigned)

Details

User Agent: Mozilla/5.0 (Windows NT 6.3; WOW64; rv:34.0) Gecko/20100101 Firefox/34.0 (Beta/Release)
Build ID: 20140829030204

Steps to reproduce:

Sync is not possible. I have serveral error-logs.

1409328232879	Sync.BrowserIDManager	INFO	currentAuthState returning error.login.reason.network due to previous failure
1409328232879	Sync.Status	DEBUG	Status.login: success.login => error.login.reason.network
1409328232879	Sync.Status	DEBUG	Status.service: success.status_ok => error.login.failed
1409328233873	Sync.Tracker.Addons	DEBUG	Saving changed IDs to addons
1409328233875	Sync.Tracker.Greasemonkey	DEBUG	Saving changed IDs to greasemonkey
1409328407525	Sync.Tracker.History	DEBUG	Saving changed IDs to history
1409328832879	Sync.Service	DEBUG	User-Agent: Firefox/34.0a1 FxSync/1.36.0.20140827030202.
1409328832879	Sync.Service	INFO	Starting sync at 2014-08-29 18:13:52
1409328832881	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1409328832881	Sync.Status	INFO	Resetting Status.
1409328832881	Sync.Status	DEBUG	Status.service: error.login.failed => success.status_ok
1409328832882	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1409328834184	Sync.Resource	DEBUG	mesg: GET success 200 https://sync-34-us-west-2.sync.services.mozilla.com/1.5/1130549/info/collections
1409328834184	Sync.Resource	DEBUG	GET success 200 https://sync-34-us-west-2.sync.services.mozilla.com/1.5/1130549/info/collections
1409328834186	Sync.Service	DEBUG	Fetching global metadata record
1409328834186	Sync.Service	DEBUG	Weave Version: 1.36.0 Local Storage: 5 Remote Storage: 5
1409328834186	Sync.Service	INFO	Sync key is up-to-date: no need to upgrade.
1409328834186	Sync.Service	DEBUG	Fetching and verifying -- or generating -- symmetric keys.
1409328834186	Sync.Service	INFO	Testing info/collections: {"passwords":1408798106.1,"addons":1408907717.43,"tabs":1409328233.34,"clients":1409246545.19,"crypto":1400033537.25,"forms":1409321316.18,"meta":1408044107.55,"bookmarks":1408052563.8,"prefs":1409170396.01,"greasemonkey":1409253433.93,"history":1409328231.94}
1409328834186	Sync.CollectionKeyManager	INFO	Testing for updateNeeded. Last modified: 1400033537.25
1409328834186	Sync.Synchronizer	DEBUG	Refreshing client list.
1409328834187	Sync.Engine.Clients	INFO	0 outgoing items pre-reconciliation
1409328834187	Sync.Engine.Clients	INFO	Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled.
1409328834188	Sync.Synchronizer	INFO	Updating enabled engines: 5 clients.
1409328834190	Sync.Engine.Bookmarks	INFO	0 outgoing items pre-reconciliation
1409328834194	Sync.Engine.Bookmarks	INFO	Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled.
1409328834197	Sync.Engine.Forms	INFO	0 outgoing items pre-reconciliation
1409328834197	Sync.Engine.Forms	INFO	Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled.
1409328834198	Sync.Engine.History	INFO	1 outgoing items pre-reconciliation
1409328834199	Sync.Engine.History	INFO	Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled.
1409328834206	Sync.Engine.History	INFO	Uploading all of 1 records
1409328834206	Sync.BrowserIDManager	DEBUG	_ensureValidToken already has one
1409328834207	Sync.Collection	DEBUG	POST Length: 843
1409328835187	Sync.Tracker.Clients	DEBUG	Saving changed IDs to clients
1409328835193	Sync.Tracker.Bookmarks	DEBUG	Saving changed IDs to bookmarks
1409328835197	Sync.Tracker.Forms	DEBUG	Saving changed IDs to forms
1409328835199	Sync.Tracker.History	DEBUG	Saving changed IDs to history
1409328835220	Sync.Collection	DEBUG	mesg: POST fail 503 https://sync-34-us-west-2.sync.services.mozilla.com/1.5/1130549/storage/history
1409328835220	Sync.Collection	DEBUG	POST fail 503 https://sync-34-us-west-2.sync.services.mozilla.com/1.5/1130549/storage/history
1409328835220	Sync.Engine.History	DEBUG	Uploading records failed: <html>
<head><title>503 Service Unavailable</title></head>
<body bgcolor="white">
<center><h1>503 Service Cloudy: Try again later. </h1></center>
</body>
</html>

1409328835221	Sync.ErrorHandler	DEBUG	Got Retry-After: 3600
1409328835221	Sync.Status	DEBUG	Status.sync: success.sync => error.sync.reason.serverMaintenance
1409328835221	Sync.Status	DEBUG	Status.service: success.status_ok => error.sync.failed
1409328835221	Sync.SyncScheduler	DEBUG	Got backoff notification: 3600000ms
1409328835221	Sync.SyncScheduler	DEBUG	Fuzzed minimum next sync: 1409332435221
1409328835221	Sync.Status	DEBUG	Status for engine history: error.engine.reason.record_upload_fail
1409328835221	Sync.Status	DEBUG	Status.service: error.sync.failed => error.sync.failed_partial
1409328835221	Sync.ErrorHandler	DEBUG	history failed: <html>
<head><title>503 Service Unavailable</title></head>
<body bgcolor="white">
<center><h1>503 Service Cloudy: Try again later. </h1></center>
</body>
</html>
 No traceback available
1409328835221	Sync.Synchronizer	INFO	Aborting sync for failure in history
1409328835221	Sync.Synchronizer	INFO	Sync completed at 2014-08-29 18:13:55 after 2.34 secs.
1409328835222	Sync.Declined	DEBUG	Handling remote declined: []
1409328835222	Sync.Declined	DEBUG	Handling local declined: []
1409328835222	Sync.Declined	DEBUG	Declined changed? false
1409328835223	Sync.Service	INFO	No change to declined engines. Not reuploading meta/global.
1409328835223	Sync.SyncScheduler	DEBUG	Starting client-initiated backoff. Next sync in 4167372.950409165 ms.
1409328835223	Sync.SyncScheduler	DEBUG	Next sync in 4167372.950409165 ms.
1409328835224	Sync.ErrorHandler	DEBUG	Some engines did not sync correctly.
File:error-1408527712548.txt
	3 KB 	20.08.2014 	11:41:52
File:error-1408527712561.txt
	2 KB 	20.08.2014 	11:41:52
File:error-1408548907795.txt
	17 KB 	20.08.2014 	17:35:07
File:error-1408548907966.txt
	2 KB 	20.08.2014 	17:35:08
File:error-1408550713524.txt
	6 KB 	20.08.2014 	18:05:13
File:error-1408567341174.txt
	6 KB 	20.08.2014 	22:42:21
File:error-1408614794390.txt
	3 KB 	21.08.2014 	11:53:14
File:error-1408614794472.txt
	2 KB 	21.08.2014 	11:53:14
File:error-1408784152432.txt
	22 KB 	23.08.2014 	10:55:52
File:error-1408784152487.txt
	1 KB 	23.08.2014 	10:55:52
File:error-1408784168737.txt
	17 KB 	23.08.2014 	10:56:08
File:error-1408784168768.txt
	1 KB 	23.08.2014 	10:56:08
File:error-1409018176149.txt
	16 KB 	26.08.2014 	03:56:16
File:error-1409018176565.txt
	1 KB 	26.08.2014 	03:56:16
File:error-1409027417557.txt
	17 KB 	26.08.2014 	06:30:17
File:error-1409027417662.txt
	1 KB 	26.08.2014 	06:30:17
File:error-1409072202406.txt
	17 KB 	26.08.2014 	18:56:42
File:error-1409072203603.txt
	1 KB 	26.08.2014 	18:56:43
File:error-1409084276212.txt
	2 KB 	26.08.2014 	22:17:56
File:error-1409276930936.txt
	17 KB 	29.08.2014 	03:48:50
File:error-1409276930954.txt
	1 KB 	29.08.2014 	03:48:51
File:error-1409328835224.txt
	6 KB 	29.08.2014 	18:13:55
If further info's needed, pls needinfo me
I believe that the sync-34 node had some capacity issues recently, which would explain why you're seeing these 503 errors.  Bob can you confirm the circumstances under which we'd see this "503 Service Cloudy" from (I presume) nginx?
Flags: needinfo?(bobm)
The server logs show quite a few successful requests for your userid, in addition to the errors.  In particular I see no errors for the past few days, but several successful POST requests to e.g. the history collection.

Lars, does sync seem to be working sometimes for you, or does it always give an error?
Flags: needinfo?(lars.gusowski+bugzilla)
Is there local any log where i could see if it is working?
Or do i need to check if something is sucessfully synchronized.
Should i create for the test a new Sync-Account?
Flags: needinfo?(lars.gusowski+bugzilla) → needinfo?(rfkelly)
In "about:config" you can search for "logOnSuccess" and toggle it to true, this will produce logs for successful sync as well as unsuccessful ones.
Flags: needinfo?(rfkelly)
Will check it and come back with info.
Flags: needinfo?(lars.gusowski+bugzilla)
File:success-1409586161556.txt	18 KB 	01.09.2014 	17:42:41
File:success-1409586763739.txt	19 KB 	01.09.2014 	17:52:43
File:success-1409587472805.txt	18 KB 	01.09.2014 	18:04:32

At the moment it is sucessfull. It seems that there are "only" server error's due capacity issues
Flags: needinfo?(lars.gusowski+bugzilla)
OK, that's good to hear, thanks for checking.  I'll let Bob weigh in on the current status of sync-34 but other than that, I don't think there's much more we can do in this bug.
(In reply to Ryan Kelly [:rfkelly] from comment #9)
> OK, that's good to hear, thanks for checking.  I'll let Bob weigh in on the
> current status of sync-34 but other than that, I don't think there's much
> more we can do in this bug.

The sync-34 node users will be migrated and the node decommissioned by the end of the day.
Flags: needinfo?(bobm)
FYI: i was sucessfull migrated to a new node (98-us-west)
Great, hopefully all is well on the new node - closing this out
Status: UNCONFIRMED → RESOLVED
Closed: 10 years ago
Resolution: --- → FIXED
Component: Firefox Sync: Backend → Sync
Product: Cloud Services → Firefox
You need to log in before you can comment on or make changes to this bug.