Intermittent Cloud Datastore Error: ServiceUnavailable: 503

[speedplane]

I am getting intermittent ServiceUnavailable: 503 error messages when doing datastore operations with the google cloud client library. The stack trace is below. I am running Python 2.7 on Ubuntu, within a Docker container on a small Kubernetes cluster.

Traceback (most recent call last):
  ...
  File "/home/speedplane/DA/djangoappengine/db_gcl/compiler.py", line 345, in get_matching_pk
    self.client.get_multi(self.included_pks, **config)
  File "/usr/local/lib/python2.7/dist-packages/google/cloud/datastore/client.py", line 307, in get_multi
    transaction_id=transaction and transaction.id,
  File "/usr/local/lib/python2.7/dist-packages/google/cloud/datastore/client.py", line 124, in _extended_lookup
    transaction_id=transaction_id,
  File "/usr/local/lib/python2.7/dist-packages/google/cloud/datastore/_http.py", line 519, in lookup
    lookup_response = self._datastore_api.lookup(project, lookup_request)
  File "/usr/local/lib/python2.7/dist-packages/google/cloud/datastore/_http.py", line 304, in lookup
    return self._stub.Lookup(request_pb)
  File "/usr/lib/python2.7/contextlib.py", line 35, in __exit__
    self.gen.throw(type, value, traceback)
  File "/usr/local/lib/python2.7/dist-packages/google/cloud/datastore/_http.py", line 260, in _grpc_catch_rendezvous
    raise error_class(exc.details())
ServiceUnavailable: 503 {"created":"@1489111389.496403106","description":"Endpoint read failed","file":"src/core/ext/transport/chttp2/transport/chttp2_transport.c","file_line":1851,"grpc_status":14,"occurred_during_write":0,"referenced_errors":[{"created":"@1489111389.496341023","description":"Secure read failed","file":"src/core/lib/security/transport/secure_endpoint.c","file_line":166,"referenced_errors":[{"created":"@1489111389.496338171","description":"Socket closed","fd":25,"file":"src/core/lib/iomgr/tcp_posix.c","file_line":249,"target_address":"ipv4:173.194.192.95:443"}]}]}

For ease of reading, that last line is expanded:

ServiceUnavailable: 503 {
 "created":"@1489111389.496403106",
 "description":"Endpoint read failed",
 "file":"src/core/ext/transport/chttp2/transport/chttp2_transport.c",
 "file_line":1851,
 "grpc_status":14,"occurred_during_write":0,
 "referenced_errors":[{"created":"@1489111389.496341023",
   "description":"Secure read failed",
   "file":"src/core/lib/security/transport/secure_endpoint.c","file_line":166,
   "referenced_errors":[{"created":"@1489111389.496338171",
     "description":"Socket closed",
     "fd":25,"file":"src/core/lib/iomgr/tcp_posix.c",
    "file_line":249,"target_address":"ipv4:173.194.192.95:443"}]
  }]
}

I am running this within a Docker container orchestrated by Kubernetes. My Dockerfile inherits from ubuntu:trusty. Below is version information:

# lsb_release
LSB Version:    core-2.0-amd64:core-2.0-noarch:core-3.0-amd64:core-3.0-noarch:core-3.1-amd64:core-3.1-noarch:core-3.2-amd64:core-3.2-noarch:core-4.0-amd64:core-4.0-noarch:core-4.1-amd64:core-4.1-noarch:security-4.0-amd64:security-4.0-noarch:security-4.1-amd64:security-4.1-noarch
# python --version
Python 2.7.6

[cobookman]

Is there a chance that this is related: #2896

[cobookman]

Also the Socket closed error makes it seem like gRPC had its connection terminated to datastore. And needs to be re-opened. In issue #2896, they mention that the python datastore client library doesn't implement retry logic (yet). This issue was created around adding retry logic to all client libs: #2694

[lukesneeringer]

Are you getting the error at 30 minute intervals like the author of #2896?

[speedplane]

It's happening much more regularly than once every 30 minutes. Below are logs with some timings.

[lukesneeringer]

Interesting that the second log set shows so much more frequent failures than the first one.

[daspecster]

@speedplane if this was asked already somewhere, sorry for the repeat question, but is this script using multiprocessing or any kind of threading?

My thought is that either it's an upstream issue(in which case I feel like there would be more people chiming in) or there's something in your architecture that is unhappy.

[speedplane]

I saw that discussion. I don't use multiprocessing. I don't think there is threading, but just in case, I make sure all my clients are thread-local using the function below.

Perhaps I should have mentioned, but this call is being made across projects. It is being made from an instance within a project named ocr-api, but is trying to grab data from a project named docketupdate.

Also, I have a cloud support package, and I can try opening a case if that would help.

import threading
_datastore_client = threading.local()
def datastore_client(project = None):
    '''Return a thread-unique datastore client for the given project.'''
    # Our global datstore client cache.
    global _datastore_client
    if not getattr(_datastore_client, 'clients'):
        _datastore_client.clients = {}
    if project not in _datastore_client.clients:
        # Create a new datastore client and save it in the cache.
        _datastore_client.clients[project] = datastore.client.Client(project) \
            if project else datastore.client.Client()
    return _datastore_client.clients[project]

I can add my own retry logic and see if it helps, but given how often this is occurring, it would be preferable if the underlying issue could be addressed. I added a third screenshot of timestamps above.

[cobookman]

I'd recommend filling a support ticket. Feel free to cc me at bookman@google.com or share your case #, so I can follow up on it and make sure your issue gets resolved.

…

On Fri, Mar 10, 2017, 8:56 AM Michael Sander ***@***.***> wrote: I saw that discussion. I don't use multiprocessing. I don't think there is threading, but just in case, I make sure all my clients are thread-local using the function below. Perhaps I should have mentioned, but this call is being made across projects. It is being made from an instance within a project named ocr-api, but is trying to grab data from a project named docketupdate. Also, I have a cloud support package, and I can try opening a case if that would help. import threading _datastore_client = threading.local() def datastore_client(project = None): '''Return a thread-unique datastore client for the given project.''' # Our global datstore client cache. global _datastore_client if not getattr(_datastore_client, 'clients'): _datastore_client.clients = {} if project not in _datastore_client.clients: # Create a new datastore client and save it in the cache. _datastore_client.clients[project] = datastore.client.Client(project) \ if project else datastore.client.Client() return _datastore_client.clients[project] — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#3128 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ABqI5wN-HzXktWwlMk9rS5Hqo-Uf74Cfks5rkYDVgaJpZM4MY4KO> .

[daspecster]

@speedplane the project information is helpful. I believe there was an issue about that a long time ago regarding that not being supported well? I can't seem to find it though.

@dhermes @tseaver might remember?

[speedplane]

Done. See case ID 12283187.

[speedplane]

I stopped receiving these altogether on March 10 at around 3:30PM ET. I did not redeploy or change any settings in my app since then. Did something change on the backend?