python appengine-gcs-client demo with local devserver hitting AccessTokenRefreshError(u'internal_failure',)

Question

I'm having trouble getting the python appengine-gcs-client demo working using the 1.9.40 (latest presently) SDK's dev_appserver.py.

I followed the Setting Up Google Cloud Storage and the App Engine and Google Cloud Storage Sample instructions.

I created the default bucket for a paid app, with billing enabled and a non-zero daily spending limit set. I successfully uploaded a file to that bucket using the developer console.

I cloned the GoogleCloudPlatform/appengine-gcs-client repo from github. I copied the python/src/cloudstorage dir into the python/demo dir, which now looks like this:

dancorn-laptop.acasa:/home/dancorn/src/appengine-gcs-client/python> find demo/ | sort
demo/
demo/app.yaml
demo/blobstore.py
demo/cloudstorage
demo/cloudstorage/api_utils.py
demo/cloudstorage/api_utils.pyc
demo/cloudstorage/cloudstorage_api.py
demo/cloudstorage/cloudstorage_api.pyc
demo/cloudstorage/common.py
demo/cloudstorage/common.pyc
demo/cloudstorage/errors.py
demo/cloudstorage/errors.pyc
demo/cloudstorage/__init__.py
demo/cloudstorage/__init__.pyc
demo/cloudstorage/rest_api.py
demo/cloudstorage/rest_api.pyc
demo/cloudstorage/storage_api.py
demo/cloudstorage/storage_api.pyc
demo/cloudstorage/test_utils.py
demo/__init__.py
demo/main.py
demo/main.pyc
demo/README

This is how I executed the devserver and the errors reported when trying to access http://localhost:8080 as instructed:

dancorn-laptop.acasa:/home/dancorn/src/appengine-gcs-client/python> /home/usr_local/google_appengine_1.9.40/dev_appserver.py demo
INFO     2016-08-04 01:07:51,786 sdk_update_checker.py:229] Checking for updates to the SDK.
INFO     2016-08-04 01:07:51,982 sdk_update_checker.py:257] The SDK is up to date.
INFO     2016-08-04 01:07:52,121 api_server.py:205] Starting API server at: http://localhost:50355
INFO     2016-08-04 01:07:52,123 dispatcher.py:197] Starting module "default" running at: http://localhost:8080
INFO     2016-08-04 01:07:52,124 admin_server.py:116] Starting admin server at: http://localhost:8000
INFO     2016-08-04 01:08:03,461 client.py:804] Refreshing access_token
INFO     2016-08-04 01:08:05,234 client.py:827] Failed to retrieve access token: {
  "error" : "internal_failure"
}
ERROR    2016-08-04 01:08:05,236 api_server.py:272] Exception while handling service_name: "app_identity_service"
method: "GetAccessToken"
request: "\n7https://www.googleapis.com/auth/devstorage.full_control"
request_id: "ccqdTObLrl"

Traceback (most recent call last):
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/tools/devappserver2/api_server.py", line 247, in _handle_POST
    api_response = _execute_request(request).Encode()
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/tools/devappserver2/api_server.py", line 186, in _execute_request
    make_request()
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/tools/devappserver2/api_server.py", line 181, in make_request
    request_id)
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/api/apiproxy_stub.py", line 131, in MakeSyncCall
    method(request, response)
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/api/app_identity/app_identity_defaultcredentialsbased_stub.py", line 192, in _Dynamic_GetAccessToken
    token = credentials.get_access_token()
  File "/home/usr_local/google_appengine_1.9.40/lib/oauth2client/oauth2client/client.py", line 689, in get_access_token
    self.refresh(http)
  File "/home/usr_local/google_appengine_1.9.40/lib/oauth2client/oauth2client/client.py", line 604, in refresh
    self._refresh(http.request)
  File "/home/usr_local/google_appengine_1.9.40/lib/oauth2client/oauth2client/client.py", line 775, in _refresh
    self._do_refresh_request(http_request)
  File "/home/usr_local/google_appengine_1.9.40/lib/oauth2client/oauth2client/client.py", line 840, in _do_refresh_request
    raise AccessTokenRefreshError(error_msg)
AccessTokenRefreshError: internal_failure

