Django exception bugging me, don't know how to debug it

Question

I recently upgraded to python2.7 and django1.3 and since then

Unhandled exception in thread started by <bound method Command.inner_run of <django.core.management.commands.runserver.Command object at 0x109c57490>>
Traceback (most recent call last):
    File "/Users/ApPeL/.virtualenvs/myhunt/lib/python2.7/site-packages/django/core/management/commands/runserver.py", line 88, in inner_run
        self.validate(display_num_errors=True)
    File "/Users/ApPeL/.virtualenvs/myhunt/lib/python2.7/site-packages/django/core/management/base.py", line 249, in validate
        num_errors = get_validation_errors(s, app)
    File "/Users/ApPeL/.virtualenvs/myhunt/lib/python2.7/site-packages/django/core/management/validation.py", line 36, in get_validation_errors
        for (app_name, error) in get_app_errors().items():
    File "/Users/ApPeL/.virtualenvs/myhunt/lib/python2.7/site-packages/django/db/models/loading.py", line 146, in get_app_errors
        self._populate()
    File "/Users/ApPeL/.virtualenvs/myhunt/lib/python2.7/site-packages/django/db/models/loading.py", line 67, in _populate
        self.write_lock.release()
    File "/System/Library/Frameworks/Python.framework/Versions/2.7/lib/python2.7/threading.py", line 137, in release
        raise RuntimeError("cannot release un-acquired lock")
    RuntimeError: cannot release un-acquired lock

Your help would be greatly appreciated.

Answer 1

A usual first recommendation is to apply the latest updates to gevent or greenlet or what you use related to threads. Implementation of threading.Thread.start has been changed between Python 2.6 and 2.7. There are many recipes how to start green... or green... with Django. Try to read any recent for Python 2.7. and send a link which one makes the problem.

Debugging: Add following lines to your manage.py to enable logging of thread start etc. to stderr:

import threading
setattr(threading, '__debug__', True)

Add the argument verbose to django/db/loading.py line 39 in order to see also what threads acquire and release the lock.

-        write_lock = threading.RLock(),
+        write_lock = threading.RLock(verbose=True),

Run development server. For only one thread without autoreload you should see something like:

$ python manage.py runserver --noreload
Validating models...

MainThread: <_RLock owner='MainThread' count=1>.acquire(1): initial success
MainThread: <_RLock owner=None count=0>.release(): final release

Notes:
count=1 acquire(1) -- the first acquire by a blocking lock
owner=None count=0>.release() -- the the lock is currently being unlocked

$ python manage.py runserver
Validating models...

Dummy-1: <_RLock owner=-1222960272 count=1>.acquire(1): initial success
Dummy-1: <_RLock owner=None count=0>.release(): final release

This is the same with autoreload. Models are validated by the child process. "Dummy-1" is a symbolic name of the thread. This can be repeated for more threads, but no threads should/can acquire the lock until it is released by the previous thread. We can continue according the results.