[PATCH 6 of 6 cubicweb] [debug-toolbar/rql] display sql queries generated by rql ones

Laurent Peuch cortex at worlddomination.be
Thu Oct 24 06:43:43 CEST 2019


# HG changeset patch
# User Laurent Peuch <cortex at worlddomination.be>
# Date 1564684216 -7200
#      Thu Aug 01 20:30:16 2019 +0200
# Node ID 51eb8ccf2bffa75657db5b8b8d5b087e26d31819
# Parent  cb5372119fcee80d2ba07c5b80c4a460540580e1
# Available At https://hg.logilab.org/users/lpeuch/cubicweb
#              hg pull https://hg.logilab.org/users/lpeuch/cubicweb -r 51eb8ccf2bff
[debug-toolbar/rql] display sql queries generated by rql ones

diff --git a/cubicweb/debug.py b/cubicweb/debug.py
--- a/cubicweb/debug.py
+++ b/cubicweb/debug.py
@@ -23,6 +23,7 @@ logger = getLogger('cubicweb')
 
 SUBSCRIBERS = {
     "rql": [],
+    "sql": [],
 }
 
 
diff --git a/cubicweb/pyramid/debug_toolbar_templates/rql.dbtmako b/cubicweb/pyramid/debug_toolbar_templates/rql.dbtmako
--- a/cubicweb/pyramid/debug_toolbar_templates/rql.dbtmako
+++ b/cubicweb/pyramid/debug_toolbar_templates/rql.dbtmako
@@ -5,6 +5,7 @@
             <th class="table-col-2">Time (ms)</th>
             <th class="table-col-3">RQL</th>
             <th class="table-col-5">Result</th>
+            <th class="table-col-6">SQL</th>
             <th class="table-col-7">Description</th>
             <th class="table-col-8">Stack</th>
         </tr>
@@ -29,6 +30,15 @@
                 % else:
                 <td class="table-col-5">${highlight(query["result"], "python3") | n}</td>
                 % endif
+                <td>
+                    % for sql in query["generated_sql_queries"]:
+                    <div class="well" style="padding: 3px">
+                        ${highlight(sql['sql'], "SQL") | n}
+                        <br>
+                        ${highlight(sql['args'], "python3") | n}
+                    </div>
+                    % endfor
+                </td>
                 <td class="table-col-7">${highlight(query["description"], "python3") | n}</td>
                 <td class="table-col-8">
                     <a class="btn btn-default" id="show-stack-${i}" href="javascript:show_stack(${i})">show stack</a>
diff --git a/cubicweb/pyramid/debugtoolbar_panels.py b/cubicweb/pyramid/debugtoolbar_panels.py
--- a/cubicweb/pyramid/debugtoolbar_panels.py
+++ b/cubicweb/pyramid/debugtoolbar_panels.py
@@ -16,6 +16,8 @@
 # You should have received a copy of the GNU Lesser General Public License along
 # with CubicWeb.  If not, see <http://www.gnu.org/licenses/>.
 
+from collections import defaultdict
+
 from pyramid_debugtoolbar.panels import DebugPanel
 from cubicweb.debug import subscribe_to_debug_channel, unsubscribe_to_debug_channel
 from cubicweb.misc.source_highlight import highlight_html, generate_css
@@ -25,6 +27,18 @@ class RQLDebugPanel(DebugPanel):
     """
     CubicWeb RQL debug panel
     """
+
+    """
+    Excepted formats:
+    SQL: {
+        'rql_query_tracing_token': 'some_token',
+        'args': {dict with some args},
+        'rollback': False|True,
+        'time': time_in_float,
+        'sql':_sql_query_as_a_string,
+    }
+    """
+
     name = 'RQL'
     has_content = True
     template = 'cubicweb.pyramid:debug_toolbar_templates/rql.dbtmako'
@@ -32,11 +46,29 @@ class RQLDebugPanel(DebugPanel):
     def __init__(self, request):
         self.data = {'rql_queries': []}
         self.rql_queries = []
