Track and display middleware time in the toolbar

debug_toolbar/panels/timer.py

@@ -45,6 +45,10 @@ def content(self):
             (_("System CPU time"), _("%(stime)0.3f msec") % stats),
             (_("Total CPU time"), _("%(total)0.3f msec") % stats),
             (_("Elapsed time"), _("%(total_time)0.3f msec") % stats),
+            (
+                _("Toolbar time"),
+                _("%(toolbar_time)0.3f msec") % stats,
+            ),
             (
                 _("Context switches"),
                 _("%(vcsw)d voluntary, %(ivcsw)d involuntary") % stats,
@@ -90,6 +94,9 @@ def generate_stats(self, request, response):
             #        stats['urss'] = self._end_rusage.ru_idrss
             #        stats['usrss'] = self._end_rusage.ru_isrss
 
+        if hasattr(self, "_toolbar_start_time"):
+            stats["toolbar_time"] = (perf_counter() - self._toolbar_start_time) * 1000
+
         self.record_stats(stats)
 
     def generate_server_timing(self, request, response):
@@ -101,6 +108,15 @@ def generate_server_timing(self, request, response):
         self.record_server_timing(
             "total_time", "Elapsed time", stats.get("total_time", 0)
         )
+        self.record_server_timing(
+            "toolbar_time", "Toolbar time", stats.get("toolbar_time", 0)
+        )
 
     def _elapsed_ru(self, name):
         return getattr(self._end_rusage, name) - getattr(self._start_rusage, name)
+
+    def enable_instrumentation(self):
+        self._toolbar_start_time = perf_counter()
+
+    def aenable_instrumentation(self):
+        self._toolbar_start_time = perf_counter()

debug_toolbar/toolbar.py

@@ -63,7 +63,15 @@ def enabled_panels(self):
         """
         Get a list of panels enabled for the current request.
         """
-        return [panel for panel in self._panels.values() if panel.enabled]
+        panels = [panel for panel in self._panels.values() if panel.enabled]
+        # Ensure TimerPanel is first in order to measure the full time of the toolbar's processing.
+        timer_panel = next(
+            (panel for panel in panels if panel.panel_id == "TimerPanel"), None
+        )
+        if timer_panel:
+            panels.remove(timer_panel)
+            panels.insert(0, timer_panel)
+        return panels
 
     def get_panel_by_id(self, panel_id):
         """

docs/changes.rst

@@ -10,6 +10,7 @@ Pending
 * Fixed a crash which occurred when using non-``str`` static file values.
 * Documented experimental async support.
 * Improved troubleshooting doc for incorrect mime types for .js static files
+* Added toolbar time to the timer panel.
 
 5.0.0-alpha (2024-09-01)
 ------------------------

tests/test_integration.py

@@ -297,6 +297,10 @@ def test_concurrent_async_sql_page(self):
             len(response.toolbar.get_panel_by_id("SQLPanel").get_stats()["queries"]), 2
         )
 
+    def test_timer_panel_first(self):
+        toolbar = DebugToolbar(self.request, self.get_response)
+        self.assertEqual(toolbar.enabled_panels[0].panel_id, "TimerPanel")
+
 
 @override_settings(DEBUG=True)
 class DebugToolbarIntegrationTestCase(IntegrationTestCase):
@@ -605,6 +609,7 @@ def test_server_timing_headers(self):
             r'TimerPanel_stime;dur=(\d)*(\.(\d)*)?;desc="System CPU time", ',
             r'TimerPanel_total;dur=(\d)*(\.(\d)*)?;desc="Total CPU time", ',
             r'TimerPanel_total_time;dur=(\d)*(\.(\d)*)?;desc="Elapsed time", ',
+            r'TimerPanel_toolbar_time;dur=(\d)*(\.(\d)*)?;desc="Toolbar time", ',
             r'SQLPanel_sql_time;dur=(\d)*(\.(\d)*)?;desc="SQL 1 queries", ',
             r'CachePanel_total_time;dur=0;desc="Cache 0 Calls"',
         ]