Receiving 503s from reading list prod endpoint

RESOLVED FIXED

Status

Cloud Services
Server: ReadingList
RESOLVED FIXED
3 years ago
3 years ago

People

(Reporter: Margaret, Assigned: tarek)

Tracking

Firefox Tracking Flags

(Not tracked)

Details

(Reporter)

Description

3 years ago
From my Android log:

I/FxReadingList(21147): fennec :: ReadingListSyncAdapter :: Syncing reading list against endpoint: https://readinglist.services.mozilla.com/v1/
W/FxReadingList(21147): fennec :: ReadingListClient :: Upload got failure response HTTP/1.1 503 Service Temporarily Unavailable
Bob, does this look like a load issue or something more pernicious? I know the French crew are off today, so maybe you could front-load the investigation for them.
Flags: needinfo?(bobm)
I'm seeing 503s from Desktop too:


1428339087107	readinglist.sync	DEBUG	Phase 1 part 2: Uploading new items
1428339087110	readinglist.sync	DEBUG	Sending request: {"method":"POST","path":"/batch","body":{"defaults":{"method":"POST","path":"/articles"},"requests":[{"body":{"url":"https://phonebook.mozilla.org/","title":"Mozilla Phonebook","resolved_url":"https://phonebook.mozilla.org/","resolved_title":null,"excerpt":null,"favorite":null,"is_article":null,"word_count":null,"unread":null,"added_by":"gavin's Nightly on gavin-mbp","added_on":1428339087088,"marked_read_by":null,"marked_read_on":null,"read_position":null,"preview":"https://phonebook.mozilla.org//pic.php?mail=frashed@mozilla.com&type=thumb"}}]}}
1428339087110	FirefoxAccounts	DEBUG	getOAuthToken enter
1428339087120	FirefoxAccounts	DEBUG	getOAuthToken returning a cached token
1428339087120	readinglist.serverclient	DEBUG	dispatching request to: https://readinglist.services.mozilla.com/v1/batch
1428339132107	readinglist.api	DEBUG	Deleting item with guid: ${guid}, url: ${url}
1428339132108	readinglist.api	DEBUG	Item is new, truly deleting it: {"guid":null,"serverLastModified":null,"url":"https://phonebook.mozilla.org/","preview":"https://phonebook.mozilla.org//pic.php?mail=frashed@mozilla.com&type=thumb","title":"Mozilla Phonebook","resolvedURL":"https://phonebook.mozilla.org/","resolvedTitle":null,"excerpt":null,"archived":null,"deleted":null,"favorite":null,"isArticle":null,"wordCount":null,"unread":null,"addedBy":"gavin's Nightly on gavin-mbp","addedOn":1428339087088,"storedOn":null,"markedReadBy":null,"markedReadOn":null,"readPosition":null,"syncStatus":1}
1428339147470	readinglist.serverclient	DEBUG	received response status: 503 Service Temporarily Unavailable
1428339147471	readinglist.serverclient	INFO	Failed to parse JSON body |<html>
<head><title>503 Service Unavailable</title></head>
<body bgcolor="white">
<center><h1>503 Service Cloudy: Try again later. </h1></center>
</body>
</html>
|: SyntaxError: JSON.parse: unexpected character at line 1 column 1 of the JSON data (resource:///modules/readinglist/ServerClient.jsm:144:26) JS Stack trace: _rawRequest/</request.onComplete@ServerClient.jsm:144:27 < onStopRequest@rest.js:481:5
1428339147471	readinglist.serverclient	DEBUG	initial request got status 503
1428339147471	readinglist.sync	DEBUG	Received response: {"status":503,"headers":{"date":"Mon, 06 Apr 2015 16:52:27 GMT","content-type":"text/html","content-length":"162","connection":"keep-alive","etag":"\"5513a69a-a2\""}}
1428339147471	readinglist.sync	ERROR	Unexpected response uploading new items: {"status":503,"headers":{"date":"Mon, 06 Apr 2015 16:52:27 GMT","content-type":"text/html","content-length":"162","connection":"keep-alive","etag":"\"5513a69a-a2\""}}
I filed Bug 1151521 for desktop to not complain on non-JSON responses, btw.
(In reply to Richard Newman [:rnewman] from comment #1)
> Bob, does this look like a load issue or something more pernicious? I know
> the French crew are off today, so maybe you could front-load the
> investigation for them.

I think it's related to RDS max_connections, or the SQL connection pool.

Apr  3 02:52:06 ip-a-b-c-d uwsgi: /data/readinglist/lib/python2.7/site-packages/requests/packages/urllib3/util/ssl_.py:79: InsecurePlatformWarning: A true SSLContext object is not available. This prevents urllib3 from configuring SSL appropriately and may cause certain SSL connections to fail. For more information, see https://urllib3.readthedocs.org/en/latest/security.html#insecureplatformwarning.
Apr  3 02:52:06 ip-a-b-c-d uwsgi: InsecurePlatformWarning
Apr  3 02:52:06 ip-a-b-c-d uwsgi: 2015-04-03 02:52:06,393 ERROR [cliquet.storage.postgresql][uWSGIWorker1Core0] "POST  /v1/articles" ? (? ms) FATAL:  remaining connection slots are reserved for non-replication superuser connections
Apr  3 02:52:06 ip-a-b-c-d uwsgi: lang=None; auth_type=FxA; resource_name=article; uid=fxa_XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX; errno=None; agent=Firefox-Android-FxReader/40.0a1 (Nightly); resource_timestamp=142794298745
6
Apr  3 02:52:06 ip-a-b-c-d uwsgi: 2015-04-03 02:52:06,393 ERROR [cliquet.storage.postgresql][uWSGIWorker1Core0] "POST  /v1/articles" ? (? ms) FATAL:  remaining connection slots are reserved for non-replication superuser connections
Apr  3 02:52:06 ip-a-b-c-d uwsgi: lang=None; auth_type=FxA; resource_name=article; uid=fxa_XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX; errno=None; agent=Firefox-Android-FxReader/40.0a1 (Nightly); resource_timestamp=142794298745
6
Apr  3 02:52:06 ip-a-b-c-d uwsgi: 2015-04-03 02:52:06,397 CRITI [cliquet.storage.postgresql][uWSGIWorker1Core0] "POST  /v1/articles" ? (? ms) FATAL:  remaining connection slots are reserved for non-replication superuser connections
Apr  3 02:52:06 ip-a-b-c-d uwsgi: lang=None; auth_type=FxA; exception=Traceback (most recent call last):
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/tweens.py", line 21, in excview_tween
Apr  3 02:52:06 ip-a-b-c-d uwsgi: response = handler(request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/router.py", line 163, in handle_request
Apr  3 02:52:06 ip-a-b-c-d uwsgi: response = view_callable(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 596, in __call__
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return view(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 329, in attr_view
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return view(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 305, in predicate_wrapper
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return view(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 245, in _secured_view
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return view(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 355, in rendered_view
Apr  3 02:52:06 ip-a-b-c-d uwsgi: result = view(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 501, in _requestonly_view
Apr  3 02:52:06 ip-a-b-c-d uwsgi: response = view(request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cornice/service.py",line 548, in wrapper
Apr  3 02:52:06 ip-a-b-c-d uwsgi: response = view_()
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "./readinglist/views/article.py", line 129, in collection_post
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return super(Article, self).collection_post(*args, **kwargs)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/resource.py", line 129, in collection_post
Apr  3 02:52:06 ip-a-b-c-d uwsgi: record = self.create_record(new_record)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/resource.py", line 305, in create_record
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return self.db.create(record=record, **self.db_kwargs)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/statsd/client.py", line 30, in _wrapped
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return_value = f(*args, **kwargs)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/storage/postgresql/__init__.py", line 203, in create
Apr  3 02:52:06 ip-a-b-c-d uwsgi: self._check_unicity(cursor, resource, user_id, record)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/storage/post
gresql/__init__.py", line 599, in _check_unicity
Apr  3 02:52:06 ip-a-b-c-d uwsgi: existing = self.get(resource, user_id, result['id'])
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/statsd/client.py", line 30, in _wrapped
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return_value = f(*args, **kwargs)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/storage/postgresql/__init__.py", line 221, in get
Apr  3 02:52:06 ip-a-b-c-d uwsgi: with self.connect() as cursor:
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/usr/lib64/python2.7/contextlib.py", line 17, in __enter__
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return self.gen.next()
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/storage/postgresql/__init__.py", line 59, in connect
Apr  3 02:52:06 ip-a-b-c-d uwsgi: raise exceptions.BackendError(original=e)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: BackendError; resource_name=article; uid=fxa_XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX; errno=None; agent=Firefox-Android-FxReader/40.0a1 (Nightly); resource_timestamp=1427942987456
Apr  3 02:52:06 ip-a-b-c-d uwsgi: 2015-04-03 02:52:06,397 CRITI [cliquet.storage.postgresql][uWSGIWorker1Core0] "POST  /v1/articles" ? (? ms) FATAL:  remaining connection slots are reserved for non-replication superuser connections
Apr  3 02:52:06 ip-a-b-c-d uwsgi: lang=None; auth_type=FxA; exception=Traceback (most recent call last):
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/tweens.py",line 21, in excview_tween
Apr  3 02:52:06 ip-a-b-c-d uwsgi: response = handler(request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/router.py",line 163, in handle_request
Apr  3 02:52:06 ip-a-b-c-d uwsgi: response = view_callable(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 596, in __call__
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return view(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 329, in attr_view
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return view(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 305, in predicate_wrapper
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return view(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 245, in _secured_view
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return view(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 355, in rendered_view
Apr  3 02:52:06 ip-a-b-c-d uwsgi: result = view(context, request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/pyramid/config/views.py", line 501, in _requestonly_view
Apr  3 02:52:06 ip-a-b-c-d uwsgi: response = view(request)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cornice/service.py",line 548, in wrapper
Apr  3 02:52:06 ip-a-b-c-d uwsgi: response = view_()
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "./readinglist/views/article.py", line 129, in collection_post
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return super(Article, self).collection_post(*args, **kwargs)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/resource.py", line 129, in collection_post
Apr  3 02:52:06 ip-a-b-c-d uwsgi: record = self.create_record(new_record)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/resource.py", line 305, in create_record
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return self.db.create(record=record, **self.db_kwargs)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/statsd/client.py", line 30, in _wrapped
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return_value = f(*args, **kwargs)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/storage/postgresql/__init__.py", line 203, in create
Apr  3 02:52:06 ip-a-b-c-d uwsgi: self._check_unicity(cursor, resource, user_id, record)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/storage/postgresql/__init__.py", line 599, in _check_unicity
Apr  3 02:52:06 ip-a-b-c-d uwsgi: existing = self.get(resource, user_id, result['id'])
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/statsd/client.py", line 30, in _wrapped
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return_value = f(*args, **kwargs)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/storage/postgresql/__init__.py", line 221, in get
Apr  3 02:52:06 ip-a-b-c-d uwsgi: with self.connect() as cursor:
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/usr/lib64/python2.7/contextlib.py", line 17, in __enter__
Apr  3 02:52:06 ip-a-b-c-d uwsgi: return self.gen.next()
Apr  3 02:52:06 ip-a-b-c-d uwsgi: File "/data/readinglist/lib/python2.7/site-packages/cliquet/storage/postgresql/__init__.py", line 59, in connect
Apr  3 02:52:06 ip-a-b-c-d uwsgi: raise exceptions.BackendError(original=e)
Apr  3 02:52:06 ip-a-b-c-d uwsgi: BackendError; resource_name=article; uid=fxa_XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX; errno=None; agent=Firefox-Android-FxReader/40.0a1 (Nightly); resource_timestamp=1427942987456
Flags: needinfo?(bobm)
Thanks. This is a problem in our connection pooling, that was fixed in 1.5.x (the next release to come). The solution is to land 1.5.x and tweak the pool sizes so it's < the pgsql max_connections value
As discussed in the #taskcontinuity channel on IRC, we are going to fix this problem with the 1.5.0 deploy (Bug 1149259).
The 1.5.0 code has been deployed to production.
Deployment verified with a smoke test. Margaret can you try again ?
Flags: needinfo?(margaret.leibovic)
(Reporter)

Comment 9

3 years ago
(In reply to Tarek Ziadé (:tarek) from comment #8)
> Deployment verified with a smoke test. Margaret can you try again ?

I'm still not seeing synced reading list items appear on either of my Android devices, but I'm not seeing any reading list related errors in the log. 

However, I am seeing a lot of sync related errors. Could it be a client bug that regular sync problems are causing reading list sync problems?

E/GeckPasswordsProvider(32574): Error in NSSBridge
E/JavaBinder(32574): *** Uncaught remote exception!  (Exceptions are not yet supported across processes.)
E/JavaBinder(32574): java.lang.RuntimeException: java.lang.Exception: PK11SDR_Decrypt returned error 0: Success
E/JavaBinder(32574): 
E/JavaBinder(32574): 	at org.mozilla.gecko.db.PasswordsProvider.doCrypto(PasswordsProvider.java:247)
E/JavaBinder(32574): 	at org.mozilla.gecko.db.PasswordsProvider.onPostQuery$3e5a7f14(PasswordsProvider.java:310)
E/JavaBinder(32574): 	at org.mozilla.gecko.db.SQLiteBridgeContentProvider.query(SQLiteBridgeContentProvider.java:429)
E/JavaBinder(32574): 	at android.content.ContentProvider.query(ContentProvider.java:857)
E/JavaBinder(32574): 	at android.content.ContentProvider$Transport.query(ContentProvider.java:200)
E/JavaBinder(32574): 	at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:112)
E/JavaBinder(32574): 	at android.os.Binder.execTransact(Binder.java:404)
E/JavaBinder(32574): 	at dalvik.system.NativeStart.run(Native Method)
E/JavaBinder(32574): Caused by: java.lang.Exception: PK11SDR_Decrypt returned error 0: Success
E/JavaBinder(32574): 
E/JavaBinder(32574): 	at org.mozilla.gecko.NSSBridge.nativeDecrypt(Native Method)
E/JavaBinder(32574): 	at org.mozilla.gecko.NSSBridge.decrypt(NSSBridge.java:44)
E/JavaBinder(32574): 	at org.mozilla.gecko.db.PasswordsProvider.doCrypto(PasswordsProvider.java:242)
E/JavaBinder(32574): 	... 7 more
E/FxAccounts(13009): fennec :: PasswordsRepoSession :: Got null cursor exception in PasswordsRepoSession.fetchSince
E/FxAccounts(13009): fennec :: PasswordsRepoSession :: Exception in fetch.
W/FxAccounts(13009): fennec :: RecordsChannel :: onFetchFailed. Calling for immediate stop.
W/FxAccounts(13009): org.mozilla.gecko.sync.repositories.NullCursorException
W/FxAccounts(13009): 	at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkAndLogCursor(RepoUtils.java:86)
W/FxAccounts(13009): 	at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.safeQuery(RepoUtils.java:65)
W/FxAccounts(13009): 	at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$2.run(PasswordsRepositorySession.java:141)
W/FxAccounts(13009): 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
W/FxAccounts(13009): 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
W/FxAccounts(13009): 	at java.lang.Thread.run(Thread.java:841)
W/FxAccounts(13009): fennec :: SynchronizerSession :: Second RecordsChannel onFlowFetchFailed. Logging local fetch error.
W/FxAccounts(13009): org.mozilla.gecko.sync.repositories.NullCursorException
W/FxAccounts(13009): 	at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkAndLogCursor(RepoUtils.java:86)
W/FxAccounts(13009): 	at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.safeQuery(RepoUtils.java:65)
W/FxAccounts(13009): 	at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$2.run(PasswordsRepositorySession.java:141)
W/FxAccounts(13009): 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
W/FxAccounts(13009): 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
W/FxAccounts(13009): 	at java.lang.Thread.run(Thread.java:841)
W/FxAccounts(13009): fennec :: ServLocSynchronizerSess :: Got 1 failures fetching local records! Aborting session.
W/FxAccounts(13009): fennec :: ServerSyncStage :: Synchronize failed: Got 1 failures fetching local records!
W/FxAccounts(13009): org.mozilla.gecko.sync.repositories.FetchFailedException
W/FxAccounts(13009): 	at org.mozilla.gecko.sync.synchronizer.ServerLocalSynchronizerSession.onSecondFlowCompleted(ServerLocalSynchronizerSession.java:61)
W/FxAccounts(13009): 	at org.mozilla.gecko.sync.synchronizer.SynchronizerSession.onFlowCompleted(SynchronizerSession.java:246)
W/FxAccounts(13009): 	at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onStoreCompleted(RecordsChannel.java:249)
W/FxAccounts(13009): 	at org.mozilla.gecko.sync.repositories.RepositorySession$1.run(RepositorySession.java:141)
W/FxAccounts(13009): 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
W/FxAccounts(13009): 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
W/FxAccounts(13009): 	at java.lang.Thread.run(Thread.java:841)
I/FxAccounts(13009): fennec :: ServerSyncStage :: Advancing session even though stage failed (took 7.18 seconds). Timestamps not persisted.
I/FxAccounts(13009): fennec :: GlobalSession :: Running next stage syncBookmarks (org.mozilla.gecko.sync.stage.AndroidBrowserBookmarksServerSyncStage@4233a190)...
I/FxAccounts(13009): fennec :: CountCheckingServer11RepositorySession :: Collection bookmarks has already had a first sync: timestamp is 1428349457300; ignoring any updated counts and syncing as usual.
I/FxAccounts(13009): fennec :: BrowserRepoSession :: BEGIN: creating record -> GUID map.
Flags: needinfo?(rnewman)
Flags: needinfo?(nalexander)
Flags: needinfo?(margaret.leibovic)
I wouldn't discount it, but they're separate SyncAdapters, so it should be fine.

Try unchecking Passwords in Settings > Sync (inside Fennec), see if you get further?
Flags: needinfo?(rnewman)
Flags: needinfo?(nalexander)
Bob are we still seeing 503s on the server ? I feel like this bug is not related to the server anymore, as others on IRC have successfuly synced their clients.
Flags: needinfo?(bobm)
(In reply to Tarek Ziadé (:tarek) from comment #11)
> Bob are we still seeing 503s on the server ? I feel like this bug is not
> related to the server anymore, as others on IRC have successfuly synced
> their clients.

We are not.
Flags: needinfo?(bobm)
Closing this as resolved then. Margaret, feel free to reopen if you get errors again
Status: NEW → RESOLVED
Last Resolved: 3 years ago
Resolution: --- → FIXED
(In reply to :Margaret Leibovic from comment #9)
> (In reply to Tarek Ziadé (:tarek) from comment #8)
> > Deployment verified with a smoke test. Margaret can you try again ?
> 
> I'm still not seeing synced reading list items appear on either of my
> Android devices, but I'm not seeing any reading list related errors in the
> log. 
> 
> However, I am seeing a lot of sync related errors. Could it be a client bug
> that regular sync problems are causing reading list sync problems?
> 
> E/GeckPasswordsProvider(32574): Error in NSSBridge
> E/JavaBinder(32574): *** Uncaught remote exception!  (Exceptions are not yet
> supported across processes.)
> E/JavaBinder(32574): java.lang.RuntimeException: java.lang.Exception:
> PK11SDR_Decrypt returned error 0: Success
> E/JavaBinder(32574): 
> E/JavaBinder(32574): 	at
> org.mozilla.gecko.db.PasswordsProvider.doCrypto(PasswordsProvider.java:247)
> E/JavaBinder(32574): 	at
> org.mozilla.gecko.db.PasswordsProvider.
> onPostQuery$3e5a7f14(PasswordsProvider.java:310)
> E/JavaBinder(32574): 	at
> org.mozilla.gecko.db.SQLiteBridgeContentProvider.
> query(SQLiteBridgeContentProvider.java:429)
> E/JavaBinder(32574): 	at
> android.content.ContentProvider.query(ContentProvider.java:857)
> E/JavaBinder(32574): 	at
> android.content.ContentProvider$Transport.query(ContentProvider.java:200)
> E/JavaBinder(32574): 	at
> android.content.ContentProviderNative.onTransact(ContentProviderNative.java:
> 112)
> E/JavaBinder(32574): 	at android.os.Binder.execTransact(Binder.java:404)
> E/JavaBinder(32574): 	at dalvik.system.NativeStart.run(Native Method)
> E/JavaBinder(32574): Caused by: java.lang.Exception: PK11SDR_Decrypt
> returned error 0: Success
> E/JavaBinder(32574): 
> E/JavaBinder(32574): 	at org.mozilla.gecko.NSSBridge.nativeDecrypt(Native
> Method)
> E/JavaBinder(32574): 	at
> org.mozilla.gecko.NSSBridge.decrypt(NSSBridge.java:44)
> E/JavaBinder(32574): 	at
> org.mozilla.gecko.db.PasswordsProvider.doCrypto(PasswordsProvider.java:242)
> E/JavaBinder(32574): 	... 7 more
> E/FxAccounts(13009): fennec :: PasswordsRepoSession :: Got null cursor
> exception in PasswordsRepoSession.fetchSince
> E/FxAccounts(13009): fennec :: PasswordsRepoSession :: Exception in fetch.
> W/FxAccounts(13009): fennec :: RecordsChannel :: onFetchFailed. Calling for
> immediate stop.
> W/FxAccounts(13009): org.mozilla.gecko.sync.repositories.NullCursorException
> W/FxAccounts(13009): 	at
> org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.
> checkAndLogCursor(RepoUtils.java:86)
> W/FxAccounts(13009): 	at
> org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.
> safeQuery(RepoUtils.java:65)
> W/FxAccounts(13009): 	at
> org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$2.
> run(PasswordsRepositorySession.java:141)
> W/FxAccounts(13009): 	at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:
> 1112)
> W/FxAccounts(13009): 	at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:
> 587)
> W/FxAccounts(13009): 	at java.lang.Thread.run(Thread.java:841)
> W/FxAccounts(13009): fennec :: SynchronizerSession :: Second RecordsChannel
> onFlowFetchFailed. Logging local fetch error.
> W/FxAccounts(13009): org.mozilla.gecko.sync.repositories.NullCursorException
> W/FxAccounts(13009): 	at
> org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.
> checkAndLogCursor(RepoUtils.java:86)
> W/FxAccounts(13009): 	at
> org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.
> safeQuery(RepoUtils.java:65)
> W/FxAccounts(13009): 	at
> org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$2.
> run(PasswordsRepositorySession.java:141)
> W/FxAccounts(13009): 	at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:
> 1112)
> W/FxAccounts(13009): 	at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:
> 587)
> W/FxAccounts(13009): 	at java.lang.Thread.run(Thread.java:841)
> W/FxAccounts(13009): fennec :: ServLocSynchronizerSess :: Got 1 failures
> fetching local records! Aborting session.
> W/FxAccounts(13009): fennec :: ServerSyncStage :: Synchronize failed: Got 1
> failures fetching local records!
> W/FxAccounts(13009): org.mozilla.gecko.sync.repositories.FetchFailedException
> W/FxAccounts(13009): 	at
> org.mozilla.gecko.sync.synchronizer.ServerLocalSynchronizerSession.
> onSecondFlowCompleted(ServerLocalSynchronizerSession.java:61)
> W/FxAccounts(13009): 	at
> org.mozilla.gecko.sync.synchronizer.SynchronizerSession.
> onFlowCompleted(SynchronizerSession.java:246)
> W/FxAccounts(13009): 	at
> org.mozilla.gecko.sync.synchronizer.RecordsChannel.
> onStoreCompleted(RecordsChannel.java:249)
> W/FxAccounts(13009): 	at
> org.mozilla.gecko.sync.repositories.RepositorySession$1.
> run(RepositorySession.java:141)
> W/FxAccounts(13009): 	at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:
> 1112)
> W/FxAccounts(13009): 	at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:
> 587)
> W/FxAccounts(13009): 	at java.lang.Thread.run(Thread.java:841)
> I/FxAccounts(13009): fennec :: ServerSyncStage :: Advancing session even
> though stage failed (took 7.18 seconds). Timestamps not persisted.
> I/FxAccounts(13009): fennec :: GlobalSession :: Running next stage
> syncBookmarks
> (org.mozilla.gecko.sync.stage.
> AndroidBrowserBookmarksServerSyncStage@4233a190)...
> I/FxAccounts(13009): fennec :: CountCheckingServer11RepositorySession ::
> Collection bookmarks has already had a first sync: timestamp is
> 1428349457300; ignoring any updated counts and syncing as usual.
> I/FxAccounts(13009): fennec :: BrowserRepoSession :: BEGIN: creating record
> -> GUID map.

Periodically I have seen such things.  I believe you have malformed records in your (Fennec) passwords DB and the CP is not handling them gracefully.  Such bad records should not impact your RL syncing at all (as rnewman suggested).
You need to log in before you can comment on or make changes to this bug.