WARNING  2016-08-04 01:08:05,239 tasklets.py:468] suspended generator _make_token_async(rest_api.py:55) raised RuntimeError(AccessTokenRefreshError(u'internal_failure',))
WARNING  2016-08-04 01:08:05,240 tasklets.py:468] suspended generator get_token_async(rest_api.py:224) raised RuntimeError(AccessTokenRefreshError(u'internal_failure',))
WARNING  2016-08-04 01:08:05,240 tasklets.py:468] suspended generator urlfetch_async(rest_api.py:259) raised RuntimeError(AccessTokenRefreshError(u'internal_failure',))
WARNING  2016-08-04 01:08:05,240 tasklets.py:468] suspended generator run(api_utils.py:164) raised RuntimeError(AccessTokenRefreshError(u'internal_failure',))
WARNING  2016-08-04 01:08:05,240 tasklets.py:468] suspended generator do_request_async(rest_api.py:198) raised RuntimeError(AccessTokenRefreshError(u'internal_failure',))
WARNING  2016-08-04 01:08:05,241 tasklets.py:468] suspended generator do_request_async(storage_api.py:128) raised RuntimeError(AccessTokenRefreshError(u'internal_failure',))
ERROR    2016-08-04 01:08:05,241 main.py:62] AccessTokenRefreshError(u'internal_failure',)
Traceback (most recent call last):
  File "/home/dancorn/src/appengine-gcs-client/python/demo/main.py", line 43, in get
    self.create_file(filename)
  File "/home/dancorn/src/appengine-gcs-client/python/demo/main.py", line 89, in create_file
    retry_params=write_retry_params)
  File "/home/dancorn/src/appengine-gcs-client/python/demo/cloudstorage/cloudstorage_api.py", line 97, in open
    return storage_api.StreamingBuffer(api, filename, content_type, options)
  File "/home/dancorn/src/appengine-gcs-client/python/demo/cloudstorage/storage_api.py", line 697, in __init__
    status, resp_headers, content = self._api.post_object(path, headers=headers)
  File "/home/dancorn/src/appengine-gcs-client/python/demo/cloudstorage/rest_api.py", line 82, in sync_wrapper
    return future.get_result()
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/ext/ndb/tasklets.py", line 383, in get_result
    self.check_success()
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/ext/ndb/tasklets.py", line 427, in _help_tasklet_along
    value = gen.throw(exc.__class__, exc, tb)
  File "/home/dancorn/src/appengine-gcs-client/python/demo/cloudstorage/storage_api.py", line 128, in do_request_async
    deadline=deadline, callback=callback)
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/ext/ndb/tasklets.py", line 427, in _help_tasklet_along
    value = gen.throw(exc.__class__, exc, tb)
  File "/home/dancorn/src/appengine-gcs-client/python/demo/cloudstorage/rest_api.py", line 198, in do_request_async
    follow_redirects=False)
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/ext/ndb/tasklets.py", line 427, in _help_tasklet_along
    value = gen.throw(exc.__class__, exc, tb)
  File "/home/dancorn/src/appengine-gcs-client/python/demo/cloudstorage/api_utils.py", line 164, in run
    result = yield tasklet(**kwds)
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/ext/ndb/tasklets.py", line 427, in _help_tasklet_along
    value = gen.throw(exc.__class__, exc, tb)
  File "/home/dancorn/src/appengine-gcs-client/python/demo/cloudstorage/rest_api.py", line 259, in urlfetch_async
    self.token = yield self.get_token_async()
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/ext/ndb/tasklets.py", line 427, in _help_tasklet_along
    value = gen.throw(exc.__class__, exc, tb)
  File "/home/dancorn/src/appengine-gcs-client/python/demo/cloudstorage/rest_api.py", line 224, in get_token_async
    self.scopes, self.service_account_id)
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/ext/ndb/tasklets.py", line 427, in _help_tasklet_along
    value = gen.throw(exc.__class__, exc, tb)
  File "/home/dancorn/src/appengine-gcs-client/python/demo/cloudstorage/rest_api.py", line 55, in _make_token_async
    token, expires_at = yield rpc
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/ext/ndb/tasklets.py", line 513, in _on_rpc_completion
    result = rpc.get_result()
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/api/apiproxy_stub_map.py", line 613, in get_result
    return self.__get_result_hook(self)
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/api/app_identity/app_identity.py", line 519, in get_access_token_result
    rpc.check_success()
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/api/apiproxy_stub_map.py", line 579, in check_success
    self.__rpc.CheckSuccess()
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/api/apiproxy_rpc.py", line 157, in _WaitImpl
    self.request, self.response)
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/ext/remote_api/remote_api_stub.py", line 201, in MakeSyncCall
    self._MakeRealSyncCall(service, call, request, response)
  File "/home/usr_local/google_appengine_1.9.40/google/appengine/ext/remote_api/remote_api_stub.py", line 235, in _MakeRealSyncCall
    raise pickle.loads(response_pb.exception())
RuntimeError: AccessTokenRefreshError(u'internal_failure',)
INFO     2016-08-04 01:08:05,255 module.py:788] default: "GET / HTTP/1.1" 200 249

I was surprised when I saw the attempt to contact a Google server, I was expecting to use a faked, local filesystem-based emulation, based on these notes from the App Engine and Google Cloud Storage Sample instructions:

• Using the client library with the development app server:

You can use the client library with the development server.

**Note**: Files saved locally are subject to the file size and naming conventions imposed by the local filesystem.

• app.yaml walkthrough:

You specify the project ID in the line application: your-app-id, replacing the value your-app-id. This value isn't used when running locally, but you must supply a valid project ID before deploying: the deployment utility reads this entry to determine where to deploy your app.

• Deploying the Sample, step 5:

In your browser, visit https://.appspot.com; the application will execute on page load, just as it did when running locally. Only this time, the app will actually be writing to and reading from a real bucket.

I even placed my real app's ID into the app.yaml file, but that didn't make any difference.

I've checked the known GAE issues and only found this potentially related one, but on a much older SDK version:

• Issue 11690 GloudStorage bug in GoogleAppEngineLanucher development server

I checked a few older SDK versions I have around (1.9.30, 1.9.35), just in case - no difference either.

My questions:

1. How can I make the GCS client operate locally (w/ faked GCS based on the local filesystem) when it's used with dev_appserver.py?
2. Since it's mentioned it should work with the real GCS as well even when used with dev_appserver.py what do I need to do to achieve that? (less important, more of a curiosity)

Answer 1

Actually the reason was what IMHO is a quite silly bug - inability to read the credentials from a local file written by an earlier version of the SDK (or related package?) and failure to fallback to a more decent action which leads to a rather misleading traceback throwing off the investigation.

Credit goes to this answer: https://stackoverflow.com/a/35890078/4495081 ('tho the bug mentioned in the post was for something else, ultimately triggering the similar end result)

After removing the ~/.config/gcloud/application_default_credentias.json file the demo completed successfully using the local filesystem. And my real app worked fine as well.

My 2nd question stands, but I'm not too worried about it - personally I don't see a great value in using the real GCS storage with the local development server - I have to do testing on a real staging GAE app anyways for other reasons.