Merge pull request #731 from tim-schilling/generate-stats

Generate stats - fix slow loading of media files.

debug_toolbar/locale/en/LC_MESSAGES/django.po

@@ -6,7 +6,7 @@ msgid ""
 msgstr ""
 "Project-Id-Version: Django Debug Toolbar\n"
 "Report-Msgid-Bugs-To: \n"
-"POT-Creation-Date: 2015-05-27 19:40-0400\n"
+"POT-Creation-Date: 2015-07-06 16:50-0400\n"
 "PO-Revision-Date: 2012-03-31 20:10+0000\n"
 "Last-Translator: \n"
 "Language-Team: \n"
@@ -20,18 +20,18 @@ msgstr ""
 msgid "Debug Toolbar"
 msgstr ""
 
-#: panels/cache.py:197
+#: panels/cache.py:209
 msgid "Cache"
 msgstr ""
 
-#: panels/cache.py:202
+#: panels/cache.py:214
 #, python-format
 msgid "%(cache_calls)d call in %(time).2fms"
 msgid_plural "%(cache_calls)d calls in %(time).2fms"
 msgstr[0] ""
 msgstr[1] ""
 
-#: panels/cache.py:210
+#: panels/cache.py:222
 #, python-format
 msgid "Cache calls from %(count)d backend"
 msgid_plural "Cache calls from %(count)d backends"
@@ -292,7 +292,7 @@ msgid "Calls"
 msgstr ""
 
 #: templates/debug_toolbar/panels/cache.html:43
-#: templates/debug_toolbar/panels/sql.html:20
+#: templates/debug_toolbar/panels/sql.html:23
 msgid "Time (ms)"
 msgstr ""
 
@@ -466,36 +466,46 @@ msgid_plural "%(num)s queries"
 msgstr[0] ""
 msgstr[1] ""
 
-#: templates/debug_toolbar/panels/sql.html:18
+#: templates/debug_toolbar/panels/sql.html:9
+#, python-format
+msgid "including %(dupes)s duplicates"
+msgstr ""
+
+#: templates/debug_toolbar/panels/sql.html:21
 msgid "Query"
 msgstr ""
 
-#: templates/debug_toolbar/panels/sql.html:19
+#: templates/debug_toolbar/panels/sql.html:22
 #: templates/debug_toolbar/panels/timer.html:36
 msgid "Timeline"
 msgstr ""
 
-#: templates/debug_toolbar/panels/sql.html:21
+#: templates/debug_toolbar/panels/sql.html:24
 msgid "Action"
 msgstr ""
 
-#: templates/debug_toolbar/panels/sql.html:64
+#: templates/debug_toolbar/panels/sql.html:39
+#, python-format
+msgid "Duplicated %(dupes)s times."
+msgstr ""
+
+#: templates/debug_toolbar/panels/sql.html:71
 msgid "Connection:"
 msgstr ""
 
-#: templates/debug_toolbar/panels/sql.html:66
+#: templates/debug_toolbar/panels/sql.html:73
 msgid "Isolation level:"
 msgstr ""
 
-#: templates/debug_toolbar/panels/sql.html:69
+#: templates/debug_toolbar/panels/sql.html:76
 msgid "Transaction status:"
 msgstr ""
 
-#: templates/debug_toolbar/panels/sql.html:83
+#: templates/debug_toolbar/panels/sql.html:90
 msgid "(unknown)"
 msgstr ""
 
-#: templates/debug_toolbar/panels/sql.html:92
+#: templates/debug_toolbar/panels/sql.html:99
 msgid "No SQL queries were recorded during this request."
 msgstr ""
 

debug_toolbar/middleware.py

@@ -126,6 +126,10 @@ def process_response(self, request, response):
             # When the body ends with a newline, there's two trailing groups.
             bits.append(''.join(m[0] for m in matches if m[1] == ''))
         if len(bits) > 1:
+            # When the toolbar will be inserted for sure, generate the stats.
+            for panel in reversed(toolbar.enabled_panels):
+                panel.generate_stats(request, response)
+
             bits[-2] += toolbar.render_toolbar()
             response.content = insert_before.join(bits)
             if response.get('Content-Length', None):

debug_toolbar/panels/__init__.py

