Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Track and display middleware time in the toolbar #2049

Open
wants to merge 6 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from 2 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 13 additions & 0 deletions debug_toolbar/middleware.py
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,7 @@
import re
import socket
from functools import cache
from time import perf_counter

from asgiref.sync import iscoroutinefunction, markcoroutinefunction
from django.conf import settings
Expand Down Expand Up @@ -78,6 +79,8 @@ def __init__(self, get_response):
markcoroutinefunction(self)

def __call__(self, request):
# Start tracking middleware execution time
middleware_start_time = perf_counter()
tim-schilling marked this conversation as resolved.
Show resolved Hide resolved
# Decide whether the toolbar is active for this request.
if self.async_mode:
return self.__acall__(request)
Expand All @@ -98,10 +101,16 @@ def __call__(self, request):
# regardless of the response. Keep 'return' clauses below.
for panel in reversed(toolbar.enabled_panels):
panel.disable_instrumentation()
middleware_end_time = perf_counter()
toolbar.middleware_time = (
middleware_end_time - middleware_start_time
) * 1000

return self._postprocess(request, response, toolbar)

async def __acall__(self, request):
# Start tracking middleware execution time
middleware_start_time = perf_counter()
# Decide whether the toolbar is active for this request.
show_toolbar = get_show_toolbar()
if not show_toolbar(request) or DebugToolbar.is_toolbar_request(request):
Expand All @@ -125,6 +134,10 @@ async def __acall__(self, request):
# regardless of the response. Keep 'return' clauses below.
for panel in reversed(toolbar.enabled_panels):
panel.disable_instrumentation()
middleware_end_time = perf_counter()
toolbar.middleware_time = (
middleware_end_time - middleware_start_time
) * 1000

return self._postprocess(request, response, toolbar)

Expand Down
9 changes: 9 additions & 0 deletions debug_toolbar/panels/timer.py
Original file line number Diff line number Diff line change
Expand Up @@ -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),
(
_("Middleware time"),
_("%(middleware_time)0.3f msec") % stats,
),
(
_("Context switches"),
_("%(vcsw)d voluntary, %(ivcsw)d involuntary") % stats,
Expand Down Expand Up @@ -90,6 +94,8 @@ def generate_stats(self, request, response):
# stats['urss'] = self._end_rusage.ru_idrss
# stats['usrss'] = self._end_rusage.ru_isrss

# Add middleware time to stats
stats["middleware_time"] = self.toolbar.middleware_time
self.record_stats(stats)

def generate_server_timing(self, request, response):
Expand All @@ -101,6 +107,9 @@ def generate_server_timing(self, request, response):
self.record_server_timing(
"total_time", "Elapsed time", stats.get("total_time", 0)
)
self.record_server_timing(
"middleware_time", "Middleware time", stats.get("middleware_time", 0)
)

def _elapsed_ru(self, name):
return getattr(self._end_rusage, name) - getattr(self._start_rusage, name)
1 change: 1 addition & 0 deletions debug_toolbar/toolbar.py
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,7 @@ def __init__(self, request, get_response):
self.stats = {}
self.server_timing_stats = {}
self.store_id = None
self.middleware_time = 0
self._created.send(request, toolbar=self)

# Manage panels
Expand Down
1 change: 1 addition & 0 deletions docs/changes.rst
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@ Pending
* Converted to Django Commons PyPI release process.
* Fixed a crash which occurred when using non-``str`` static file values.
* Documented experimental async support.
* Added middleware time to the timer panel.

5.0.0-alpha (2024-09-01)
------------------------
Expand Down
1 change: 1 addition & 0 deletions tests/test_integration.py
Original file line number Diff line number Diff line change
Expand Up @@ -605,6 +605,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_middleware_time;dur=(\d)*(\.(\d)*)?;desc="Middleware time", ',
r'SQLPanel_sql_time;dur=(\d)*(\.(\d)*)?;desc="SQL 1 queries", ',
r'CachePanel_total_time;dur=0;desc="Cache 0 Calls"',
]
Expand Down