What steps will reproduce the problem?

This bug is not consistently reproducible

What is the expected output? What do you see instead?

We have a site with about 1 request every 5 seconds and every once in a while, like once a day on average, we see something like this in the live server logs:

<class 'django.core.urlresolvers.Resolver404'>: {'path': u'djdb/track/search.txt'} Traceback (most recent call last): File "/base/data/home/apps/chirpradio/1.339081418084163115/main.py", line 61, in <module> main() File "/base/data/home/apps/chirpradio/1.339081418084163115/main.py", line 57, in main util.run_wsgi_app(application) File "/base/python_lib/versions/1/google/appengine/ext/webapp/util.py", line 97, in run_wsgi_app run_bare_wsgi_app(add_wsgi_middleware(application)) File "/base/python_lib/versions/1/google/appengine/ext/webapp/util.py", line 115, in run_bare_wsgi_app result = application(env, _start_response) File "/base/data/home/apps/chirpradio/1.339081418084163115/django.zip/django/core/handlers/wsgi.py", line 241, in call File "/base/data/home/apps/chirpradio/1.339081418084163115/django.zip/django/core/handlers/base.py", line 73, in get_response File "/base/data/home/apps/chirpradio/1.339081418084163115/django.zip/django/middleware/common.py", line 56, in process_request File "/base/data/home/apps/chirpradio/1.339081418084163115/django.zip/django/middleware/common.py", line 142, in _is_valid_path File "/base/data/home/apps/chirpradio/1.339081418084163115/django.zip/django/core/urlresolvers.py", line 303, in resolve File "/base/data/home/apps/chirpradio/1.339081418084163115/django.zip/django/core/urlresolvers.py", line 218, in resolve File "/base/data/home/apps/chirpradio/1.339081418084163115/django.zip/django/core/urlresolvers.py", line 234, in resolve

Of course, this is a valid URL and works at all other times. We have seen this happen on older versions of Google App Engine Django and it did not go away after upgrading to r100

What version of the product are you using? On what operating system?

Google App Engine Django r100 Django 1.1.1 (django.zip) SDK 1.3.0

Please provide any additional information below.

I was hoping the fix to Issue 124 would address this but it does not. Note that the ImportError we were seeing relating to Issue 124 did go away after upgrading to r100.

For reference our app is at http://code.google.com/p/chirpradio/

Yes. The error seems to pop up the first few times newly uploaded pages are loaded. I can repeat the issue by uploading a new version and then loading pages at somethign like 11.latest.myapp.appspot.com. The issue seems to go away after the pages have been accessed a few times.

it happens for our app long after a new version was deployed. It might be due to App Engine internally spinning up a new machine with the app but I'm not sure.

I strongly recommend the GAE team to escalate this ticket.

My app is having this problem now very frequently starting tonight after a new deployment. It stills happens at around 20 times every 10 minutes, 1 hour after a new version is deployed. It doesn't look like any change in our code is related to this.

We used to see this error occassionally.

We have been using django 1.1.1 for many months.

Here is the error log: File "/base/data/home/apps/snsanalytics/1.339549158011260084/common/zip-packages/django-1.1.zip/django/core/handlers/wsgi.py", line 241, in call File "/base/data/home/apps/snsanalytics/1.339549158011260084/common/zip-packages/django-1.1.zip/django/core/handlers/base.py", line 73, in get_response File "/base/data/home/apps/snsanalytics/1.339549158011260084/common/zip-packages/django-1.1.zip/django/middleware/common.py", line 56, in process_request File "/base/data/home/apps/snsanalytics/1.339549158011260084/common/zip-packages/django-1.1.zip/django/middleware/common.py", line 142, in _is_valid_path File "/base/data/home/apps/snsanalytics/1.339549158011260084/common/zip-packages/django-1.1.zip/django/core/urlresolvers.py", line 294, in resolve File "/base/data/home/apps/snsanalytics/1.339549158011260084/common/zip-packages/django-1.1.zip/django/core/urlresolvers.py", line 218, in resolve File "/base/data/home/apps/snsanalytics/1.339549158011260084/common/zip-packages/django-1.1.zip/django/core/urlresolvers.py", line 234, in resolve

FWIW, I found out that in my case, Resolver404 was the symptom of an exception getting raised randomly on the first request of when an app got spun up internally on an App Engine server (not a deploy). The culprit exception was raised while a module was imported and in our case it was a Datastore timeout which is random. Every subsequent request seemed to leave the Django WSGI app in a broken state where the URL mapping was incomplete. To fix the timeout, we use AutoRetry, which you can find here:

http://code.google.com/p/chirpradio/source/browse/common/autoretry.py and http://code.google.com/p/chirpradio/source/browse/common/tests/test_autoretry.py

more info: http://code.google.com/p/chirpradio/issues/detail?id=78&can=1&q=timeout

this is probably a bug in Google App Engine but it's hard to track down and no one has a fix for it yet (if it is indeed a bug): http://code.google.com/p/googleappengine/issues/detail?id=1409

I was unsuccessful at creating a fresh Google App Engine Django project to reproduce this scenario. If anyone else can reproduce it, that will help in understanding and possibly fixing this incomplete module state. It probably has to do with how view functions are registered at import time.

After some code shuffling around, we kinda fixed this problem in our app. So this ticket is not the highest priority for my app now.

Although, we don't know the exact reason. We believe it has to do with the load sequence of various django libs. It seems the load sequence can be very complicated. Each application has to carefully check the load sequence and timing.

GAE may have a bug to allow a deferred job to proceed before some django libs are not fully loaded and initialized.

This is now fixed with a better explanation of the problem and a patch to Google App Engine Django in Issue 169

Possibly issue 1409 is also relevant -- the problem there is caused by app-engine- patch which attempts to delete the imported django modules. This is not safe.

Sorry, that would be http://code.google.com/p/googleappengine/issues/detail?id=1409 -- I forgot this is a different tracker. (And the relevance is likely that attempts to delete django from sys.modules are always unsafe.)

I'm going to merge this into issue 169 since it looks like they share a root cause and most of the debugging/discussion is in that issue.