Fixed #26157 #25321 -- Added sql/params to extra context of schema logger

Thanks Akshesh Doshi for the initial patch and Tim Graham for the review

4 files changed, 32 insertions, 3 deletions

diff --git a/django/db/backends/base/schema.py b/django/db/backends/base/schema.py
index a9d84e114d..0d4082c5c5 100644
--- a/django/db/backends/base/schema.py
+++ b/django/db/backends/base/schema.py
@@ -99,7 +99,7 @@ class BaseDatabaseSchemaEditor(object):
         Executes the given SQL statement, with optional parameters.
         """
         # Log the command we're running, then run it
-        logger.debug("%s; (params %r)", sql, params)
+        logger.debug("%s; (params %r)", sql, params, extra={'params': params, 'sql': sql})
         if self.collect_sql:
             ending = "" if sql.endswith(";") else ";"
             if params is not None:
diff --git a/django/test/utils.py b/django/test/utils.py
index 28b02e2199..7317814e11 100644
--- a/django/test/utils.py
+++ b/django/test/utils.py
@@ -502,7 +502,7 @@ class ignore_warnings(TestContextDecorator):
 
 
 @contextmanager
-def patch_logger(logger_name, log_level):
+def patch_logger(logger_name, log_level, log_kwargs=False):
     """
     Context manager that takes a named logger and the logging level
     and provides a simple mock-like list of messages received
@@ -510,7 +510,8 @@ def patch_logger(logger_name, log_level):
     calls = []
 
     def replacement(msg, *args, **kwargs):
-        calls.append(msg % args)
+        call = msg % args
+        calls.append((call, kwargs) if log_kwargs else call)
     logger = logging.getLogger(logger_name)
     orig = getattr(logger, log_level)
     setattr(logger, log_level, replacement)
diff --git a/docs/topics/logging.txt b/docs/topics/logging.txt
index 9cb1da45b4..554acf2514 100644
--- a/docs/topics/logging.txt
+++ b/docs/topics/logging.txt
@@ -583,6 +583,13 @@ specific logger following this example:
 Logs the SQL queries that are executed during schema changes to the database by
 the :doc:`migrations framework </topics/migrations>`. Note that it won't log the
 queries executed by :class:`~django.db.migrations.operations.RunPython`.
+Messages to this logger have ``params`` and ``sql`` in their extra context (but
+unlike ``django.db.backends``, not duration). The values have the same meaning
+as explained in :ref:`django-db-logger`.
+
+.. versionadded:: 1.10
+
+    The ``extra`` context was added.
 
 Handlers
 --------
diff --git a/tests/logging_tests/tests.py b/tests/logging_tests/tests.py
index 8864786f28..eb90b54430 100644
--- a/tests/logging_tests/tests.py
+++ b/tests/logging_tests/tests.py
@@ -9,6 +9,7 @@ from admin_scripts.tests import AdminScriptTestCase
 from django.conf import settings
 from django.core import mail
 from django.core.files.temp import NamedTemporaryFile
+from django.db import connection
 from django.test import RequestFactory, SimpleTestCase, override_settings
 from django.test.utils import LoggingCaptureMixin, patch_logger
 from django.utils.deprecation import RemovedInNextVersionWarning
@@ -475,3 +476,23 @@ format=%(message)s
         out, err = self.run_manage(['check'])
         self.assertNoOutput(err)
         self.assertOutput(out, "System check identified no issues (0 silenced).")
+
+
+class SchemaLoggerTests(SimpleTestCase):
+
+    def test_extra_args(self):
+        editor = connection.schema_editor(collect_sql=True)
+        sql = "SELECT * FROM foo WHERE id in (%s, %s)"
+        params = [42, 1337]
+        with patch_logger('django.db.backends.schema', 'debug', log_kwargs=True) as logger:
+            editor.execute(sql, params)
+        self.assertEqual(
+            logger,
+            [(
+                'SELECT * FROM foo WHERE id in (%s, %s); (params [42, 1337])',
+                {'extra': {
+                    'sql': 'SELECT * FROM foo WHERE id in (%s, %s)',
+                    'params': [42, 1337],
+                }},
+            )]
+        )