Django Decorator to Print SQL Queries

Michael Shepanski
November 27, 2011
0 comments
Nov
27

Django's ORM is great for fast development, but it is sometimes all too easy to write inefficient queries in the language. There are a few options to help find rogue queries sucking all that process time. My favorite is of course Django Debug Toolbar. However, sometimes this is not a viable option, such as when writing AJAX processors, or for some reason DDTB is not available to you.

This simple decorator may help you alleviate some pain. It also becomes a useful tool to copy and paste the queries into an external query browser. My favorite for Linux is CrunchyFrog.

import os

COLORS = {'blue':34, 'cyan':36, 'green':32, 'grey':30, 'magenta':35, 'red':31, 'white':37, 'yellow':33}
RESET = '\033[0m'

def print_queries(filter=None):
    """ Print all queries executed in this funnction. """
    def wrapper1(func):
        def wrapper2(*args, **kwargs):
            from django.db import connection
            sqltime, longest, numshown = 0.0, 0.0, 0
            initqueries = len(connection.queries)
            starttime = time.time()
            result = func(*args, **kwargs)
            for query in connection.queries[initqueries:]:
                sqltime += float(query['time'].strip('[]s'))
                longest = max(longest, float(query['time'].strip('[]s')))
                if not filter or filter in query['sql']:
                    numshown += 1
                    querystr = colored('\n[%ss] ' % query['time'], 'yellow')
                    querystr += colored(query['sql'], 'blue')
                    print querystr
            numqueries = len(connection.queries) - initqueries
            numhidden = numqueries - numshown
            runtime = round(time.time() - starttime, 3)
            proctime = round(runtime - sqltime, 3)
            print colored("------", 'blue')
            print colored('Total Time:  %ss' % runtime, 'yellow')
            print colored('Proc Time:   %ss' % proctime, 'yellow')
            print colored('Query Time:  %ss (longest: %ss)' % (sqltime, longest), 'yellow')
            print colored('Num Queries: %s (%s hidden)\n' % (numqueries, numhidden), 'yellow')
            return result
        return wrapper2
    return wrapper1

def colored(text, color=None):
    """ Colorize text {red, green, yellow, blue, magenta, cyan, white}. """
    if os.getenv('ANSI_COLORS_DISABLED') is None:
        fmt_str = '\033[%dm%s'
        if color is not None:
            text = fmt_str % (COLORS[color], text)
        text += RESET
    return text

And here is an obligatory usage example. You can optionally send an a single filter argument that would not display the query unless the specified string exists in the query. In the example below, I am only display queries with the word 'metric' in them.

@print_queries('metric')
def function_with_queries():
    # Do something here that runs some Django queries
    # Perhaps just wrap your page view

>> [0.023s] SELECT (CAST(label AS int)) AS "range", SUM("api_metrics_heuristic"."value") AS "sum" FROM "api_metrics_heuristic" WHERE ("api_metrics_heuristic"."type" = E'sizes'  AND "api_metrics_heuristic"."headfiler_id" IN (SELECT U0."id" FROM "accounts_filer" U0 INNER JOIN "auth_user" U1 ON (U0."user_id" = U1."id") LEFT OUTER JOIN "accounts_account" U2 ON (U1."id" = U2."user_id") WHERE (NOT (U1."is_staff" = true ) AND U2."account_deleted" IS NULL))) GROUP BY (CAST(label AS int)), CAST(label AS int) ORDER BY "range" ASC
>> ------
>> Total Time:  0.399s
>> Proc Time:   0.301s
>> Query Time:  0.098s (longest: 0.037s)
>> Num Queries: 27 (26 hidden)

Comments

There are currently no comments for this article.