+        self.sql_queries = []
         subscribe_to_debug_channel("rql", self.add_debug_message)
+        subscribe_to_debug_channel("sql", self.collect_sql_queries)
 
     def add_debug_message(self, message):
         self.rql_queries.append(message)
 
+    def collect_sql_queries(self, message):
+        self.sql_queries.append(message)
+
+    def link_sql_queries_to_rql_queries(self):
+        sql_to_rql = defaultdict(list)
+        for sql_query in self.sql_queries[:]:
+            sql_to_rql[sql_query['rql_query_tracing_token']].append(sql_query)
+
+        for rql_query in self.rql_queries:
+            rql_query_tracing_token = rql_query['rql_query_tracing_token']
+
+            if rql_query_tracing_token in sql_to_rql:
+                rql_query['generated_sql_queries'] = sql_to_rql[rql_query_tracing_token]
+            else:
+                rql_query['generated_sql_queries'] = []
+
     @property
     def nav_title(self):
         return 'RQL'
@@ -54,14 +86,18 @@ class RQLDebugPanel(DebugPanel):
         return 'RQL queries'
 
     def process_response(self, response):
+        unsubscribe_to_debug_channel("rql", self.add_debug_message)
+        unsubscribe_to_debug_channel("sql", self.collect_sql_queries)
+
         # clear on every new response
         self.data = {
             'rql_queries': self.rql_queries[:],
             'highlight': highlight_html,
             'generate_css': generate_css,
         }
+        self.link_sql_queries_to_rql_queries()
         self.rql_queries = []
-        unsubscribe_to_debug_channel("rql", self.add_debug_message)
+        self.sql_queries = []
 
 
 def includeme(config):
diff --git a/cubicweb/server/sources/native.py b/cubicweb/server/sources/native.py
--- a/cubicweb/server/sources/native.py
+++ b/cubicweb/server/sources/native.py
@@ -24,6 +24,7 @@ from os.path import basename
 import pickle
 import re
 import itertools
+import time
 import zipfile
 import logging
 import sys
@@ -39,6 +40,7 @@ from cubicweb import (UnknownEid, Authen
                       UniqueTogetherError, UndoTransactionException, ViolatedConstraint)
 from cubicweb import transaction as tx, server, neg_role, _
 from cubicweb.utils import QueryCache
+from cubicweb.debug import emit_to_debug_channel
 from cubicweb.schema import VIRTUAL_RTYPES
 from cubicweb.cwconfig import CubicWebNoAppConfiguration
 from cubicweb.server import hook
@@ -684,6 +686,16 @@ class NativeSQLSource(SQLAdapterMixIn, A
         """Execute a query.
         it's a function just so that it shows up in profiling
         """
+
+        query_debug_informations = {
+            "sql": query,
+            "args": args,
+            "rollback": False,
+            "rql_query_tracing_token": rql_query_tracing_token,
+        }
+
+        start = time.time()
+
         cursor = cnx.cnxset.cu
         if server.DEBUG & server.DBG_SQL:
             print('exec', highlight(query, "SQL"), args, cnx.cnxset.cnx)
@@ -699,6 +711,7 @@ class NativeSQLSource(SQLAdapterMixIn, A
             if rollback:
                 try:
                     cnx.cnxset.rollback()
+                    query_debug_informations["rollback"] = True
                     if self.repo.config.mode != 'test':
                         self.debug('transaction has been rolled back')
                 except Exception:
@@ -741,6 +754,9 @@ class NativeSQLSource(SQLAdapterMixIn, A
                         raise ViolatedConstraint(cnx, cstrname=mo.group(1),
                                                  query=query)
             raise
+        finally:
+            query_debug_informations["time"] = (time.time() - start) * 1000
+            emit_to_debug_channel("sql", query_debug_informations)
         return cursor
 
     @statsd_timeit



More information about the cubicweb-devel mailing list