DEADLINE Exceeded Messages ?!

[Derrick]

I am consistently getting Deadline exceeded messages. The problem is
that my individual requests are trivial: do a query or two to
BigTable, serialize the results, and return them.

So, what could be causing these messages. How are deadlines actually
measured on app engine?

In my case, I am sending a number (10-50) of requests in parallel.
Each individual request retrieves a single row in a table plus one or
two rows in related tables.

I would guess that that CPU time usage is measured by interrupting the
thread serving a request at regular intervals. The question is, how
does this interrupt ascertain whether a CPU deadline has been
exceeded.

I hypothesize that when the poller wakes up, it checks to see which
application has the cpu, and adds a tick to the count for that user.
If the same application is using the CPU as the previous time the
poller awoke, then the poller checks to see if the tick count exceeds
the deadline. If so, it initiates a deadline exceeded message and
terminates the request.

If this is the algorithm, then it is very problematic for me. Will
someone from the Google App Engine team explain to us the workings of
the Deadline measuring algorithm so that we can adjust our application
for work on the platform.

Also, could the problem have anything to do with indexing? Our
queries are dirt simple: a single query parameter, so we do not
generate indices for them manually.

[Marzia Niccolai]

Hi Derrick,

What DeadlineExceedError message are you getting, there are a few different deadlines you can run in to with App Engine.

The most common would be the request deadline.  Any given request with App Engine must be completed within 10 seconds.  This is the runtime DeadlineExceededError

Various APIs, like the datastore and URLFetch also have deadlines to ensure that those calls return within the overall request deadline. If you are running in to this deadline, you will get the apiproxy_errors.DeadlineExceededError.

The problem shouldn't have anything to do with indexing, since simple queries indexes are automatically generated, there is no need specify them in the index.yaml (see this article: http://code.google.com/appengine/articles/index_building.html)

From your description I can imagine the problem is either you are requesting too much information from the datastore (running in to apiproxy_errors.DeadlineExceededError) in one request.  The amount of data you can return in a query will depend on the size and shape of your data, but you can test this by reducing the amount of data you query for in one call.

The other issue I can see is that you are just taking too long to return the entire request.  This probably happens because it takes too long to process all of your results before the request deadline.

Generally in such a case we'd suggest profiling your application which will indicate on which calls, and for how long, your app spends it's time.  Some good information on profiling can be found in our FAQ:
http://code.google.com/appengine/kb/commontasks.html#profiling
Screencast:
Optimizing Your App: Profiling and Memcache    http://www.youtube.com/watch?v=Zip1G6-NiMM
And the Google I/O talk 'Building a Production Quality Application on Google App Engine:
http://sites.google.com/site/io/best-practices---building-a-production-quality-application-on-google-app-engine

-Marzia

[Derrick]

I am getting <class 'google.appengine.runtime.DeadlineExceededError'>

> Optimizing Your App: Profiling and Memcachehttp://www.youtube.com/watch?v=Zip1G6-NiMM

> And the Google I/O talk 'Building a Production Quality Application on Google

> App Engine:http://sites.google.com/site/io/best-practices---building-a-productio...
>
> -Marzia

[Marzia Niccolai]

This means your app is taking more than 10 seconds to respond to a request.  Try processing less data per request, or work on streamlining the way that you process the data during a request.

-Marzia

[Derrick]

Here is what I get from the profile of a query that does not exceed
the deadline, but comes close:

ncalls tottime percall cumtime percall filename:lineno(function)
15/13 0.299 0.020 1.018 0.078 {__import__}
16 0.217 0.014 0.235 0.015
{google3.apphosting.runtime._apphosting_runtime___python__apiproxy.Wait}

Does this mean that I am making 16 datastore requests and that I need
to cut down on the number of such requests?

On Dec 18, 1:13 pm, Marzia Niccolai <ma...@google.com> wrote:
> This means your app is taking more than 10 seconds to respond to a request.
> Try processing less data per request, or work on streamlining the way that
> you process the data during a request.
>
> -Marzia
>

[Marzia Niccolai]

Hi,

Seems like you are also doing some heavy module importing.  You could be able to trim that down as well.

-Marzia

[Derrick]

Thanks.

On Dec 18, 5:17 pm, Marzia Niccolai <ma...@google.com> wrote:
> Hi,
>
> Seems like you are also doing some heavy module importing.  You could be
> able to trim that down as well.
>
> -Marzia
>

[Derrick]

