diff options
Diffstat (limited to 'debug_toolbar/panels')
| -rw-r--r-- | debug_toolbar/panels/logger.py | 83 | ||||
| -rw-r--r-- | debug_toolbar/panels/sql.py | 108 |
2 files changed, 164 insertions, 27 deletions
diff --git a/debug_toolbar/panels/logger.py b/debug_toolbar/panels/logger.py index 620102e..5e82a13 100644 --- a/debug_toolbar/panels/logger.py +++ b/debug_toolbar/panels/logger.py @@ -8,16 +8,21 @@ from django.template.loader import render_to_string from django.utils.translation import ugettext_lazy as _ from debug_toolbar.panels import DebugPanel -class ThreadTrackingHandler(logging.Handler): + +class LogCollector(object): def __init__(self): if threading is None: raise NotImplementedError("threading module is not available, \ the logging panel cannot be used without it") - logging.Handler.__init__(self) self.records = {} # a dictionary that maps threads to log records - def emit(self, record): - self.get_records().append(record) + def add_record(self, record, thread=None): + # Avoid logging SQL queries since they are already in the SQL panel + # TODO: Make this check whether SQL panel is enabled + if record.get('channel', '') == 'django.db.backends': + return + + self.get_records(thread).append(record) def get_records(self, thread=None): """ @@ -36,20 +41,67 @@ class ThreadTrackingHandler(logging.Handler): if thread in self.records: del self.records[thread] -handler = ThreadTrackingHandler() + +class ThreadTrackingHandler(logging.Handler): + def __init__(self, collector): + logging.Handler.__init__(self) + self.collector = collector + + def emit(self, record): + record = { + 'message': record.getMessage(), + 'time': datetime.datetime.fromtimestamp(record.created), + 'level': record.levelname, + 'file': record.pathname, + 'line': record.lineno, + 'channel': record.name, + } + self.collector.add_record(record) + + +collector = LogCollector() +logging_handler = ThreadTrackingHandler(collector) logging.root.setLevel(logging.NOTSET) -logging.root.addHandler(handler) +logging.root.addHandler(logging_handler) # register with logging + +try: + import logbook + logbook_supported = True +except ImportError: + # logbook support is optional, so fail silently + logbook_supported = False + +if logbook_supported: + class LogbookThreadTrackingHandler(logbook.handlers.Handler): + def __init__(self, collector): + logbook.handlers.Handler.__init__(self, bubble=True) + self.collector = collector + + def emit(self, record): + record = { + 'message': record.message, + 'time': record.time, + 'level': record.level_name, + 'file': record.filename, + 'line': record.lineno, + 'channel': record.channel, + } + self.collector.add_record(record) + + + logbook_handler = LogbookThreadTrackingHandler(collector) + logbook_handler.push_application() # register with logbook class LoggingPanel(DebugPanel): name = 'Logging' has_content = True def process_request(self, request): - handler.clear_records() + collector.clear_records() def get_and_delete(self): - records = handler.get_records() - handler.clear_records() + records = collector.get_records() + collector.clear_records() return records def nav_title(self): @@ -57,7 +109,7 @@ class LoggingPanel(DebugPanel): def nav_subtitle(self): # FIXME l10n: use ngettext - return "%s message%s" % (len(handler.get_records()), (len(handler.get_records()) == 1) and '' or 's') + return "%s message%s" % (len(collector.get_records()), (len(collector.get_records()) == 1) and '' or 's') def title(self): return _('Log Messages') @@ -66,16 +118,7 @@ class LoggingPanel(DebugPanel): return '' def content(self): - records = [] - for record in self.get_and_delete(): - records.append({ - 'message': record.getMessage(), - 'time': datetime.datetime.fromtimestamp(record.created), - 'level': record.levelname, - 'file': record.pathname, - 'line': record.lineno, - }) - + records = self.get_and_delete() context = self.context.copy() context.update({'records': records}) diff --git a/debug_toolbar/panels/sql.py b/debug_toolbar/panels/sql.py index e1e9bdf..c6e73a0 100644 --- a/debug_toolbar/panels/sql.py +++ b/debug_toolbar/panels/sql.py @@ -6,14 +6,29 @@ import traceback import django from django.conf import settings -from django.db import connection +try: + from django.db import connections +except ImportError: + # Compatibility with Django < 1.2 + from django.db import connection + connections = {'default': connection} + connection.alias = 'default' + from django.db.backends import util from django.views.debug import linebreak_iter from django.template import Node from django.template.loader import render_to_string from django.utils import simplejson -from django.utils.encoding import force_unicode +from django.utils.encoding import force_unicode, DjangoUnicodeDecodeError from django.utils.hashcompat import sha_constructor +try: + from django.utils.log import getLogger + logger = getLogger('django.db.backends') + has_logger = True +except ImportError: + # Compatibility with Django < 1.2 + has_logger = False + from django.utils.translation import ugettext_lazy as _ from debug_toolbar.panels import DebugPanel @@ -85,12 +100,73 @@ class DatabaseStatTracker(util.CursorDebugWrapper): Replacement for CursorDebugWrapper which stores additional information in `connection.queries`. """ + def clean_params(self, params): + clean_params = () + for x in params: + try: + force_unicode(x, strings_only=True) + except DjangoUnicodeDecodeError: + clean_params += ("<non unicode object>", ) + else: + clean_params += (x, ) + return clean_params + def execute(self, sql, params=()): start = datetime.now() try: return self.cursor.execute(sql, params) finally: stop = datetime.now() + params = self.clean_params(params) + duration = ms_from_timedelta(stop - start) + stacktrace = tidy_stacktrace(traceback.extract_stack()) + _params = '' + try: + _params = simplejson.dumps([force_unicode(x, strings_only=True) for x in params]) + except TypeError: + pass # object not JSON serializable + + template_info = None + cur_frame = sys._getframe().f_back + try: + while cur_frame is not None: + if cur_frame.f_code.co_name == 'render': + node = cur_frame.f_locals['self'] + if isinstance(node, Node): + template_info = get_template_info(node.source) + break + cur_frame = cur_frame.f_back + except: + pass + del cur_frame + + # Logging was added in Django 1.3 + if has_logger: + logger.debug('(%.3f) %s; args=%s' % (duration, sql, params), + extra={'duration':duration, 'sql':sql, 'params':params} + ) + + # We keep `sql` to maintain backwards compatibility + self.db.queries.append({ + 'sql': self.db.ops.last_executed_query(self.cursor, sql, params), + '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), + 'is_select': sql.lower().strip().startswith('select'), + 'template_info': template_info, + }) + + def executemany(self, sql, params=()): + start = datetime.now() + try: + return self.cursor.executemany(sql, params) + finally: + stop = datetime.now() duration = ms_from_timedelta(stop - start) stacktrace = tidy_stacktrace(traceback.extract_stack()) _params = '' @@ -113,6 +189,11 @@ class DatabaseStatTracker(util.CursorDebugWrapper): pass del cur_frame + if has_logger: + logger.debug('(%.3f) %s; args=%s' % (duration, sql, params), + extra={'duration':duration, 'sql':sql, 'params':params} + ) + # We keep `sql` to maintain backwards compatibility self.db.queries.append({ 'sql': self.db.ops.last_executed_query(self.cursor, sql, params), @@ -139,16 +220,27 @@ class SQLDebugPanel(DebugPanel): def __init__(self, *args, **kwargs): super(self.__class__, self).__init__(*args, **kwargs) - self._offset = len(connection.queries) + self._offset = dict((conn, len(connections[conn].queries)) for conn in connections) self._sql_time = 0 self._queries = [] + self._databases = {} def nav_title(self): return _('SQL') def nav_subtitle(self): - self._queries = connection.queries[self._offset:] - self._sql_time = sum([q['duration'] for q in self._queries]) + self._queries = [] + self._databases = {} + for alias in connections: + db_queries = connections[alias].queries[self._offset[alias]:] + self._databases[alias] = { + 'time_spent': sum(q['duration'] for q in db_queries), + 'queries': len(db_queries), + } + self._queries.extend([(alias, q) for q in db_queries]) + + self._queries.sort(key=lambda x: x[1]['start_time']) + self._sql_time = sum([d['time_spent'] for d in self._databases.itervalues()]) num_queries = len(self._queries) # TODO l10n: use ngettext return "%d %s in %.2fms" % ( @@ -165,7 +257,8 @@ class SQLDebugPanel(DebugPanel): def content(self): width_ratio_tally = 0 - for query in self._queries: + for alias, query in self._queries: + query['alias'] = alias query['sql'] = reformat_sql(query['sql']) try: query['width_ratio'] = (query['duration'] / self._sql_time) * 100 @@ -176,7 +269,8 @@ class SQLDebugPanel(DebugPanel): context = self.context.copy() context.update({ - 'queries': self._queries, + 'databases': sorted(self._databases.items(), key=lambda x: -x[1]['time_spent']), + 'queries': [q for a, q in self._queries], 'sql_time': self._sql_time, 'is_mysql': settings.DATABASE_ENGINE == 'mysql', }) |