crashes on long queries

[priestc]

I have a view that executes a huge query which takes 15 seconds to complete. With the rundevserver, it always crashes right after the query finishes. Here is what gets outputted:

Debugging middleware catched exception in streamed response at a point where response headers were already sent.
Traceback (most recent call last):
  File "/home/chris/.virtualenvs/flightloggin/lib/python2.6/site-packages/django/core/servers/basehttp.py", line 651, in __call__
    return self.application(environ, start_response)
  File "/home/chris/.virtualenvs/flightloggin/src/django/devserver/handlers.py", line 215, in __call__
    DevServerMiddleware().process_complete(request)
  File "/home/chris/.virtualenvs/flightloggin/src/django/devserver/handlers.py", line 156, in process_complete
    mod.process_complete(request)
  File "/home/chris/.virtualenvs/flightloggin/src/django/devserver/modules/sql.py", line 137, in process_complete
    ), duration=sum(float(c['time']) for c in connection.queries))
  File "/home/chris/.virtualenvs/flightloggin/src/django/devserver/modules/sql.py", line 137, in <genexpr>
    ), duration=sum(float(c['time']) for c in connection.queries))
KeyError: 'time'
192.168.1.145 - - [13/Feb/2010 02:42:30] "GET /stats_save.py?sk=sss HTTP/1.1" 20

[pablobm]

I have run into this. If your problem is the same as mine, then it's not down to long queries, but to Django's supplying a bad query back.

Devserver retrieves the last executed query by calling last_executed_query(), and then formats it. Unfortunately, in most DB backends this method returns an unescaped query. For example, the following is such a non-escaped query:

SELECT * FROM examples WHERE text = bad"query;

Most of the time devserver won't notice, but when it sees a query like the above, it raises an exception because it cannot find the pair of the double quote.

This explains why the query is actually run, but devserver crashes immediately afterwards.

[pablobm]

By the way, I have a (simple) patch. I can't see how to attach it here, so I'll leave it on the body of this comment:

diff --git a/devserver/modules/sql.py b/devserver/modules/sql.py
index 4db7293..4db84e8 100644
--- a/devserver/modules/sql.py
+++ b/devserver/modules/sql.py
@@ -71,7 +71,12 @@ class DatabaseStatTracker(util.CursorDebugWrapper):
             if self.logger:
                 if settings.DEVSERVER_TRUNCATE_SQL:
                     sql = truncate_sql(sql)
-                message = sqlparse.format(sql, reindent=True, keyword_case='upper')
+                try:
+                    message = sqlparse.format(sql, reindent=True, keyword_case='upper')
+                except:
+                    # A bug in Django's last_executed_query() returns unescaped queries,
+                    # which in turn make sqlparse raise an exception
+                    message = 'Could not format SQL.'

                 self.logger.debug(message, duration=duration)
                 if self.cursor.rowcount >= 0:

[pablobm]

Forgot to mention, I'm pursuing this Django bug at http://code.djangoproject.com/ticket/12923 However, this could take time so it should be worked around in devserver