Django: show/log ORM sql calls from python shell

Viewed 36920

Using the excellent Django-Devserver I'm finding all kinds of interesting and unexpected SQL calls in my code. I wanted to find where the calls are coming from, and so I'm looking for a way to get a log or print-out of all SQL calls generated by the Django ORM in the Python shell. That is, when I do a Django ORM call via the Python shell, I'd like to see the resulting SQL printed out or logged.

I noticed several solutions that add log info to the html page. Is there an easy way to dump to the command line instead?

8 Answers

Rob Hudson's Django Debug Toolbar, as well as its general awesomness, also includes a pretty nifty debugsqlshell manage.py command which does exactly this.

If you're in the shell, or anywhere for that matter, you can use the queryset method

query.as_sql()

to print the SQL command.

ie:

MyModel.objects.all().query.as_sql()

Just to mention another option - I've made the django-sql-sniffer tool so that it can attach to any running Python process and monitor/analyze SQL execution coming from Django ORM.

As such it can also be used to monitor queries coming from a Python shell process (see github page for the demo video):

  • open shell and get process ID:
In [1]: import os

In [2]: os.getpid()
Out[2]: 99688
  • attach django-sql-sniffer in another tab (and in this case specify the tail mode to follow the queries live)
$ django-sql-sniffer -p 99688 -t
  • go back to your shell and start executing queries
In [3]: cat library/models.py
from django.db import models


class Book(models.Model):
    title = models.CharField(null=False, blank=False, max_length=100)
    author = models.ForeignKey('Author', on_delete=models.CASCADE)


class Author(models.Model):
    first_name = models.CharField(max_length=30)
    last_name = models.CharField(max_length=30)


In [4]: from library.models import *

In [5]: books = Book.objects.all()

In [6]: len(books)  # better use count
Out[6]: 121000

In [7]: book = books.first()  # query set not ordered, will hit db again

In [8]: book = books.first()  # query set not ordered, will hit db again

In [9]: book = books.first()  # query set not ordered, will hit db again

In [10]: book.author.id  # better use author_id
Out[10]: 1

In [11]: Book.objects.filter(author__first_name__startswith='A').count() > 0
Out[11]: True

In [12]: Book.objects.filter(author__first_name__startswith='A').exists()
Out[12]: True
  • the tool prints the raw queries as they get executed
Count: 1; Duration: 0.002211809; Max Duration: 0.002211809; Query:
SELECT "library_book"."id",
       "library_book"."title",
       "library_book"."author_id"
  FROM "library_book"
-------------------------------------------------------
Count: 1; Duration: 0.000240326; Max Duration: 0.000240326; Query:
SELECT "library_book"."id",
       "library_book"."title",
       "library_book"."author_id"
  FROM "library_book"
 ORDER BY "library_book"."id" ASC
 LIMIT 1
-------------------------------------------------------
Count: 2; Duration: 0.000150919; Max Duration: 0.000240326; Query:
SELECT "library_book"."id",
       "library_book"."title",
       "library_book"."author_id"
  FROM "library_book"
 ORDER BY "library_book"."id" ASC
 LIMIT 1
-------------------------------------------------------
Count: 3; Duration: 0.000187874; Max Duration: 0.000240326; Query:
SELECT "library_book"."id",
       "library_book"."title",
       "library_book"."author_id"
  FROM "library_book"
 ORDER BY "library_book"."id" ASC
 LIMIT 1
-------------------------------------------------------
Count: 1; Duration: 0.000919104; Max Duration: 0.000919104; Query:
SELECT "library_author"."id",
       "library_author"."first_name",
       "library_author"."last_name"
  FROM "library_author"
 WHERE "library_author"."id" = %s
 LIMIT 21
-------------------------------------------------------
Count: 1; Duration: 0.040677071; Max Duration: 0.040677071; Query:
SELECT COUNT(*) AS "__count"
  FROM "library_book"
 INNER JOIN "library_author"
    ON ("library_book"."author_id" = "library_author"."id")
 WHERE "library_author"."first_name" LIKE %s ESCAPE '\'
-------------------------------------------------------
Count: 1; Duration: 0.002345800; Max Duration: 0.002345800; Query:
SELECT (1) AS "a"
  FROM "library_book"
 INNER JOIN "library_author"
    ON ("library_book"."author_id" = "library_author"."id")
 WHERE "library_author"."first_name" LIKE %s ESCAPE '\'
 LIMIT 1
-------------------------------------------------------
  • finally, hit Ctrl + C to stop the tool and get an analysis of all captured queries
=======================================================

  ____    ___   _       ____  _____   _   _____  ____
 / ___|  / _ \ | |     / ___||_   _| / \ |_   _|/ ___|
 \___ \ | | | || |     \___ \  | |  / _ \  | |  \___ \
  ___) || |_| || |___   ___) | | | / ___ \ | |   ___) |
 |____/  \__\_\|_____| |____/  |_|/_/   \_\|_|  |____/

               Django SQL Sniffer v1.0.0
=======================================================
             TOP QUERIES BY MAX DURATION


Count: 1; Max Duration: 0.040677071; Combined Duration: 0.040677071; Query:
SELECT COUNT(*) AS "__count"
  FROM "library_book"
 INNER JOIN "library_author"
    ON ("library_book"."author_id" = "library_author"."id")
 WHERE "library_author"."first_name" LIKE %s ESCAPE '\'
-------------------------------------------------------
Count: 1; Max Duration: 0.002345800; Combined Duration: 0.002345800; Query:
SELECT (1) AS "a"
  FROM "library_book"
 INNER JOIN "library_author"
    ON ("library_book"."author_id" = "library_author"."id")
 WHERE "library_author"."first_name" LIKE %s ESCAPE '\'
 LIMIT 1
-------------------------------------------------------
Count: 1; Max Duration: 0.002211809; Combined Duration: 0.002211809; Query:
SELECT "library_book"."id",
       "library_book"."title",
       "library_book"."author_id"
  FROM "library_book"
-------------------------------------------------------
=======================================================
Related