Push Task Queue: "Process terminated because the request deadline was exceeded during a loading request."

[Clint Doriot]

I have a push task queue that, even with relatively small load, produces a lot of the following error: Process terminated because the request deadline was exceeded during a loading request.

Tasks that produce these errors run the full 600s before they time out, tie up the task queue, and don't seem to call any of my handler code*. When they do finally run, they typically take 1-60 seconds (probably average closer to 20s).

* I'm assuming its not running any of my main handler code because the first line of my handler code is a print statement, and it never gets logged. Also one of the early steps is hitting an external server, which also never logs the hit.

I'm also noticing that these errors seem to be generated by a subset of the same instances. Its like the instance gets tripped up and doesn't process any of the requests that get sent to it. Those instances seem to have no valid requests that have gone through.

This is the main error I'm seeing:

E 2015-06-16 17:42:27.108 500 0 B 605.3s E 17:42:27.105 /tasks/sync-twitter/friends/tw:944039 0.1.0.2 - - [16/Jun/2015:14:42:27 -0700] "POST /tasks/sync-twitter/friends/tw:944039 HTTP/1.1" 500 0 "https://my-app.appspot.com/api/user" "AppEngine-Google; (+http://code.google.com/appengine)" "sync-twitter.my-app.appspot.com" ms=605304 cpu_ms=2 queue_name=sync-twitter-1 task_name=873919997852904174 pending_ms=5754 exit_code=125 instance=00c61b117cfd2005f05f45857103617298e8e508 app_engine_release=1.9.22 E 17:42:27.105 Process terminated because the request deadline was exceeded during a loading request.

But I also get a lot of similar deadline errors from seemingly random points in the code:

Traceback (most recent call last): File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/runtime/wsgi.py", line 240, in Handle handler = _config_handle.add_wsgi_middleware(self._LoadHandler()) File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/runtime/wsgi.py", line 299, in _LoadHandler handler, path, err = LoadObject(self._handler) File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/runtime/wsgi.py", line 85, in LoadObject obj = __import__(path[0]) File "/base/data/home/apps/s~project-test/sync-twitter:v2.385068030814249794/sync_twitter.py", line 18, in <module> from project.tasks import queue_sync_twitter_network File "/base/data/home/apps/s~project-test/sync-twitter:v2.385068030814249794/common/project/tasks.py", line 12, in <module> import project.models File "/base/data/home/apps/s~project-test/sync-twitter:v2.385068030814249794/common/project/models/__init__.py", line 3, in <module> import leaderboards File "/base/data/home/apps/s~project-test/sync-twitter:v2.385068030814249794/common/project/models/leaderboards.py", line 16, in <module> import project.game_date as game_date File "/base/data/home/apps/s~project-test/sync-twitter:v2.385068030814249794/common/project/game_date.py", line 11, in <module> PROJECT_TZ_INFO = pytz.timezone('Pacific/Honolulu') File "/base/data/home/apps/s~project-test/sync-twitter:v2.385068030814249794/lib/pytz/__init__.py", line 171, in timezone _tzinfo_cache[zone] = build_tzinfo(zone, open_resource(zone)) File "/base/data/home/apps/s~project-test/sync-twitter:v2.385068030814249794/lib/pytz/__init__.py", line 86, in open_resource return loader.open_resource(name) DeadlineExceededError

...or...

Traceback (most recent call last): File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/runtime/wsgi.py", line 240, in Handle handler = _config_handle.add_wsgi_middleware(self._LoadHandler()) File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/runtime/wsgi.py", line 299, in _LoadHandler handler, path, err = LoadObject(self._handler) File "/base/data/home/runtimes/python27/python27_lib/versions/1/google/appengine/runtime/wsgi.py", line 85, in LoadObject obj = __import__(path[0]) File "/base/data/home/apps/s~project-test/sync-twitter:v2.385068030814249794/sync_twitter.py", line 18, in <module> from project.tasks import queue_sync_twitter_network File "/base/data/home/apps/s~project-test/sync-twitter:v2.385068030814249794/common/project/tasks.py", line 2, in <module> """Functions for adding tasks to their respective task queues""" DeadlineExceededError

Anyone have any idea as to what might be causing these errors?

[Michael (Cloud Platform Support)]

Hi Clint,

There was a known issue that occurred yesterday within your timeframe involving application deployment difficulties and large task queue latency spikes. This has since been resolved and you should be good to go from here. You can find more info in this incident report.

Cheers!

[Mike D]

As of this morning none of our apps (test, demo, production) are running.  Nothing changed over night.  Could this be the reason why?  Even now our apps won't run.  The GAE log shows: Process terminated because the request deadline was exceeded. (Error code 123).

There are multiple instances running.  We shut them all down and try accessing the app and the browser just waits and multiple instances start up again.

[Michael (Cloud Platform Support)]

Hi Mike!

I was just checking in on this thread, are you still experiencing this issue? Does your application connect to CloudSQL instances in the us-central1 region?

Cheers!

On Tuesday, June 16, 2015 at 7:55:51 PM UTC-4, Clint Doriot wrote:

[Clint Doriot]

I created a support ticket with the Google Support Center, and the rep suggested this was not the cause of the issue I'm seeing:

"I do not see a close correlation with your issue, for two reasons: the incident lasted several hours, but your issue occurred at a precise point in time (admittedly during the incident); and the issue signature doesn't seem to resemble your issue."

I also load tested again yesterday, and continually saw the same issue occur, mostly corresponding with large spikes in traffic.

So, the support team is looking into things on the backend server logs.

But if anyone has had this problem, and pin pointed any code problems that might cause it, or even off chance things to consider, your feedback would be much appreciated!

On Tuesday, June 16, 2015 at 7:55:51 PM UTC-4, Clint Doriot wrote: