[debug-toolbar/rql] display sql queries generated by rql ones

authorLaurent Peuch <cortex@worlddomination.be>
changeset10b8352b0208
branchdefault
phasepublic
hiddenno
parent revision#d5ae5abd0876 [debug-toolbar/rql] add RQL panel
child revision#f14dde905818 [pyramid/ctl/debugtoolbar] automatically include custom panels on -t
files modified by this revision
cubicweb/debug.py
cubicweb/pyramid/debug_toolbar_templates/rql.dbtmako
cubicweb/pyramid/debugtoolbar_panels.py
cubicweb/server/sources/native.py
# HG changeset patch
# User Laurent Peuch <cortex@worlddomination.be>
# Date 1564684216 -7200
# Thu Aug 01 20:30:16 2019 +0200
# Node ID 10b8352b0208de3f29c37df46dcebef0bf4f49da
# Parent d5ae5abd0876e91f1d935113befe32b56dfe5f80
[debug-toolbar/rql] display sql queries generated by rql ones

diff --git a/cubicweb/debug.py b/cubicweb/debug.py
@@ -21,10 +21,11 @@
1  logger = getLogger('cubicweb')
2 
3 
4  SUBSCRIBERS = {
5      "rql": [],
6 +    "sql": [],
7  }
8 
9 
10  def subscribe_to_debug_channel(channel, subscriber):
11      if channel not in SUBSCRIBERS.keys():
diff --git a/cubicweb/pyramid/debug_toolbar_templates/rql.dbtmako b/cubicweb/pyramid/debug_toolbar_templates/rql.dbtmako
@@ -3,10 +3,11 @@
12          <tr>
13              <th class="table-col-1">#</th>
14              <th class="table-col-2">Time (ms)</th>
15              <th class="table-col-3">RQL</th>
16              <th class="table-col-5">Result</th>
17 +            <th class="table-col-6">SQL</th>
18              <th class="table-col-7">Description</th>
19              <th class="table-col-8">Stack</th>
20          </tr>
21      </thead>
22      <tbody>
@@ -27,10 +28,19 @@
23                      </span>
24                  </td>
25                  % else:
26                  <td class="table-col-5">${highlight(query["result"], "python3") | n}</td>
27                  % endif
28 +                <td>
29 +                    % for sql in query["generated_sql_queries"]:
30 +                    <div class="well" style="padding: 3px">
31 +                        ${highlight(sql['sql'], "SQL") | n}
32 +                        <br>
33 +                        ${highlight(sql['args'], "python3") | n}
34 +                    </div>
35 +                    % endfor
36 +                </td>
37                  <td class="table-col-7">${highlight(query["description"], "python3") | n}</td>
38                  <td class="table-col-8">
39                      <a class="btn btn-default" id="show-stack-${i}" href="javascript:show_stack(${i})">show stack</a>
40                      <a class="btn btn-default" id="hide-stack-${i}" href="javascript:hide_stack(${i})" style="display: none">hide stack</a>
41                  </td>
diff --git a/cubicweb/pyramid/debugtoolbar_panels.py b/cubicweb/pyramid/debugtoolbar_panels.py
@@ -14,19 +14,33 @@
42  # details.
43  #
44  # You should have received a copy of the GNU Lesser General Public License along
45  # with CubicWeb.  If not, see <http://www.gnu.org/licenses/>.
46 
47 +from collections import defaultdict
48 +
49  from pyramid_debugtoolbar.panels import DebugPanel
50  from cubicweb.debug import subscribe_to_debug_channel, unsubscribe_to_debug_channel
51  from cubicweb.misc.source_highlight import highlight_html, generate_css
52 
53 
54  class RQLDebugPanel(DebugPanel):
55      """
56      CubicWeb RQL debug panel
57      """
58 +
59 +    """
60 +    Excepted formats:
61 +    SQL: {
62 +        'rql_query_tracing_token': 'some_token',
63 +        'args': {dict with some args},
64 +        'rollback': False|True,
65 +        'time': time_in_float,
66 +        'sql':_sql_query_as_a_string,
67 +    }
68 +    """
69 +
70      name = 'RQL'
71      title = 'RQL queries'
72      nav_title = 'RQL'
73      nav_subtitle_style = 'progress-bar-info'
74 
@@ -34,23 +48,36 @@
75      template = 'cubicweb.pyramid:debug_toolbar_templates/rql.dbtmako'
76 
77      def __init__(self, request):
78          self.data = {
79              'rql_queries': [],
80 +            'sql_queries': [],
81              'highlight': highlight_html,
82              'generate_css': generate_css,
83          }
84          subscribe_to_debug_channel("rql", self.collect_rql_queries)
85 +        subscribe_to_debug_channel("sql", self.collect_sql_queries)
86 
87      @property
88      def nav_subtitle(self):
89          return '%d' % len(self.data['rql_queries'])
90 
91      def collect_rql_queries(self, rql_query):
92 +        rql_query["generated_sql_queries"] = []
93 +
94 +        # link sql queries to rql's one
95 +        for sql_query in self.data["sql_queries"]:
96 +            if sql_query["rql_query_tracing_token"] == rql_query["rql_query_tracing_token"]:
97 +                rql_query["generated_sql_queries"].append(sql_query)
98 +
99          self.data["rql_queries"].append(rql_query)
100 
101 +    def collect_sql_queries(self, sql_query):
102 +        self.data["sql_queries"].append(sql_query)
103 +
104      def process_response(self, response):
105          unsubscribe_to_debug_channel("rql", self.collect_rql_queries)
106 +        unsubscribe_to_debug_channel("sql", self.collect_sql_queries)
107 
108 
109  def includeme(config):
110      config.add_debugtoolbar_panel(RQLDebugPanel)
diff --git a/cubicweb/server/sources/native.py b/cubicweb/server/sources/native.py
@@ -22,10 +22,11 @@
111  from contextlib import contextmanager
112  from os.path import basename
113  import pickle
114  import re
115  import itertools
116 +import time
117  import zipfile
118  import logging
119  import sys
120 
121  from logilab.common.decorators import cached, clear_cache
@@ -37,10 +38,11 @@
122 
123  from cubicweb import (UnknownEid, AuthenticationError, ValidationError, Binary,
124                        UniqueTogetherError, UndoTransactionException, ViolatedConstraint)
125  from cubicweb import transaction as tx, server, neg_role, _
126  from cubicweb.utils import QueryCache
127 +from cubicweb.debug import emit_to_debug_channel
128  from cubicweb.schema import VIRTUAL_RTYPES
129  from cubicweb.cwconfig import CubicWebNoAppConfiguration
130  from cubicweb.server import hook
131  from cubicweb.server import schema2sql as y2sql
132  from cubicweb.server.utils import crypt_password, verify_and_update
@@ -682,10 +684,20 @@
133      @statsd_timeit
134      def doexec(self, cnx, query, args=None, rollback=True, rql_query_tracing_token=None):
135          """Execute a query.
136          it's a function just so that it shows up in profiling
137          """
138 +
139 +        query_debug_informations = {
140 +            "sql": query,
141 +            "args": args,
142 +            "rollback": False,
143 +            "rql_query_tracing_token": rql_query_tracing_token,
144 +        }
145 +
146 +        start = time.time()
147 +
148          cursor = cnx.cnxset.cu
149          if server.DEBUG & server.DBG_SQL:
150              print('exec', highlight_terminal(query, "SQL"), args, cnx.cnxset.cnx)
151          try:
152              # str(query) to avoid error if it's a unicode string
@@ -697,10 +709,11 @@
153                  self.info("sql: %r\n args: %s\ndbms message: %r",
154                            query, args, ex.args[0])
155              if rollback:
156                  try:
157                      cnx.cnxset.rollback()
158 +                    query_debug_informations["rollback"] = True
159                      if self.repo.config.mode != 'test':
160                          self.debug('transaction has been rolled back')
161                  except Exception:
162                      pass
163              if any(cls.__name__ for cls in ex.__class__.__mro__
@@ -739,10 +752,13 @@
164                      if mo is not None:
165                          # sqlite3 (old)
166                          raise ViolatedConstraint(cnx, cstrname=mo.group(1),
167                                                   query=query)
168              raise
169 +        finally:
170 +            query_debug_informations["time"] = (time.time() - start) * 1000
171 +            emit_to_debug_channel("sql", query_debug_informations)
172          return cursor
173 
174      @statsd_timeit
175      def doexecmany(self, cnx, query, args):
176          """Execute a query.