App Engine dev tries and fails to reach Datastore

[stephenplusplus]

Updated 12/12/14

I'm running https://github.com/stephenplusplus/sillycloud/tree/gae with an app.yaml and Dockerfile copied from the appengine quickstart project. I only made small modifications to match my structure.

When I run gcloud preview app run . I see that my routes are correctly configured. I have a handler for GET requests to /api/users: https://github.com/stephenplusplus/sillycloud/blob/master/actions.js#L10. The first api request, runQuery, is where I start experiencing errors.

NOTE: I'm using my branch from #328 to test against

See #233 (comment) for the error I'm experiencing.

[rakyll]

I will return back to issue when I get back to the office tomorrow, likely that I can peer with @rrch to discover the missing parts.

[rakyll]

@silvolu was able to figure out which hostname we should use, should update the issue.

[silvolu]

Yeah sorry, hostname is ok, but the port should be read from process.env.GAE_SERVER_PORT.
I'm having problems writing to the datastore though, still investigating.

[rakyll]

I'm not sure if we should skip the Authorization header if mock server runs on localhost:8080. I haven't read their code, but could be a possibility.

[stephenplusplus]

I started using the correct port, GAE_SERVER_PORT.

When I run GET /api/users, which uses gcloud to run POST /datastore/v1beta2/datasets/nth-circlet-705/runQuery, this is what the gcloud console shows:

...
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9938s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9940s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9941s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9943s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9944s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9945s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9946s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9947s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9948s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9949s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9950s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9951s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9951s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9952s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9953s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9954s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 3> after 9.9955s pending
INFO: sillycloud: "POST /datastore/v1beta2/datasets/nth-circlet-705/runQuery HTTP/1.1" 503 -
DEBUG: Request handled by <Instance 0: 1/1, total: 3> in 10.0251s
INFO: sillycloud: "GET /api/users HTTP/1.1" 200 9

When I try to add a user (POST /api/users which makes a POST /datastore/v1beta2/datasets/nth-circlet-705/commit), it has similar output:

...
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9981s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9982s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9983s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9984s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9985s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9986s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9987s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9989s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9990s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9991s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9992s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9993s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9994s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9995s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9996s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9997s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9998s pending
DEBUG: Dispatching request to <Instance 0: 1/1, total: 4> after 9.9999s pending
INFO: sillycloud: "POST /datastore/v1beta2/datasets/nth-circlet-705/commit HTTP/1.1" 503 -

So, my API requests are tried for 10 seconds, but inevitably timeout and return 503s.

My request header:

POST /datastore/v1beta2/datasets/nth-circlet-705/commit HTTP/1.1
Content-Type: application/x-protobuf
User-Agent: gcloud-node/0.4.0
Host: 10.0.2.2:8080
Connection: keep-alive
Transfer-Encoding: chunked

[stephenplusplus]

2 months later, I'm going to see if anything magically fixed itself. 👍 🔍

[stephenplusplus]

Nothing magical. Same errors as above. Updated the initial post in this thread with the latest steps to reproduce.