django how to see sql query when running tests?

Question

One of my django application unit test fails with

DatabaseError: ORA-00942: table or view does not exist

I would like to see actual SQL query that caused this error. Do you know how to achieve that?

Answer 1

Another option is to use CaptureQueriesContext (tested with pytest).

from django.db import connection
from django.test.utils import CaptureQueriesContext


def test_foo():
    with CaptureQueriesContext(connection) as ctx:
        # code that runs SQL queries
        print(ctx.captured_queries)

Sources:

• https://blog.ploetzli.ch/2019/showing-sql-queries-with-pytest-and-django/
• How to force django to print each executed sql query

Answer 2

If you want to print/log all SQL queries from the tests, try subclassing TestCase like this:

from django.conf import settings
from django.template import Template, Context
import sys
from django.db import connection
from django.test import TestCase

class LoggingTestCase(TestCase):

  @staticmethod
  def setUpClass():
    # The test runner sets DEBUG to False. Set to True to enable SQL logging.
    settings.DEBUG = True
    super(LoggingTestCase, LoggingTestCase).setUpClass()

  @staticmethod
  def tearDownClass():
    super(LoggingTestCase, LoggingTestCase).tearDownClass()

    time = sum([float(q['time']) for q in connection.queries])
    t = Template("{{count}} quer{{count|pluralize:\"y,ies\"}} in {{time}} seconds:\n\n{% for sql in sqllog %}[{{forloop.counter}}] {{sql.time}}s: {{sql.sql|safe}}{% if not forloop.last %}\n\n{% endif %}{% endfor %}")
    print >> sys.stderr, t.render(Context({'sqllog': connection.queries, 'count': len(connection.queries), 'time': time}))

    # Empty the query list between TestCases.    
    connection.queries = []

Then use LoggingTestCase instead of TestCase as the base class in your tests. Just remember to call this tearDownClass if you override it.

Answer 3

You can also do the following to get the queries (and then for instance print it or evaluate it in your test).

Actually you shouldn't alter django.conf.settings nowadays, therefore I use override_settings.

from django.db import connection, reset_queries
from django.test import override_settings, TransactionTestCase

class TransactionTests(TransactionTestCase):

    @override_settings(DEBUG=True)
    def test_sql(self):
        reset_queries()
        try:
            # Code that uses the ORM goes here
        except Exception as e:
            pass
        self.assertEqual(connection.queries, [])

TestCase might also be suitable, see the differences in this answer.

See the Django documentation for details for SQL output.

Answer 4

Another option is to use connection.execute_wrapper() in your test as follows:

from django.db import connection

def logger(execute, sql, params, many, context):
    print(sql, params)
    return execute(sql, params, many, context)

class GizmoTest(TestCase):

    def test_with_sql_logging(self):
        with connection.execute_wrapper(logger):
            code_that_uses_database()

Tested with Django 2.2.

Answer 5

Its not the cleanest solution but if you just quickly want to debug without installing additional packages you could look for the execute() method in django/db.

For Oracle I guess it is in:

django/db/backends/oracle/base.py and look for:

def execute

For PostgreSQL it is in:

django/db/backends/postgresql_psycopg2/base.py

In CursorWrapper there is a execute() method.

Both are catching IntegrityError and DatabaseError, you can add a print statement there.

For ppl who want to see all sql queries, put the print statement right after the function call.

Answer 6

In the case of pytest and pytest-django just create a fixture for it

@pytest.fixture
def debug_queries(db):
    """ Because pytest run tests with DEBUG=False
        the regular query logging will not work, use this fixture instead
    """
    from django.db import connection
    from django.test.utils import CaptureQueriesContext
    with CaptureQueriesContext(connection):
        yield connection

then in your tests

@pytest.mark.django_db
def test__queries(debug_queries):
    # run your queries here

of course, your logging config should enable logging of queries, something like this:

LOGGING = {
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'standard': {
            'format': '%(asctime)s - %(levelname)s - %(name)s - %(message)s',
        },
    },
    'handlers': {
        'default': {
            'level': 'DEBUG',
            'class': 'logging.StreamHandler',
            'formatter': 'standard',
            'stream': 'ext://sys.stdout',
        },
    },
    'loggers': {
        'django.db.backends': {
            'level': 'DEBUG',
            'handlers': ['default'],
            'propagate': False,
        },
    }
}

Answer 7

The best solution I found so far is debugsqlshell custom django management command provided by django-debugtoolbar.

Answer 8

You can change console level to DEBUG in settings. It worked on Django 1.9.

LOGGING = {
...
'handlers': {
    'console': {
        'level': 'DEBUG',
        'class': 'logging.StreamHandler',
        'formatter': 'simple'
        },
    }
...
}

Answer 9

This was the solution which worked for me (Django 3.1):

from django.test import TestCase


class TestSomething(TestCase):
    @override_settings(DEBUG=True)
    def test_something(self):
        pass
    
    def tearDown(self):
        from django.db import connection
        for query in connection.queries:
            print(f"✅ {query['sql']}\n")

source

Answer 10

All the options here were too complicated/and too many things could go wrong. This works on django >= 1.11+ <= 4.x [tested it on the main branch] (until they break it in the future..)

It works by ignoring settings.DEBUG entirely and just injecting the CursorDebugWrapper to be used always, thus logging the SQLs that ran.

import inspect
from collections import deque
from contextlib import contextmanager
from unittest import mock

from django.db import connections
from django.db.backends import utils


@contextmanager
def print_queries(using="default"):
    """
    [debug] Prints out all the queries in real time

    To avoid messing with django's logging and get the SQL working inside
    tests where `DEBUG` can be set to `False`, this bypasses all that and
    goes straight for the kill.

    Example:

        class TestSomething(TestCase):
            def test_something(self):
                with print_queries():
                    Model.objects.create(a=1, b=2)

        def test_something():
            with print_queries():
                Model.objects.create(a=1, b=2)

    """

    def fake_maker(self, cursor):
        """
        Normally `make_cursor` uses `CursorWrapper` which does NOT debug.
        """
        return utils.CursorDebugWrapper(cursor, self)

    class Snitch(deque):
        """
        Modified version of `deque` that `print()`s out all the items inserted to it.
        """

        def append(self, item):
            current_frame = inspect.currentframe().f_back
            while True:
                info = inspect.getframeinfo(current_frame)
                if "/django/" in info.filename:
                    current_frame = current_frame.f_back
                    continue
                break

            print("*", item["sql"], item["time"], f"{info.filename}:{info.lineno}")
            return super().append(item)

    connection_ = connections[using]
    mock_maker = mock.patch("django.db.backends.base.base.BaseDatabaseWrapper.make_cursor", fake_maker)
    mock_deque = mock.patch.object(connection_, "queries_log", Snitch(maxlen=connection_.queries_log.maxlen))

    with mock_maker, mock_deque:
        yield

Use it like this:

def test_whatever():
    ...
    with print_queries():
        Model.objects.create(a=1, b=2)  # any query here
    ...

Output looks like:

* SELECT .. FROM "table" WHERE ... 0.001 /full/path/file.py:136
* SELECT .. FROM "table" WHERE ... 0.001 /full/path/file.py:245

Will tell you where in your code the query is being made.