Random 'google.appengine.runtime.DeadlineExceededError'

[phtq]

In recent days some requests have returned the above error. If the
request is repeated a little while later it processes normally. We
would like to put some users onto our application but can't do so
until this problem is resolved.

An example of a normal log entry for one of the operations is shown
below:


I 02-09 07:49PM 16.605 returnfile=/keyboards/keysounds/godk.mp3
See details

02-09 07:49PM 16.576 /keyboards/keysounds/godk.mp3 200 75ms 165ms-cpu
9kb
See details
203.58.113.131 - - [09/Feb/2009:19:49:16 -0800] "GET /keyboards/
keysounds/godk.mp3 HTTP/1.1" 200 9936 "http://kbdlessons.appspot.com/
TQP-PIT/Language/UK-PIT/Course/BasicKeyboard/WorkSpace/Lesson1b/bin/
Lesson1b.swf" -I 02-09 07:49PM 16.605
returnfile=/keyboards/keysounds/godk.mp3


A log entry for the same request (but failing) is shown below:



E 02-09 07:11PM 04.417 <class
'google.appengine.runtime.DeadlineExceededError'>: Traceback (most
recent call last): File "/base/data/home/apps/kbdlessons/
1-01.33130907911
See details

02-09 07:10PM 55.037 /keyboards/keysounds/godk.mp3 500 9391ms 1260ms-
cpu 0kb
See details
203.58.113.131 - - [09/Feb/2009:19:11:04 -0800] "GET /keyboards/
keysounds/godk.mp3 HTTP/1.1" 500 0 "http://kbdlessons.appspot.com/TQP-
PIT/Language/UK-PIT/Course/BasicKeyboard/WorkSpace/Lesson1b/bin/
Lesson1b.swf" -E 02-09 07:11PM 04.417
<class 'google.appengine.runtime.DeadlineExceededError'>:
Traceback (most recent call last):
File "/base/data/home/apps/kbdlessons/1-01.331309079110687966/
main.py", line 61, in <module>
main()
File "/base/data/home/apps/kbdlessons/1-01.331309079110687966/
main.py", line 57, in main
util.run_wsgi_app(application)
File "/base/python_lib/versions/1/google/appengine/ext/webapp/
util.py", line 76, in run_wsgi_app
result = application(env, _start_response)
File "/base/python_lib/versions/1/django/core/handlers/wsgi.py",
line 189, in __call__
response = self.get_response(request)
File "/base/python_lib/versions/1/django/core/handlers/base.py",
line 115, in get_response
receivers = dispatcher.send(signal=signals.got_request_exception)
File "/base/python_lib/versions/1/django/dispatch/dispatcher.py",
line 360, in send
**named
File "/base/python_lib/versions/1/django/dispatch/robustapply.py",
line 47, in robustApply
return receiver(*arguments, **named)
File "/base/data/home/apps/kbdlessons/1-01.331309079110687966/
main.py", line 40, in log_exception
logging.exception("Exception in request:")
File "/base/python_dist/lib/python2.5/logging/__init__.py", line
1301, in exception
apply(error, (msg,)+args, {'exc_info': 1})
File "/base/python_dist/lib/python2.5/logging/__init__.py", line
1294, in error
apply(root.error, (msg,)+args, kwargs)
File "/base/python_dist/lib/python2.5/logging/__init__.py", line
1015, in error
apply(self._log, (ERROR, msg, args), kwargs)
File "/base/python_dist/lib/python2.5/logging/__init__.py", line
1101, in _log
self.handle(record)
File "/base/python_dist/lib/python2.5/logging/__init__.py", line
1111, in handle
self.callHandlers(record)
File "/base/python_dist/lib/python2.5/logging/__init__.py", line
1148, in callHandlers
hdlr.handle(record)
File "/base/python_dist/lib/python2.5/logging/__init__.py", line
655, in handle
self.emit(record)
File "/base/python_lib/versions/1/google/appengine/api/
app_logging.py", line 71, in emit
self.stream.write(message.encode("UTF-8"))
File "/base/python_dist/lib/python2.5/encodings/__init__.py", line
96, in search_function
globals(), locals(), _import_tail)


No changes were made to the application between the 2 requests
(although other requests might well have been processed between the
2).

This particular operation just does one gql operation to find the
entity which has the mp3 file being requested (the file is held as a
Blob in the entity) and then hands it back.

The code follows:

def returnfile(request):
response = HttpResponse()
ref = request.get_full_path()
logging.info('returnfile='+ref)
x = FileStore.gql('where Reference = :1', ref).get()
if x == None:
return HttpResponse("OK")
response.headers['Content-Type'] = x.Type
response.write(x.Data)
return response