Login or Sign up

Django SQL logging middleware

Posted by: skyl on Dec. 29, 2010

So, you want to see what sql Django is running for your request handlers? You would like to log this SQL when you are in DEBUG? Django debug toolbar is too heavy sometimes and doesn't show you requests made with ajax or request that do not render a page? You saw this snippet; but, you don't want to take over the whole page; you just want to write the sql to the log. Plus, doesn't the output sql just build up for each request without getting reset? You can adapt the mentioned snippet:

from django.conf import settings
from django.db import connection

class SQLLoggingMiddleware(object):

  def process_request(self, request):
      if not settings.DEBUG:
          return

      logger.debug('----------------RESETTING QUERIES REQUEST----------------------')
      db.reset_queries()

  def process_response(self, request, response):
      if not settings.DEBUG:
          return response

      logger.debug('== %s ==BEGIN SQL LOGGING BEFORE RETURN RESPONSE=====' %
              (request.get_full_path()))

      timesql=0.0
      duplicate = 0
      seen={}

      for q in connection.queries:
          time = float(q['time'])
          timesql += time
          sql = q["sql"]
          count, total_time = seen.get(sql, (0,0.0))
          if count:
              duplicate += 1
          seen[sql] = (count + 1, total_time + time)

      for i, (sql,res) in enumerate(seen.iteritems()):
          logger.debug('\n#%s ran %s time(s), taking %s ms\n%s\n\n' % (i, res[0], res[1]*1000,  sql))

      logger.debug('+++++ %s queries +++++' % len(connection.queries))
      logger.debug('::::: %s unique ::::::' % len(seen))
      logger.debug('TOTAL TIME FOR SQL: %s' % timesql)
      logger.debug('TOTAL DUPES: %s' % duplicate)
      logger.debug('----------RESETTING QUERIES RESPONSE-------------')
      db.reset_queries()
      return response

Note that in a multi-<process and/or thread> environment you may get weird combinations of sql from different requests firing at the same time. With runserver, however, the results should be nice and smoof.

Comments on This Post:

Please Login (or Sign Up) to leave a comment