Fixed #24118 -- Added --debug-sql option for tests.

Added a --debug-sql option for tests and runtests.py which outputs the
SQL logger for failing tests. When combined with --verbosity=2, it also
outputs the SQL for passing tests.

Thanks to Berker, Tim, Markus, Shai, Josh and Anssi for review and
discussion.

2 files changed, 109 insertions, 2 deletions

diff --git a/tests/runtests.py b/tests/runtests.py
index 6ff5421772..f742c57bbb 100755
--- a/tests/runtests.py
+++ b/tests/runtests.py
@@ -217,7 +217,7 @@ def teardown(state):
         setattr(settings, key, value)
 
 
-def django_tests(verbosity, interactive, failfast, keepdb, reverse, test_labels):
+def django_tests(verbosity, interactive, failfast, keepdb, reverse, test_labels, debug_sql):
     state = setup(verbosity, test_labels)
     extra_tests = []
 
@@ -232,6 +232,7 @@ def django_tests(verbosity, interactive, failfast, keepdb, reverse, test_labels)
         failfast=failfast,
         keepdb=keepdb,
         reverse=reverse,
+        debug_sql=debug_sql,
     )
     # Catch warnings thrown in test DB setup -- remove in Django 1.9
     with warnings.catch_warnings():
@@ -386,6 +387,9 @@ if __name__ == "__main__":
     parser.add_argument(
         '--selenium', action='store_true', dest='selenium', default=False,
         help='Run the Selenium tests as well (if Selenium is installed)')
+    parser.add_argument(
+        '--debug-sql', action='store_true', dest='debug_sql', default=False,
+        help='Turn on the SQL query logger within tests')
     options = parser.parse_args()
 
     # mock is a required dependency
@@ -421,6 +425,7 @@ if __name__ == "__main__":
     else:
         failures = django_tests(options.verbosity, options.interactive,
                                 options.failfast, options.keepdb,
-                                options.reverse, options.modules)
+                                options.reverse, options.modules,
+                                options.debug_sql)
         if failures:
             sys.exit(bool(failures))
diff --git a/tests/test_runner/test_debug_sql.py b/tests/test_runner/test_debug_sql.py
new file mode 100644
index 0000000000..7bc0950d84
--- /dev/null
+++ b/tests/test_runner/test_debug_sql.py
@@ -0,0 +1,102 @@
+import unittest
+
+from django.db import connection
+from django.test import TestCase
+from django.test.runner import DiscoverRunner
+from django.utils import six
+
+from .models import Person
+
+
+@unittest.skipUnless(connection.vendor == 'sqlite', 'Only run on sqlite so we can check output SQL.')
+class TestDebugSQL(unittest.TestCase):
+
+    class PassingTest(TestCase):
+        def runTest(self):
+            Person.objects.filter(first_name='pass').count()
+
+    class FailingTest(TestCase):
+        def runTest(self):
+            Person.objects.filter(first_name='fail').count()
+            self.fail()
+
+    class ErrorTest(TestCase):
+        def runTest(self):
+            Person.objects.filter(first_name='error').count()
+            raise Exception
+
+    def _test_output(self, verbosity):
+        runner = DiscoverRunner(debug_sql=True, verbosity=0)
+        suite = runner.test_suite()
+        suite.addTest(self.FailingTest())
+        suite.addTest(self.ErrorTest())
+        suite.addTest(self.PassingTest())
+        old_config = runner.setup_databases()
+        stream = six.StringIO()
+        resultclass = runner.get_resultclass()
+        runner.test_runner(
+            verbosity=verbosity,
+            stream=stream,
+            resultclass=resultclass,
+        ).run(suite)
+        runner.teardown_databases(old_config)
+
+        stream.seek(0)
+        return stream.read()
+
+    def test_output_normal(self):
+        full_output = self._test_output(1)
+        for output in self.expected_outputs:
+            self.assertIn(output, full_output)
+        for output in self.verbose_expected_outputs:
+            self.assertNotIn(output, full_output)
+
+    def test_output_verbose(self):
+        full_output = self._test_output(2)
+        for output in self.expected_outputs:
+            self.assertIn(output, full_output)
+        for output in self.verbose_expected_outputs:
+            self.assertIn(output, full_output)
+
+    if six.PY3:
+        expected_outputs = [
+            ('''QUERY = 'SELECT COUNT(%s) AS "__count" '''
+                '''FROM "test_runner_person" WHERE '''
+                '''"test_runner_person"."first_name" = %s' '''
+                '''- PARAMS = ('*', 'error');'''),
+            ('''QUERY = 'SELECT COUNT(%s) AS "__count" '''
+                '''FROM "test_runner_person" WHERE '''
+                '''"test_runner_person"."first_name" = %s' '''
+                '''- PARAMS = ('*', 'fail');'''),
+        ]
+    else:
+        expected_outputs = [
+            ('''QUERY = u'SELECT COUNT(%s) AS "__count" '''
+                '''FROM "test_runner_person" WHERE '''
+                '''"test_runner_person"."first_name" = %s' '''
+                '''- PARAMS = (u'*', u'error');'''),
+            ('''QUERY = u'SELECT COUNT(%s) AS "__count" '''
+                '''FROM "test_runner_person" WHERE '''
+                '''"test_runner_person"."first_name" = %s' '''
+                '''- PARAMS = (u'*', u'fail');'''),
+        ]
+
+    verbose_expected_outputs = [
+        'runTest (test_runner.test_debug_sql.FailingTest) ... FAIL',
+        'runTest (test_runner.test_debug_sql.ErrorTest) ... ERROR',
+        'runTest (test_runner.test_debug_sql.PassingTest) ... ok',
+    ]
+    if six.PY3:
+        verbose_expected_outputs += [
+            ('''QUERY = 'SELECT COUNT(%s) AS "__count" '''
+                '''FROM "test_runner_person" WHERE '''
+                '''"test_runner_person"."first_name" = %s' '''
+                '''- PARAMS = ('*', 'pass');'''),
+        ]
+    else:
+        verbose_expected_outputs += [
+            ('''QUERY = u'SELECT COUNT(%s) AS "__count" '''
+                '''FROM "test_runner_person" WHERE '''
+                '''"test_runner_person"."first_name" = %s' '''
+                '''- PARAMS = (u'*', u'pass');'''),
+        ]