@@ -167,10 +167,29 @@ def process_view(self, request, view_func, view_args, view_kwargs):
 
     def process_response(self, request, response):
         """
-        Like process_response in Django's middleware.
+        Like process_response in Django's middleware. This is similar to
+        :meth:`generate_stats <debug_toolbar.panels.Panel.generate_stats>`,
+        but will be executed on every request. It should be used when either
+        the logic needs to be executed on every request or it needs to change
+        the response entirely, such as :class:`RedirectsPanel`.
 
         Write panel logic related to the response there. Post-process data
         gathered while the view executed. Save data with :meth:`record_stats`.
+
+        Return a response to overwrite the existing response.
+        """
+
+    def generate_stats(self, request, response):
+        """
+        Similar to :meth:`process_response
+        <debug_toolbar.panels.Panel.process_response>`,
+        but may not be executed on every request. This will only be called if
+        the toolbar will be inserted into the request.
+
+        Write panel logic related to the response there. Post-process data
+        gathered while the view executed. Save data with :meth:`record_stats`.
+
+        Does not return a value.
         """
 
 

debug_toolbar/panels/cache.py

@@ -244,7 +244,7 @@ def disable_instrumentation(self):
             middleware_cache.caches = original_caches
         cache.get_cache = original_get_cache
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         self.record_stats({
             'total_calls': len(self.calls),
             'calls': self.calls,

debug_toolbar/panels/headers.py

@@ -47,7 +47,7 @@ def process_request(self, request):
             'environ': self.environ,
         })
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         self.response_headers = OrderedDict(sorted(response.items()))
         self.record_stats({
             'response_headers': self.response_headers,

debug_toolbar/panels/logging.py

@@ -74,7 +74,7 @@ def nav_subtitle(self):
     def process_request(self, request):
         collector.clear_collection()
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         records = collector.get_collection()
         self._records[threading.currentThread()] = records
         collector.clear_collection()

debug_toolbar/panels/profiling.py

@@ -1,5 +1,6 @@
 from __future__ import absolute_import, division, unicode_literals
 
+from django.utils import six
 from django.utils.translation import ugettext_lazy as _
 from django.utils.safestring import mark_safe
 from debug_toolbar.panels import Panel
@@ -10,14 +11,29 @@
 from colorsys import hsv_to_rgb
 import os
 
+# Occasionally the disable method on the profiler is listed before
+# the actual view functions. This function call should be ignored as
+# it leads to an error within the tests.
+INVALID_PROFILER_FUNC = '_lsprof.Profiler'
+
+
+def contains_profiler(func_tuple):
+    """Helper function that checks to see if the tuple contains
+    the INVALID_PROFILE_FUNC in any string value of the tuple."""
+    has_profiler = False
+    for value in func_tuple:
+        if isinstance(value, six.string_types):
+            has_profiler |= INVALID_PROFILER_FUNC in value
+    return has_profiler
+
 
 class DjangoDebugToolbarStats(Stats):
     __root = None
 
     def get_root_func(self):
         if self.__root is None:
             for func, (cc, nc, tt, ct, callers) in self.stats.items():
-                if len(callers) == 0:
+                if len(callers) == 0 and not contains_profiler(func):
                     self.__root = func
                     break
         return self.__root
@@ -142,7 +158,7 @@ def add_node(self, func_list, func, max_depth, cum_time=0.1):
                     func.has_subfuncs = True
                     self.add_node(func_list, subfunc, max_depth, cum_time=cum_time)
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         if not hasattr(self, 'profiler'):
             return None
         # Could be delayed until the panel content is requested (perf. optim.)

debug_toolbar/panels/request.py

@@ -25,7 +25,7 @@ def nav_subtitle(self):
         view_func = self.get_stats().get('view_func', '')
         return view_func.rsplit('.', 1)[-1]
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         self.record_stats({
             'get': [(k, request.GET.getlist(k)) for k in sorted(request.GET)],
             'post': [(k, request.POST.getlist(k)) for k in sorted(request.POST)],

debug_toolbar/panels/settings.py

@@ -19,7 +19,7 @@ class SettingsPanel(Panel):
     def title(self):
         return _("Settings from <code>%s</code>") % settings.SETTINGS_MODULE
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         self.record_stats({
             'settings': OrderedDict(sorted(get_safe_settings().items(),
                                            key=lambda s: s[0])),

debug_toolbar/panels/signals.py

@@ -58,7 +58,7 @@ def signals(self):
             signals[signal_name] = getattr(signals_mod, signal_name)
         return signals
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         signals = []
         for name, signal in sorted(self.signals.items(), key=lambda x: x[0]):
             if signal is None:

debug_toolbar/panels/sql/panel.py

@@ -136,7 +136,7 @@ def disable_instrumentation(self):
         for connection in connections.all():
             unwrap_cursor(connection)
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         colors = contrasting_color_generator()
         trace_colors = defaultdict(lambda: next(colors))
         query_duplicates = defaultdict(lambda: defaultdict(int))

debug_toolbar/panels/staticfiles.py

@@ -113,7 +113,7 @@ def nav_subtitle(self):
     def process_request(self, request):
         collector.clear_collection()
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         used_paths = collector.get_collection()
         self._paths[threading.currentThread()] = used_paths
 

debug_toolbar/panels/templates/panel.py

@@ -195,7 +195,7 @@ def enable_instrumentation(self):
     def disable_instrumentation(self):
         template_rendered.disconnect(self._store_template_info)
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         template_context = []
         for template_data in self.templates:
             info = {}

debug_toolbar/panels/timer.py

@@ -52,7 +52,7 @@ def process_request(self, request):
         if self.has_content:
             self._start_rusage = resource.getrusage(resource.RUSAGE_SELF)
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         stats = {}
         if hasattr(self, '_start_time'):
             stats['total_time'] = (time.time() - self._start_time) * 1000

debug_toolbar/panels/versions.py

@@ -22,7 +22,7 @@ def nav_subtitle(self):
 
     template = 'debug_toolbar/panels/versions.html'
 
-    def process_response(self, request, response):
+    def generate_stats(self, request, response):
         versions = [
             ('Python', '%d.%d.%d' % sys.version_info[:3]),
             ('Django', self.get_app_version(django)),

docs/changes.rst

@@ -1,6 +1,22 @@
 Change log
 ==========
 
+1.4
+---
+
+New features
+~~~~~~~~~~~~
+
+* New panel method :meth:`debug_toolbar.panels.Panel.generate_stats` allows panels
+  to only record stats when the toolbar is going to be inserted into the
+  response.
+
+Bugfixes
+~~~~~~~~
+
+* Response time for requests of projects with numerous media files has
+  been improved.
+
 1.3
 ---
 

docs/panels.rst

@@ -315,6 +315,8 @@ CSS API at this time.
 
     .. automethod:: debug_toolbar.panels.Panel.process_response
 
+    .. automethod:: debug_toolbar.panels.Panel.generate_stats
+
 .. _javascript-api:
 
 JavaScript API

tests/panels/test_cache.py

@@ -46,3 +46,16 @@ def test_recording_get_cache(self):
         default_cache.set('foo', 'bar')
         second_cache.get('foo')
         self.assertEqual(len(self.panel.calls), 2)
+
+    def test_insert_content(self):
+        """
+        Test that the panel only inserts content after generate_stats and
+        not the process_response.
+        """
+        cache.cache.get('café')
+        self.panel.process_response(self.request, self.response)
+        # ensure the panel does not have content yet.
+        self.assertNotIn('café', self.panel.content)
+        self.panel.generate_stats(self.request, self.response)
+        # ensure the panel renders correctly.
+        self.assertIn('café', self.panel.content)

tests/panels/test_logging.py

@@ -1,3 +1,5 @@
+# coding: utf-8
+
 from __future__ import absolute_import, unicode_literals
 
 import logging
@@ -24,6 +26,7 @@ def test_happy_case(self):
         self.logger.info('Nothing to see here, move along!')
 
         self.panel.process_response(self.request, self.response)
+        self.panel.generate_stats(self.request, self.response)
         records = self.panel.get_stats()['records']
 
         self.assertEqual(1, len(records))
@@ -34,12 +37,26 @@ def test_formatting(self):
         self.logger.info('There are %d %s', 5, 'apples')
 
         self.panel.process_response(self.request, self.response)
+        self.panel.generate_stats(self.request, self.response)
         records = self.panel.get_stats()['records']
 
         self.assertEqual(1, len(records))
         self.assertEqual('There are 5 apples',
                          records[0]['message'])
 
+    def test_insert_content(self):
+        """
+        Test that the panel only inserts content after generate_stats and
+        not the process_response.
+        """
+        self.logger.info('café')
+        self.panel.process_response(self.request, self.response)
+        # ensure the panel does not have content yet.
+        self.assertNotIn('café', self.panel.content)
+        self.panel.generate_stats(self.request, self.response)
+        # ensure the panel renders correctly.
+        self.assertIn('café', self.panel.content)
+
     def test_failing_formatting(self):
         class BadClass(object):
             def __str__(self):
@@ -49,6 +66,7 @@ def __str__(self):
         self.logger.debug('This class is misbehaving: %s', BadClass())
 
         self.panel.process_response(self.request, self.response)
+        self.panel.generate_stats(self.request, self.response)
         records = self.panel.get_stats()['records']
 
         self.assertEqual(1, len(records))