Fix BEGIN leaking into SQL panel when using DatabaseCache store

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)
 

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
 

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"
     )