From 1cb65b8a77bd1b15f094b5857468c107784aad90 Mon Sep 17 00:00:00 2001 From: Markus Holtermann Date: Mon, 14 Mar 2016 21:38:38 +1100 Subject: [PATCH] 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 --- django/db/backends/base/schema.py | 2 +- django/test/utils.py | 5 +++-- docs/topics/logging.txt | 7 +++++++ tests/logging_tests/tests.py | 21 +++++++++++++++++++++ 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 `. 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], + }}, + )] + )