From fb6fa96a73e6f15d3750814942901119ee8270ec Mon Sep 17 00:00:00 2001
From: Daniel Hahler <git@thequod.de>
Date: Sun, 5 May 2019 04:41:11 +0200
Subject: [PATCH] Add django_debug_sql ini option

TODO:

- [ ] doc
- [ ] use a command line option instead?

I've thought about having a fixture also, but it would require to set
"force_debug_cursor" on the connections then, and it probably not
useful; typically you want to use this for a short time only - therefore
a command line option might be better suited also (but you can use `-o
django_debug_sql = 1`).  And on the other hand, it will only show up on
failures, and is therefore maybe good to set it in general.
---
 pytest_django/fixtures.py | 35 ++++++++++++++++++++--
 pytest_django/plugin.py   |  6 ++++
 tests/test_db_debug.py    | 63 +++++++++++++++++++++++++++++++++++++++
 3 files changed, 101 insertions(+), 3 deletions(-)
 create mode 100644 tests/test_db_debug.py

diff --git a/pytest_django/fixtures.py b/pytest_django/fixtures.py
index 519522c80..6f8b9b072 100644
--- a/pytest_django/fixtures.py
+++ b/pytest_django/fixtures.py
@@ -2,6 +2,7 @@
 
 from __future__ import with_statement
 
+import logging
 import os
 import warnings
 from contextlib import contextmanager
@@ -80,6 +81,27 @@ def django_db_createdb(request):
     return request.config.getvalue("create_db")
 
 
+def _setup_sql_debug_logging():
+    # Simulate what Django's DebugSQLTextTestResult does.
+    logger = logging.getLogger('django.db.backends')
+    oldlevel = logger.level
+    logger.setLevel(logging.DEBUG)
+    return oldlevel
+
+
+def _restore_sql_debug_logging(request, oldlevel):
+    logger = logging.getLogger('django.db.backends')
+    if logger.level != logging.DEBUG:
+        request.node.warn(pytest.PytestWarning(
+            "Debug logging level of django.db.backends was changed (to {}). "
+            "SQL queries might be missing.  "
+            "This might be caused by calling django.setup() too late/unnecessarily.".format(
+                logger.level
+            )
+        ))
+    logger.setLevel(oldlevel)
+
+
 @pytest.fixture(scope="session")
 def django_db_setup(
     request,
@@ -95,6 +117,11 @@ def django_db_setup(
 
     setup_databases_args = {}
 
+    debug_sql = request.config.getini("django_debug_sql")
+    if debug_sql:
+        setup_databases_args["debug_sql"] = True
+        old_loglevel = _setup_sql_debug_logging()
+
     if not django_db_use_migrations:
         _disable_native_migrations()
 
@@ -108,7 +135,9 @@ def django_db_setup(
             **setup_databases_args
         )
 
-    def teardown_database():
+    yield
+
+    if not django_db_keepdb:
         with django_db_blocker.unblock():
             try:
                 teardown_databases(db_cfg, verbosity=request.config.option.verbose)
@@ -119,8 +148,8 @@ def teardown_database():
                     )
                 )
 
-    if not django_db_keepdb:
-        request.addfinalizer(teardown_database)
+    if debug_sql:
+        _restore_sql_debug_logging(request, old_loglevel)
 
 
 def _django_db_fixture_helper(
diff --git a/pytest_django/plugin.py b/pytest_django/plugin.py
index 8ac10fb55..5ca453897 100644
--- a/pytest_django/plugin.py
+++ b/pytest_django/plugin.py
@@ -126,6 +126,12 @@ def pytest_addoption(parser):
         type="bool",
         default=True,
     )
+    parser.addini(
+        "django_debug_sql",
+        "Enable logging of SQL statements, displayed with failed tests.",
+        type="bool",
+        default=False,
+    )
     group._addoption(
         "--fail-on-template-vars",
         action="store_true",
diff --git a/tests/test_db_debug.py b/tests/test_db_debug.py
new file mode 100644
index 000000000..17ef08424
--- /dev/null
+++ b/tests/test_db_debug.py
@@ -0,0 +1,63 @@
+def test_debug_sql_setting(django_testdir):
+    django_testdir.create_test_module(
+        """
+        import pytest
+
+        from .app.models import Item
+
+        @pytest.mark.django_db
+        def test_fail_with_db_queries():
+            assert Item.objects.count() == 0
+            assert 0, "triggered failure"
+    """
+    )
+    django_testdir.makeini(
+        """
+       [pytest]
+       django_debug_sql = 1
+    """
+    )
+
+    result = django_testdir.runpytest_subprocess()
+    assert result.ret == 1
+    result.stdout.fnmatch_lines([
+        "*- Captured log setup -*",
+        "*CREATE TABLE*",
+        "*- Captured log call -*",
+        "*SELECT COUNT*",
+    ])
+
+
+def test_debug_sql_with_django_setup(django_testdir):
+    django_testdir.create_test_module(
+        """
+        import pytest
+
+        from .app.models import Item
+
+        @pytest.mark.django_db
+        def test_fail_with_db_queries():
+            import django
+            django.setup()
+
+            assert Item.objects.count() == 0
+            assert 0, "triggered failure"
+    """
+    )
+    django_testdir.makeini(
+        """
+       [pytest]
+       django_debug_sql = 1
+    """
+    )
+
+    result = django_testdir.runpytest_subprocess()
+    assert result.ret == 1
+    result.stdout.fnmatch_lines([
+        # "*- Captured stdout setup -*",
+        "*- Captured log setup -*",
+        "*CREATE TABLE*",
+        "*= warnings summary =*",
+        "*Debug logging level of django.db.backends was changed (to 0).*",
+    ])
+    assert "SELECT COUNT" not in result.stdout.str()