From f97ff555a4d8f22dae83bcfd0c2dcf6e846962c9 Mon Sep 17 00:00:00 2001 From: Rob Hudson Date: Fri, 28 Aug 2009 09:21:39 -0700 Subject: Refactored SQL panel to use datetime objects and added a visual display of both duration and sequence to the SQL template. --- debug_toolbar/media/debug_toolbar/toolbar.css | 21 ++++++++++++++ debug_toolbar/panels/sql.py | 33 ++++++++++++++++++---- .../templates/debug_toolbar/panels/sql.html | 15 ++++++---- .../debug_toolbar/panels/sql_explain.html | 4 +-- .../debug_toolbar/panels/sql_profile.html | 4 +-- .../templates/debug_toolbar/panels/sql_select.html | 4 +-- debug_toolbar/views.py | 12 ++++---- 7 files changed, 70 insertions(+), 23 deletions(-) (limited to 'debug_toolbar') diff --git a/debug_toolbar/media/debug_toolbar/toolbar.css b/debug_toolbar/media/debug_toolbar/toolbar.css index ad23f22..c1fd4b0 100644 --- a/debug_toolbar/media/debug_toolbar/toolbar.css +++ b/debug_toolbar/media/debug_toolbar/toolbar.css @@ -336,6 +336,27 @@ cursor:pointer; } +#djDebug .djDebugSqlWrap { + position:relative; +} + +#djDebug .djDebugSql { + z-index:100000002; +} + +#djDebug span.djDebugLineChart { + border-top:3px solid #777; + position:absolute; + bottom:0; + top:0; + left:0; + display:block; + z-index:1000000001; +} +#djDebug span.djDebugLineChartWarning { + border-top-color:#900; +} + #djDebug .highlight { color:#000; } #djDebug .highlight .err { color:#000; } /* Error */ #djDebug .highlight .g { color:#000; } /* Generic */ diff --git a/debug_toolbar/panels/sql.py b/debug_toolbar/panels/sql.py index f12939e..62c0e58 100644 --- a/debug_toolbar/panels/sql.py +++ b/debug_toolbar/panels/sql.py @@ -1,6 +1,6 @@ import os import SocketServer -import time +from datetime import datetime import traceback import django from django.conf import settings @@ -16,6 +16,10 @@ from debug_toolbar.panels import DebugPanel django_path = os.path.realpath(os.path.dirname(django.__file__)) socketserver_path = os.path.realpath(os.path.dirname(SocketServer.__file__)) +# TODO:This should be set in the toolbar loader as a default and panels should +# get a copy of the toolbar object with access to its config dictionary +SQL_WARNING_THRESHOLD = getattr(settings, 'DEBUG_TOOLBAR_CONFIG', {}).get('SQL_WARNING_THRESHOLD', 500) + def tidy_stacktrace(strace): """ Clean up stacktrace and remove all entries that: @@ -39,11 +43,12 @@ class DatabaseStatTracker(util.CursorDebugWrapper): in `connection.queries`. """ def execute(self, sql, params=()): - start = time.time() + start = datetime.now() try: return self.cursor.execute(sql, params) finally: - stop = time.time() + stop = datetime.now() + duration = ms_from_timedelta(stop - start) stacktrace = tidy_stacktrace(traceback.extract_stack()) _params = '' try: @@ -53,11 +58,14 @@ class DatabaseStatTracker(util.CursorDebugWrapper): # We keep `sql` to maintain backwards compatibility self.db.queries.append({ 'sql': self.db.ops.last_executed_query(self.cursor, sql, params), - 'time': (stop - start) * 1000, # convert to ms + 'duration': duration, 'raw_sql': sql, 'params': _params, 'hash': sha_constructor(settings.SECRET_KEY + sql + _params).hexdigest(), 'stacktrace': stacktrace, + 'start_time': start, + 'stop_time': stop, + 'is_slow': (duration > SQL_WARNING_THRESHOLD) }) util.CursorDebugWrapper = DatabaseStatTracker @@ -77,14 +85,14 @@ class SQLDebugPanel(DebugPanel): return 'SQL' def nav_subtitle(self): - self._sql_time = sum(map(lambda q: float(q['time']), connection.queries)) + self._sql_time = sum([q['duration'] for q in connection.queries[self._offset:]]) num_queries = len(connection.queries) - self._offset return "%d %s in %.2fms" % ( num_queries, (num_queries == 1) and 'query' or 'queries', self._sql_time ) - + def title(self): return 'SQL Queries' @@ -93,8 +101,15 @@ class SQLDebugPanel(DebugPanel): def content(self): sql_queries = connection.queries[self._offset:] + width_ratio_tally = 0 for query in sql_queries: query['sql'] = reformat_sql(query['sql']) + try: + query['width_ratio'] = (query['duration'] / self._sql_time) * 100 + except ZeroDivisionError: + query['width_ratio'] = 0 + query['start_offset'] = width_ratio_tally + width_ratio_tally += query['width_ratio'] context = { 'queries': sql_queries, @@ -103,6 +118,12 @@ class SQLDebugPanel(DebugPanel): } return render_to_string('debug_toolbar/panels/sql.html', context) +def ms_from_timedelta(td): + """ + Given a timedelta object, returns a float representing milliseconds + """ + return (td.seconds * 1000) + (td.microseconds / 1000.0) + def reformat_sql(sql): sql = sql.replace(',', ', ') sql = sql.replace('SELECT ', 'SELECT\n\t') diff --git a/debug_toolbar/templates/debug_toolbar/panels/sql.html b/debug_toolbar/templates/debug_toolbar/panels/sql.html index 7aa4c2d..9c8bfa6 100644 --- a/debug_toolbar/templates/debug_toolbar/panels/sql.html +++ b/debug_toolbar/templates/debug_toolbar/panels/sql.html @@ -11,13 +11,13 @@ {% for query in queries %} - {{ query.time|floatformat:"2" }} + {{ query.duration|floatformat:"2" }} {% if query.params %} - SELECT - EXPLAIN + SELECT + EXPLAIN {% if is_mysql %} - PROFILE + PROFILE {% endif %} {% endif %} @@ -42,7 +42,12 @@ {% endif %} - {{ query.sql|safe }} + +
+
{{ query.sql|safe }}
+ +
+ {% endfor %} diff --git a/debug_toolbar/templates/debug_toolbar/panels/sql_explain.html b/debug_toolbar/templates/debug_toolbar/panels/sql_explain.html index 38249b3..a21ec59 100644 --- a/debug_toolbar/templates/debug_toolbar/panels/sql_explain.html +++ b/debug_toolbar/templates/debug_toolbar/panels/sql_explain.html @@ -6,9 +6,9 @@
{% trans "Executed SQL" %}
- 
{{ sql|safe }}
+
{{ sql|safe }}
{% trans "Time" %}
-
{{ time }} ms
+
{{ duration }} ms
diff --git a/debug_toolbar/templates/debug_toolbar/panels/sql_profile.html b/debug_toolbar/templates/debug_toolbar/panels/sql_profile.html index 0dcb0b9..a15574e 100644 --- a/debug_toolbar/templates/debug_toolbar/panels/sql_profile.html +++ b/debug_toolbar/templates/debug_toolbar/panels/sql_profile.html @@ -7,9 +7,9 @@ {% if result %}
{% trans "Executed SQL" %}
- 
{{ sql|safe }}
+
{{ sql|safe }}
{% trans "Time" %}
-
{{ time }} ms
+
{{ duration }} ms
diff --git a/debug_toolbar/templates/debug_toolbar/panels/sql_select.html b/debug_toolbar/templates/debug_toolbar/panels/sql_select.html index e4d6027..66835c8 100644 --- a/debug_toolbar/templates/debug_toolbar/panels/sql_select.html +++ b/debug_toolbar/templates/debug_toolbar/panels/sql_select.html @@ -6,9 +6,9 @@
{% trans "Executed SQL" %}
- 
{{ sql|safe }}
+
{{ sql|safe }}
{% trans "Time" %}
-
{{ time }} ms
+
{{ duration }} ms
{% if result %}
diff --git a/debug_toolbar/views.py b/debug_toolbar/views.py index 255a49c..3a8cb79 100644 --- a/debug_toolbar/views.py +++ b/debug_toolbar/views.py @@ -33,7 +33,7 @@ def sql_select(request): Expected GET variables: sql: urlencoded sql with positional arguments params: JSON encoded parameter values - time: time for SQL to execute passed in from toolbar just for redisplay + duration: time for SQL to execute passed in from toolbar just for redisplay hash: the hash of (secret + sql + params) for tamper checking """ from debug_toolbar.panels.sql import reformat_sql @@ -52,7 +52,7 @@ def sql_select(request): context = { 'result': result, 'sql': reformat_sql(cursor.db.ops.last_executed_query(cursor, sql, params)), - 'time': request.GET.get('time', 0.0), + 'duration': request.GET.get('duration', 0.0), 'headers': headers, } return render_to_response('debug_toolbar/panels/sql_select.html', context) @@ -65,7 +65,7 @@ def sql_explain(request): Expected GET variables: sql: urlencoded sql with positional arguments params: JSON encoded parameter values - time: time for SQL to execute passed in from toolbar just for redisplay + duration: time for SQL to execute passed in from toolbar just for redisplay hash: the hash of (secret + sql + params) for tamper checking """ from debug_toolbar.panels.sql import reformat_sql @@ -84,7 +84,7 @@ def sql_explain(request): context = { 'result': result, 'sql': reformat_sql(cursor.db.ops.last_executed_query(cursor, sql, params)), - 'time': request.GET.get('time', 0.0), + 'duration': request.GET.get('duration', 0.0), 'headers': headers, } return render_to_response('debug_toolbar/panels/sql_explain.html', context) @@ -97,7 +97,7 @@ def sql_profile(request): Expected GET variables: sql: urlencoded sql with positional arguments params: JSON encoded parameter values - time: time for SQL to execute passed in from toolbar just for redisplay + duration: time for SQL to execute passed in from toolbar just for redisplay hash: the hash of (secret + sql + params) for tamper checking """ from debug_toolbar.panels.sql import reformat_sql @@ -127,7 +127,7 @@ def sql_profile(request): 'result': result, 'result_error': result_error, 'sql': reformat_sql(cursor.db.ops.last_executed_query(cursor, sql, params)), - 'time': request.GET.get('time', 0.0), + 'duration': request.GET.get('duration', 0.0), 'headers': headers, } return render_to_response('debug_toolbar/panels/sql_profile.html', context) -- cgit v1.2.3