Отладка SQL в django тестах

Отладка SQL в django тестах

В django тестах можно замерять количество сделанных SQL запросов:

def test_home(self):
    with self.assertNumQueries(1):
        response = self.client.get('/')
    self.assertEqual(response.status_code, 200)

Если код в контексте assertNumQueries сделает иное количество обращений к БД, чем ожидается (здесь 1), то тест выдает ошибку. Но когда такой тест не проходит, бывает трудно определить лишний отправленный запрос. Для отладки такого случая удобно вывести в консоль отправленные SQL запросы. Далее опишу, как этого добиться.

Кстати, если вы используете Django 1.7+, то вместе с ошибкой будут показаны все SQL выражения, т.е. если этого достаточно - то делать вообще ничего не надо. Ура! Если же вы используете более старые версии, то данная статья будет полезна.

Настройка логов для вывода SQL запросов в консоль

Django будет логировать SQL запрос, если соблюдается одного из следующих условий:

settings.DEBUG = True

или

connection.use_debug_cursor = True

По умолчанию в тестах всегда DEBUG = False вне зависимости от того, что стоит в вашем settings.DEBUG. Это правильно, тестировать лучше с боевыми настройками.

Т.о. остается connection.use_debug_cursor, которое по умолчанию всегда None или False (в разных версиях по разному). Но контекстный менеджер assertNumQueries сам выставляет это значение в True на время работы соответствующего блока! Нам остается лишь правильно задать настройки логов.

Создадим отдельный файл настроек для тестов и назовем его settings_test.py. Тесты гонять будем с ним. Рекомендую всегда делать так - это удобно. Структура проекта примерно такая:

project
├── project
│   ├── __init__.py
│   ├── settings.py
│   ├── settings_test.py
│   ├── urls.py
│   └── wsgi.py
│
├── spam  # some app
│   ├── __init__.py
│   ├── views.py
│   ├── tests.py
│   └── models.py
│
└── manage.py

Файл tests.py содержит тесты приложения spam. Так организовывать тесты не самый хороший выбор, лучше выделить отдельную папку и держать все тесты там. Но для простоты нашего примера годится.

Содержимое settings_test.py:

from settings import *
try:
    from settings import LOGGING
except ImportError:
    LOGGING = dict(version=1, disable_existing_loggers=False,
        handlers={}, loggers={})

# use database in memory to not lose your data!
DATABASES = {
    'default': {
        'ENGINE': 'django.db.backends.sqlite3',
        'NAME': ':memory:',
        'USER': '',
        'PASSWORD': '',
        'TEST_CHARSET': 'utf8',
    }}

LOGGING['handlers']['console'] = {
    'level': 'DEBUG',
    'class': 'logging.StreamHandler',
}
LOGGING['loggers']['django.db.backends'] = {
    'handlers': ['console'],
    'level': 'DEBUG',
    'propagate': False,
}
LOGGING['loggers']['django.db.backends.schema'] = {
    'propagate': False,  # don't log schema queries, django >= 1.7
}

Тест (tests.py) выглядит так:

from django.test import TestCase
from spam.models import Foo

class SpamTestCase(TestCase):
    def setUp(self):
        Foo.objects.create(title="Foo")

    def test_home(self):
        with self.assertNumQueries(1):
            response = self.client.get('/')
        self.assertEqual(response.status_code, 200)

Давайте посмотрим, что будет при прогоне теста используя разные runner'ы.

Django 1.4+

$ python manage.py test (нет SQL):

Creating test database for alias 'default'...
.
----------------------------------------------------------------------
Ran 1 test in 0.009s

OK
Destroying test database for alias 'default'...

$ python manage.py test --settings=project.settings_test (SQL в консоле)

Creating test database for alias 'default'...
(0.000) SELECT "spam_foo"."id", "spam_foo"."title" FROM "spam_foo" LIMIT 21; args=()
.
----------------------------------------------------------------------
Ran 1 test in 0.009s

OK
Destroying test database for alias 'default'...

Django 1.4+ и django-nose

  • pip install django-nose
  • в settings.py выставляем TEST_RUNNER = 'django_nose.NoseTestSuiteRunner'

$ python manage.py test (нет SQL):

...

$ python manage.py test --settings=project.settings_test (SQL в консоле)

(0.000) SELECT "spam_foo"."id", "spam_foo"."title" FROM "spam_foo" LIMIT 21; args=()
...

Django 1.4+ и pytest-django

  • pip install pytest-django
  • создаем файл pytest.ini рядом с manage.py и задаем файл настроек:

    [pytest]
    DJANGO_SETTINGS_MODULE = project.settings
    
  • переименуем tests.py в test_spam.py (стандартные имена для py.test)

$ py.test (нет SQL):

...

$ py.test --ds=project.settings_test (нет SQL, py.test перехватывает весь вывод)

...

$ py.test --ds=project.settings_test -s (SQL в консоле)

(0.000) SELECT "spam_foo"."id", "spam_foo"."title" FROM "spam_foo" LIMIT 21; args=()
...

Итого

Как видно из предыдущих примеров, при использовании нашего settings_test в консоль выводятся все запросы к БД, сделанные в блоке контекстного менеджера assertNumQueries.

Если мы хотим гонять тесты всегда с этими настройками, а не только когда хотим что-то отладить, то очень скоро устанем от обилия SQL. Можно сделать так: закомментировать строчку 'handlers': ['console'],, т.о. ничего выводится не будет. А когда нужно их посмотреть - просто убираем комментарий.

Вывод ошибки assertNumQueries и Django 1.7+

Если assertNumQueries регистрирует отличное от ожидаемого количество обращений к БД, то выводится traceback и ошибка:

Traceback (most recent call last):
  ...
AssertionError: 1 queries executed, 2 expected

Но в django 1.7+ так же выводятся и сделанные запросы:

Captured queries were:
QUERY = u'SELECT "spam_foo"."id", "spam_foo"."title" FROM "spam_foo" LIMIT 21' - PARAMS = ()

Как вы понимаете, настройки логов на это не влияют, очень удобно!

Вывод всех SQL запросов в консоль не используя assertNumQueries

До сих пор речь шла об использовании assertNumQueries. Но что если нужно посмотреть запросы вне этого менеджера?

Для этого нужно самому выставить connection.use_debug_cursor = True перед прогоном тестов. Это можно сделать в test runner'е или используя специальный hook в py.test.

SQL во всех тестах: Django 1.4+

Создаем файл test_runner.py, кладем его рядом с settings.py и вставляем такой код:

try:
    from django.test.runner import DiscoverRunner as DjangoTestSuiteRunner
except ImportError:
    # django < 1.6
    from django.test.simple import DjangoTestSuiteRunner
from django.db import connections, DEFAULT_DB_ALIAS

class SqlDebugTestSuiteRunner(DjangoTestSuiteRunner):
    def setup_test_environment(self, **kwargs):
        super(SqlDebugTestSuiteRunner, self).setup_test_environment(**kwargs)
        connections[DEFAULT_DB_ALIAS].use_debug_cursor = True

Теперь либо в settings (или settings_test, если используем его для тестов) указываем наш runner:

TEST_RUNNER = 'project.test_runner.SqlDebugTestSuiteRunner'

Запускаем python manage.py test --settings=project.settings_test и видим все запросы, созданные за время тестов.

Либо можно не задавать TEST_RUNNER, а использовать аргумент --testrunner:

python manage.py test --settings=project.settings_test --testrunner=project.test_runner.SqlDebugTestSuiteRunner

Результат будет тем же.

SQL во всех тестах: Django 1.4+ и django-nose

Для nose почти все так же, только runner нужно унаследовать от NoseTestSuiteRunner.

test_runner.py:

from django_nose import NoseTestSuiteRunner
from django.db import connections, DEFAULT_DB_ALIAS

class SqlDebugTestSuiteRunner(NoseTestSuiteRunner):
    def setup_test_environment(self, **kwargs):
        super(SqlDebugTestSuiteRunner, self).setup_test_environment(**kwargs)
        connections[DEFAULT_DB_ALIAS].use_debug_cursor = True

Да, на момент написания статьи версия django-nose==1.3. В этой версии не поддерживается аргумент --testrunner. Но я отправил пул реквест, возможно, он уже попал в релиз.

SQL во всех тестах: Django 1.4+ и pytest-django

В py.test все немного по другому, ведь там не используется стандартный runner из django. Вместо этого для установления тестового окружения можно использовать py.test хуки.

Создаем файл plugin_debug_sql.py, кладем рядом с settings.py, вставляем код:

def pytest_runtest_setup(item):
    from django.db import connections, DEFAULT_DB_ALIAS
    connections[DEFAULT_DB_ALIAS].use_debug_cursor = True

Запускать так:

PYTHONPATH=`pwd`:$PYTHONPATH py.test -s --ds=sql.settings_test -p project.plugin_debug_sql

Тут я явно добавляю текущую папку в PYTHONPATH, потому что иначе py.test не сможет найти наш плагин.

Опубликовано: Март 4, 2015
Bookmark and Share
Comments powered by Disqus