diff --git a/debug_toolbar/panels/sql/tracking.py b/debug_toolbar/panels/sql/tracking.py index 046b254a5..10c3b2526 100644 --- a/debug_toolbar/panels/sql/tracking.py +++ b/debug_toolbar/panels/sql/tracking.py @@ -46,6 +46,21 @@ # additional queries. allow_sql = contextvars.ContextVar("debug-toolbar-allow-sql", default=True) +# Whether SQL queries should be recorded by the toolbar. Set to False +# while the toolbar persists its own data (e.g. the DatabaseCache store), +# so internal queries like BEGIN/COMMIT don't leak into the SQL panel. +sql_recording = contextvars.ContextVar("debug-toolbar-sql-recording", default=True) + + +@contextlib.contextmanager +def no_sql_recording(): + """Context manager to temporarily disable SQL recording.""" + token = sql_recording.set(False) + try: + yield + finally: + sql_recording.reset(token) + DDT_MODELS = { m._meta.db_table for m in apps.get_app_config("debug_toolbar").get_models() @@ -203,74 +218,88 @@ def _record(self, method, sql, params): stop_time = perf_counter() duration = (stop_time - start_time) * 1000 _params = None - with contextlib.suppress(TypeError): - # Decode params - binary data will be handled by DebugToolbarJSONEncoder - # in store.py when the panel data is serialized - _params = self._decode(params) - template_info = get_template_info() - - # Sql might be an object (such as psycopg Composed). - # For logging purposes, make sure it's str. - if vendor == "postgresql" and not isinstance(sql, str): - if isinstance(sql, bytes): - sql = sql.decode("utf-8") - else: - sql = sql.as_string(conn) + + # Skip tracking for toolbar models by default. + # This can be overridden by setting SKIP_TOOLBAR_QUERIES = False + skip_toolbar_queries = dt_settings.get_config()["SKIP_TOOLBAR_QUERIES"] + if sql_recording.get(): + should_record = not skip_toolbar_queries or not any( + table in sql for table in DDT_MODELS + ) else: - sql = str(sql) - - kwargs = { - "vendor": vendor, - "alias": alias, - "sql": self._last_executed_query(sql, params), - "duration": duration, - "raw_sql": sql, - "params": _params, - "stacktrace": get_stack_trace(skip=2), - "template_info": template_info, - } + # Inside tracking.no_sql_recording(): only let through queries + # that mention a known toolbar table, so SKIP_TOOLBAR_QUERIES + # keeps deciding those. Table-less commands (e.g. the BEGIN/ + # COMMIT issued by the toolbar's own persistence calls) stay + # hidden either way (issue #2338). + should_record = not skip_toolbar_queries and any( + table in sql for table in DDT_MODELS + ) - if vendor == "postgresql": - # If an erroneous query was ran on the connection, it might - # be in a state where checking isolation_level raises an - # exception. - try: - iso_level = conn.isolation_level - except conn.InternalError: - iso_level = "unknown" - # PostgreSQL does not expose any sort of transaction ID, so it is - # necessary to generate synthetic transaction IDs here. If the - # connection was not in a transaction when the query started, and was - # after the query finished, a new transaction definitely started, so get - # a new transaction ID from logger.new_transaction_id(). If the query - # was in a transaction both before and after executing, make the - # assumption that it is the same transaction and get the current - # transaction ID from logger.current_transaction_id(). There is an edge - # case where Django can start a transaction before the first query - # executes, so in that case logger.current_transaction_id() will - # generate a new transaction ID since one does not already exist. - final_conn_status = conn.info.transaction_status - if final_conn_status == STATUS_IN_TRANSACTION: - if initial_conn_status == STATUS_IN_TRANSACTION: - trans_id = self.logger.current_transaction_id(alias) + if should_record: + with contextlib.suppress(TypeError): + # Decode params - binary data will be handled by DebugToolbarJSONEncoder + # in store.py when the panel data is serialized + _params = self._decode(params) + template_info = get_template_info() + + # Sql might be an object (such as psycopg Composed). + # For logging purposes, make sure it's str. + if vendor == "postgresql" and not isinstance(sql, str): + if isinstance(sql, bytes): + sql = sql.decode("utf-8") else: - trans_id = self.logger.new_transaction_id(alias) + sql = sql.as_string(conn) else: - trans_id = None - - kwargs.update( - { - "trans_id": trans_id, - "trans_status": conn.info.transaction_status, - "iso_level": iso_level, - } - ) + sql = str(sql) + + kwargs = { + "vendor": vendor, + "alias": alias, + "sql": self._last_executed_query(sql, params), + "duration": duration, + "raw_sql": sql, + "params": _params, + "stacktrace": get_stack_trace(skip=2), + "template_info": template_info, + } + + if vendor == "postgresql": + # If an erroneous query was ran on the connection, it might + # be in a state where checking isolation_level raises an + # exception. + try: + iso_level = conn.isolation_level + except conn.InternalError: + iso_level = "unknown" + # PostgreSQL does not expose any sort of transaction ID, so it is + # necessary to generate synthetic transaction IDs here. If the + # connection was not in a transaction when the query started, and was + # after the query finished, a new transaction definitely started, so get + # a new transaction ID from logger.new_transaction_id(). If the query + # was in a transaction both before and after executing, make the + # assumption that it is the same transaction and get the current + # transaction ID from logger.current_transaction_id(). There is an edge + # case where Django can start a transaction before the first query + # executes, so in that case logger.current_transaction_id() will + # generate a new transaction ID since one does not already exist. + final_conn_status = conn.info.transaction_status + if final_conn_status == STATUS_IN_TRANSACTION: + if initial_conn_status == STATUS_IN_TRANSACTION: + trans_id = self.logger.current_transaction_id(alias) + else: + trans_id = self.logger.new_transaction_id(alias) + else: + trans_id = None + + kwargs.update( + { + "trans_id": trans_id, + "trans_status": conn.info.transaction_status, + "iso_level": iso_level, + } + ) - # Skip tracking for toolbar models by default. - # This can be overridden by setting SKIP_TOOLBAR_QUERIES = False - if not dt_settings.get_config()["SKIP_TOOLBAR_QUERIES"] or not any( - table in sql for table in DDT_MODELS - ): # We keep `sql` to maintain backwards compatibility self.logger.record(**kwargs) diff --git a/debug_toolbar/store.py b/debug_toolbar/store.py index 6f6253cef..5acf3256a 100644 --- a/debug_toolbar/store.py +++ b/debug_toolbar/store.py @@ -206,7 +206,9 @@ def exists(cls, request_id: str) -> bool: @classmethod def set(cls, request_id: str): """Set a request_id in the store and clean up old entries""" - with transaction.atomic(): + from debug_toolbar.panels.sql.tracking import no_sql_recording + + with no_sql_recording(), transaction.atomic(): # Create the entry if it doesn't exist (ignore otherwise) _, created = HistoryEntry.objects.get_or_create(request_id=request_id) @@ -227,7 +229,9 @@ def delete(cls, request_id: str): @classmethod def save_panel(cls, request_id: str, panel_id: str, data: Any = None): """Save the panel data for the given request_id""" - with transaction.atomic(): + from debug_toolbar.panels.sql.tracking import no_sql_recording + + with no_sql_recording(), transaction.atomic(): obj, _ = HistoryEntry.objects.get_or_create(request_id=request_id) store_data = obj.data store_data[panel_id] = serialize(data) @@ -276,10 +280,13 @@ def __getattr__(self, name): @functools.wraps(attr) def untracked(*args, **kwargs): + from debug_toolbar.panels.sql.tracking import no_sql_recording + panel = getattr(self._cache, "_djdt_panel", None) self._cache._djdt_panel = None try: - return attr(*args, **kwargs) + with no_sql_recording(): + return attr(*args, **kwargs) finally: self._cache._djdt_panel = panel diff --git a/tests/panels/test_sql.py b/tests/panels/test_sql.py index efddc4214..1f05fb310 100644 --- a/tests/panels/test_sql.py +++ b/tests/panels/test_sql.py @@ -1,4 +1,5 @@ import asyncio +import contextlib import datetime import os import unittest @@ -225,6 +226,88 @@ async def test_toolbar_model_query_is_not_tracked_async(self): self.assertEqual(len(self.panel._queries), 0) + def test_no_sql_recording_suppresses_queries_without_known_table(self): + """ + Queries that don't reference any toolbar table (e.g. the BEGIN/COMMIT + emitted by transaction.atomic()) carry no table name, so + SKIP_TOOLBAR_QUERIES can never filter them on its own. They must be + suppressed while inside tracking.no_sql_recording(). + """ + self.assertEqual(len(self.panel._queries), 0) + + with tracking.no_sql_recording(): + with connection.cursor() as cursor: + cursor.execute("SELECT 1") + + self.assertEqual(len(self.panel._queries), 0) + + def test_no_sql_recording_does_not_affect_queries_outside_the_block(self): + """ + sql_recording must be restored once the block exits, even though + no exception was raised, so normal application queries keep being + tracked afterwards. + """ + with tracking.no_sql_recording(): + pass + + sql_call() + + self.assertEqual(len(self.panel._queries), 1) + + def test_no_sql_recording_restores_state_even_on_exception(self): + """sql_recording must be restored even if the block raises.""" + with contextlib.suppress(ValueError): + with tracking.no_sql_recording(): + raise ValueError("boom") + + sql_call() + + self.assertEqual(len(self.panel._queries), 1) + + @override_settings( + DEBUG_TOOLBAR_CONFIG={ + "SKIP_TOOLBAR_QUERIES": False, + "TOOLBAR_STORE_CLASS": "debug_toolbar.store.DatabaseStore", + } + ) + def test_no_sql_recording_does_not_override_skip_toolbar_queries_false(self): + """ + SKIP_TOOLBAR_QUERIES=False asks to see queries that touch the + toolbar's own tables. That choice must win over sql_recording=False + for queries that DO mention a known table, even while inside + tracking.no_sql_recording() (e.g. the toolbar persisting its own + data while the user is debugging the toolbar itself). + """ + self.assertEqual(len(self.panel._queries), 0) + + patch_tracking_ddt_models() + with tracking.no_sql_recording(): + sql_call_toolbar_model() + + self.assertEqual(len(self.panel._queries), 1) + query = self.panel._queries[0] + self.assertTrue(HistoryEntry._meta.db_table in query["sql"]) + + @override_settings( + DEBUG_TOOLBAR_CONFIG={ + "SKIP_TOOLBAR_QUERIES": True, + "TOOLBAR_STORE_CLASS": "debug_toolbar.store.DatabaseStore", + } + ) + def test_no_sql_recording_combined_with_skip_toolbar_queries_true(self): + """ + With the default SKIP_TOOLBAR_QUERIES=True, toolbar-table queries + stay hidden whether or not they're also inside + tracking.no_sql_recording(). + """ + self.assertEqual(len(self.panel._queries), 0) + + patch_tracking_ddt_models() + with tracking.no_sql_recording(): + sql_call_toolbar_model() + + self.assertEqual(len(self.panel._queries), 0) + @unittest.skipUnless( connection.vendor == "postgresql", "Test valid only on PostgreSQL" ) diff --git a/tests/test_store.py b/tests/test_store.py index d8fd1e047..9a985a56d 100644 --- a/tests/test_store.py +++ b/tests/test_store.py @@ -6,7 +6,7 @@ from django.core.management import call_command from django.db import connection from django.http import HttpResponse -from django.test import RequestFactory, TestCase +from django.test import RequestFactory, TestCase, TransactionTestCase from django.test.utils import CaptureQueriesContext, override_settings from django.utils.safestring import SafeData, mark_safe @@ -538,3 +538,131 @@ def test_database_backend_can_be_tracked_by_sql_panel(self): self.assertEqual(len(cache_queries), 4) finally: sql_panel.disable_instrumentation() + + @staticmethod + def _transaction_control_queries(queries): + """ + Return the queries that are pure transaction-control commands + (BEGIN/COMMIT, or SAVEPOINT/RELEASE SAVEPOINT when already inside a + transaction, as happens under TestCase). These carry no table name, + so SKIP_TOOLBAR_QUERIES can never filter them by itself (issue #2338). + """ + return [ + q + for q in queries + if q.get("raw_sql", "") + .strip() + .upper() + .startswith( + ("BEGIN", "COMMIT", "SAVEPOINT", "RELEASE SAVEPOINT", "ROLLBACK") + ) + ] + + def test_database_backend_transaction_control_not_tracked_by_sql_panel(self): + """ + Regression test for #2338: the transaction.atomic() control commands + issued while CacheStore persists data to a DatabaseCache table must + not leak into the SQL panel. + """ + request = RequestFactory().get("/") + toolbar = DebugToolbar(request, lambda req: HttpResponse()) + sql_panel = toolbar.get_panel_by_id("SQLPanel") + sql_panel.enable_instrumentation() + + try: + self.store.set("test_req") + + leaked = self._transaction_control_queries(sql_panel._queries) + self.assertEqual(leaked, []) + finally: + sql_panel.disable_instrumentation() + + @override_settings( + DEBUG_TOOLBAR_CONFIG={ + "TOOLBAR_STORE_CLASS": "debug_toolbar.store.CacheStore", + "CACHE_BACKEND": "ddt_db_cache", + "SKIP_TOOLBAR_QUERIES": False, + }, + ) + def test_database_backend_transaction_control_hidden_even_with_skip_toolbar_queries_false( + self, + ): + """ + SKIP_TOOLBAR_QUERIES=False is meant to reveal queries that touch the + toolbar's own tables. It must not resurrect the table-less + BEGIN/COMMIT (or SAVEPOINT) control commands, while the actual + cache table queries should still be visible. + """ + request = RequestFactory().get("/") + toolbar = DebugToolbar(request, lambda req: HttpResponse()) + sql_panel = toolbar.get_panel_by_id("SQLPanel") + sql_panel.enable_instrumentation() + + try: + self.store.set("test_req") + + leaked = self._transaction_control_queries(sql_panel._queries) + self.assertEqual(leaked, []) + + table_queries = [ + q + for q in sql_panel._queries + if "test_cache_store_table" in q.get("sql", "").lower() + ] + self.assertGreater(len(table_queries), 0) + finally: + sql_panel.disable_instrumentation() + + +@override_settings( + DEBUG_TOOLBAR_CONFIG={ + "TOOLBAR_STORE_CLASS": "debug_toolbar.store.CacheStore", + "CACHE_BACKEND": "ddt_db_cache_autocommit", + }, + CACHES={ + "ddt_db_cache_autocommit": { + "BACKEND": "django.core.cache.backends.db.DatabaseCache", + "LOCATION": "autocommit_cache_store_table", + } + }, +) +class CacheStoreWithDatabaseBackendAutocommitTestCase(TransactionTestCase): + """ + Regression test for #2338, reproducing the exact scenario reported in + the issue: in autocommit mode -- i.e. outside any wrapping transaction, + as happens during a real request, unlike under TestCase which already + wraps each test in a transaction -- transaction.atomic() emits a literal + BEGIN (and COMMIT), not a SAVEPOINT. Those commands carry no table name + and must not leak into the SQL panel. + """ + + @classmethod + def setUpClass(cls): + super().setUpClass() + call_command("createcachetable", "autocommit_cache_store_table", verbosity=0) + + @classmethod + def tearDownClass(cls): + with connection.cursor() as cursor: + cursor.execute("DROP TABLE IF EXISTS autocommit_cache_store_table") + super().tearDownClass() + + def tearDown(self): + store.CacheStore.clear() + + def test_begin_and_commit_not_tracked_by_sql_panel(self): + request = RequestFactory().get("/") + toolbar = DebugToolbar(request, lambda req: HttpResponse()) + sql_panel = toolbar.get_panel_by_id("SQLPanel") + sql_panel.enable_instrumentation() + + try: + store.CacheStore.set("test_req") + + raw_sqls = [ + q.get("raw_sql", "").strip().upper() for q in sql_panel._queries + ] + self.assertNotIn("BEGIN", raw_sqls) + self.assertNotIn("COMMIT", raw_sqls) + finally: + sql_panel.disable_instrumentation()