From fa35c8bdbc6aca65d94d6280fa463d5bc7baa5c0 Mon Sep 17 00:00:00 2001 From: Nick Pope Date: Fri, 2 Jul 2021 14:36:53 +0100 Subject: [PATCH] Fixed #30934 -- Included database alias in django.db.backends log messages. This is useful when working with database routing as you want to know where each query is being executed. Co-authored-by: David Winterbottom --- AUTHORS | 1 + django/db/backends/utils.py | 5 +++-- docs/ref/logging.txt | 5 +++++ docs/releases/4.0.txt | 3 ++- tests/backends/tests.py | 18 ++++++++++++++++++ 5 files changed, 29 insertions(+), 3 deletions(-) diff --git a/AUTHORS b/AUTHORS index 84cbf17c27..6a2224110f 100644 --- a/AUTHORS +++ b/AUTHORS @@ -251,6 +251,7 @@ answer newbie questions, and generally made Django that much better: David Sanders David Schein David Tulig + David Winterbottom David Wobrock Davide Ceretti Deep L. Sukhwani diff --git a/django/db/backends/utils.py b/django/db/backends/utils.py index 45c03ba3e9..c342cf79b5 100644 --- a/django/db/backends/utils.py +++ b/django/db/backends/utils.py @@ -121,11 +121,12 @@ class CursorDebugWrapper(CursorWrapper): 'time': '%.3f' % duration, }) logger.debug( - '(%.3f) %s; args=%s', + '(%.3f) %s; args=%s; alias=%s', duration, sql, params, - extra={'duration': duration, 'sql': sql, 'params': params}, + self.db.alias, + extra={'duration': duration, 'sql': sql, 'params': params, 'alias': self.db.alias}, ) diff --git a/docs/ref/logging.txt b/docs/ref/logging.txt index e60583c41c..8c682dfceb 100644 --- a/docs/ref/logging.txt +++ b/docs/ref/logging.txt @@ -178,6 +178,7 @@ Messages to this logger have the following extra context: * ``duration``: The time taken to execute the SQL statement. * ``sql``: The SQL statement that was executed. * ``params``: The parameters that were used in the SQL call. +* ``alias``: The alias of the database used in the SQL call. For performance reasons, SQL logging is only enabled when ``settings.DEBUG`` is set to ``True``, regardless of the logging @@ -188,6 +189,10 @@ This logging does not include framework-level initialization (e.g. ``COMMIT``, and ``ROLLBACK``). Turn on query logging in your database if you wish to view all database queries. +.. versionchanged:: 4.0 + + The database ``alias`` was added to log messages. + .. _django-security-logger: ``django.security.*`` diff --git a/docs/releases/4.0.txt b/docs/releases/4.0.txt index c1e64c499a..54d0fd4c1d 100644 --- a/docs/releases/4.0.txt +++ b/docs/releases/4.0.txt @@ -226,7 +226,8 @@ Internationalization Logging ~~~~~~~ -* ... +* The alias of the database used in an SQL call is now passed as extra context + along with each message to the :ref:`django-db-logger` logger. Management Commands ~~~~~~~~~~~~~~~~~~~ diff --git a/tests/backends/tests.py b/tests/backends/tests.py index d335aaefbc..1536e93065 100644 --- a/tests/backends/tests.py +++ b/tests/backends/tests.py @@ -3,6 +3,7 @@ import datetime import threading import unittest import warnings +from unittest import mock from django.core.management.color import no_style from django.db import ( @@ -491,6 +492,23 @@ class BackendTestCase(TransactionTestCase): BaseDatabaseWrapper.queries_limit = old_queries_limit new_connection.close() + @mock.patch('django.db.backends.utils.logger') + @override_settings(DEBUG=True) + def test_queries_logger(self, mocked_logger): + sql = 'SELECT 1' + connection.features.bare_select_suffix + with connection.cursor() as cursor: + cursor.execute(sql) + params, kwargs = mocked_logger.debug.call_args + self.assertIn('; alias=%s', params[0]) + self.assertEqual(params[2], sql) + self.assertEqual(params[3], None) + self.assertEqual(params[4], connection.alias) + self.assertEqual( + list(kwargs['extra']), + ['duration', 'sql', 'params', 'alias'], + ) + self.assertEqual(tuple(kwargs['extra'].values()), params[1:]) + def test_timezone_none_use_tz_false(self): connection.ensure_connection() with self.settings(TIME_ZONE=None, USE_TZ=False):