ExceptionReporter may re-evaluate error-causing queryset, leading to a later DatabaseError that masks the original one
|Reported by:||aaron||Owned by:||aaugustin|
|Severity:||Normal||Keywords:||ExceptionReporter DatabaseError current transaction aborted error queryset|
|Has patch:||no||Needs documentation:||no|
|Needs tests:||no||Patch needs improvement:||no|
I'm using PostgreSQL and the TransactionMiddleware , and I'm not sure if this error occurs with other database engines. Here's the error that pops up:
DatabaseError at /blah/ current transaction is aborted, commands ignored until end of transaction block Traceback: File ".../lib/django-1.3/django/core/handlers/base.py" in get_response 178. response = middleware_method(request, response) File ".../lib/django-1.3/django/contrib/sessions/middleware.py" in process_response 36. request.session.save() File ".../lib/django-1.3/django/contrib/sessions/backends/db.py" in save 61. sid = transaction.savepoint(using=using) File ".../lib/django-1.3/django/db/transaction.py" in savepoint 162. return connection.savepoint() File ".../lib/django-1.3/django/db/backends/__init__.py" in savepoint 223. self._savepoint(sid) File ".../lib/django-1.3/django/db/backends/__init__.py" in _savepoint 70. self.cursor().execute(self.ops.savepoint_create_sql(sid)) File ".../lib/django-1.3/django/db/backends/util.py" in execute 34. return self.cursor.execute(sql, params) File ".../lib/django-1.3/django/db/backends/postgresql_psycopg2/base.py" in execute 44. return self.cursor.execute(query, args)
The cause seems to be a QuerySet that causes an error, for example, it refers to a table that doesn't exist or is missing a column. This would be fine, except that there are two lines in django/views/debug.py around line 117, in ExceptionReporter.get_traceback_html() (in django 1.3 release version) that looks like this:
if 'vars' in frame: frame['vars'] = [(k, force_escape(pprint(v))) for k, v in frame['vars']]
In this case, v is the QuerySet. Running the pprint template filter on it evaluates it, and since it caused an error the first time (and never got _result_cache filled in) it causes an error the second time too. This error is caught by the filter, which returns an error string. However, the running of the SQL query puts the DB in a bad state, so any SQL commands run after this point also return an error, and saving the current user's session is one such command. This new error masks the original one, which is annoying. It's still possible to find the original error by looking at the database log, but that's defeating the point of this otherwise beautiful error page.
I'm not sure of the best way to fix this. One way, I guess, is to set a transaction savepoint before calling this method and roll it back after, but that seems to be a hack. Maybe we could check for querysets that have not been evaluated, and leave them unevaluated, printing out something like "(Unevaluated QuerySet) %s" % qs.query instead. It seems to make sense that the error reporting page renderer should not touch the database at all, since it should be as robust as possible.
I think that ideally QuerySet.__repr__ wouldn't have any side effects, but its behaviour has been around for so long and so many people are used to not needing list(qs) in an interactive shell that this would not be an easy change to make. I wonder if it would be possible to add a hook into manage.py shell that evaluates querysets as a substitute?
Change History (9)
comment:1 Changed 3 years ago by aaron
- Needs documentation unset
- Needs tests unset
- Patch needs improvement unset
comment:6 Changed 16 months ago by aaugustin
- Owner changed from nobody to aaugustin
- Status changed from new to assigned
comment:7 Changed 16 months ago by aaugustin
- Resolution set to fixed
- Status changed from assigned to closed