I continue to be plagued by deadline exceeded messages, even when
requesting a jpg file from within a zip file. I find it hard to
believe that the individual request is responsible for the deadline
exceeded. What circumstances could cause this error?

#

1.
12-18 03:35PM 36.823 /Photos/P200512048/2277/Benchmark315br.jpg/
500 8769ms 23782ms-cpu 1kb
See details

76.14.31.214 - derrickrburns [18/Dec/2008:15:35:45 -0800] "GET /
Photos/P200512048/2277/Benchmark315br.jpg/ HTTP/1.1" 500 1323 "http://
vhac.appspot.com/search?location=angel+fire%2C
+nm&bedrooms=&bathrooms=" -

2.
E 12-18 03:35PM 45.589

<class 'google.appengine.runtime.DeadlineExceededError'>:
Traceback (most recent call last):
File "/base/data/home/apps/vhac/1.330078475388282125/main.py",
line 29, in <module>
InstallAppengineHelperForDjango()
File "/base/data/home/apps/vhac/1.330078475388282125/
appengine_django/__init__.py", line 373, in
InstallAppengineHelperForDjango
InstallAuthentication()
File "/base/data/home/apps/vhac/1.330078475388282125/
appengine_django/__init__.py", line 393, in InstallAuthentication
from appengine_django.auth import models as helper_models
File "/base/data/home/apps/vhac/1.330078475388282125/
appengine_django/auth/__init__.py", line 24, in <module>
from django.template import Node
File "/base/data/home/apps/vhac/1.330078475388282125/django/
template/__init__.py", line 51, in <module>
import re
File "/base/python_dist/lib/python2.5/py_zipimport.py", line
104, in __init__
if not os.path.isfile(archive):
File "/base/python_dist/lib/python2.5/posixpath.py", line 208,
in isfile
st = os.stat(path)

[Tzakie]

I'm not entirely sure that app engine hasn't occasionally been
throwing a time out here on even on the most simplistic queries. I
can't be sure as I can't see the timing data in the log. I think got a
couple the other day even though it's the same call that's worked
thousands of times. E.G.:

DataRows = db.GqlQuery("SELECT * FROM Table WHERE R=%i AND X='%s' AND
Y=%i AND Z=%i" % (a,b,c,d))

Now I'm going to convert this to a key lookup, but I can't see how
something like this should time out.

Some ideas to help us out:
1)
The log viewer now scrolls off the screen so that if the url is a 'log
get query' you can't see the timeout data on the log. Since it's on
the end. Can you move the timing to the start of the line?
Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US; rv:1.9.0.4) Gecko/
2008102920 Firefox/3.0.4
2)
DeadlineExceededError. Can we break this down into specific errors of
each type of timeout? Also can the error that comes back spit out
profiling data to the console. E.G. a specific count for each of the
deadline counts we are up against the current value and the total
available?

[Marzia Niccolai]

Hi,

Most all of the DeadlineExceededErrors seem to be coming from the module loading of InstallAppEngineHelperForDjango().

I'm not intimately familiar with what could be causing the loading of this module to always timeout, but perhaps another user has some valuable insight?  The only advice I can give is that if you can trim down the number of imports being done on these requests you'll probably stop seeing this error.

-Marzia

[Brett C.]

On Dec 19, 12:02 pm, Marzia Niccolai <ma...@google.com> wrote:
> Hi,
>
> Most all of the DeadlineExceededErrors seem to be coming from the module
> loading of InstallAppEngineHelperForDjango().
>
> I'm not intimately familiar with what could be causing the loading of this
> module to always timeout, but perhaps another user has some valuable
> insight?  The only advice I can give is that if you can trim down the number
> of imports being done on these requests you'll probably stop seeing this
> error.

It's from the loading of google-app-engine-django. I have been getting
this as well for my project as the loading of the helper also leads to
the importing of a lot of django code. In my situation I am using a
fresh checkout of the helper and Django 1.0.2 directly from source in
my app's directory. I am going to try to see if using a zip file helps
at all.

If not it will either require using Django 0.96 as included in the
SDK, switching to app-engine-patch if it can work under the deadline
limit, or simply not using any of the Django helper projects.

-Brett

[Brett C.]

Sticking with a svn copy of google-app-engine-django and moving over
to a zip file of Django 1.0.2 with stuff removed as specified by the
App Engine article (http://code.google.com/appengine/articles/
django10_zipimport.html) and what app-engine-patch suggested (http://
code.google.com/p/app-engine-patch/wiki/ManualInstallation) worked for
me.