Track and display middleware time in the toolbar #2049
Conversation
|
Would it make sense to include a stat with the middleware time deducted from the total for the user? Or deduct it from the existing total? |
|
@robhudson the thinking I had earlier was that the toolbar changes the application so we shouldn't try to extract the toolbar itself from the timing. |
debug_toolbar/middleware.py
Outdated
| @@ -98,10 +101,14 @@ def __call__(self, request): | |||
| # regardless of the response. Keep 'return' clauses below. | |||
| for panel in reversed(toolbar.enabled_panels): | |||
| panel.disable_instrumentation() | |||
| toolbar_end_time = perf_counter() | |||
There was a problem hiding this comment.
The other thing I was thinking about is how to handle measuring the full time of the toolbar's processing. This is actually stopping before all the Panel.generate_stats() methods are called which contains quite a bit of logic. I think ideally we'd capture that in this timing.
The problem is, how do we capture that? I have a few ideas, but I'm not happy with them.
I think we could measure the end time in TimerPanel.generate_stats() like we do with the rest and store it. This means any other panels that generate their stats after the TimerPanel would not be included. To mitigate that, we could find a way to make sure that TimerPanel is first to enable and last to generate stats. I think having it be first in enabled_panels would do the trick.
The other idea I had was to create a templatetag that would do the diff between the stored time and the current time at the time the toolbar is rendered. The problem here is that it wouldn't be compatible with the serializable branch where we want to store all the stats before rendering.
So I think trying to consolidate all the logic into TimerPanel with a change to force TimerPanel to be first for processing (not appearance on the idea) is ideal.
@salty-ivy @elineda any thoughts?
There was a problem hiding this comment.
I have updated the enabled_panels property to ensure the TimerPanel is first in order. This is I think what you meant by in the first approach. The order of enabled panels is reversed in _postprocess ensuring the end time is captured at the end.
There was a problem hiding this comment.
Excellent, thank you @earthcomfy! This is looking really nice. The last bit we need are the tests.
There was a problem hiding this comment.
I added a test to ensure the timer panel is first. Are there any other tests that need to be included
There was a problem hiding this comment.
@earthcomfy ideally we'd have tests covering all the changes on the Timer panel. Or updates to similar tests to also cover these new fields.
| if timer_panel: | ||
| panels.remove(timer_panel) | ||
| panels.insert(0, timer_panel) | ||
| return panels |
There was a problem hiding this comment.
@earthcomfy I'm going to need to take a bit to process this. This is a bit of a change and I want to make sure I understand it well. For example, I think this impacts the order of the panels on the side which means it impacts the UX of the toolbar.
Currently by default the Timer panel is 3rd from the top, while the top is the History panel. I think the History panel being at the top is between mildly important and important.
@django-commons/django-debug-toolbar any thoughts here?
Description
CPU time includes the debug toolbar's own time so this PR aims to track how long the middleware takes to run and display that time on the panel.
Fixes #1903
Checklist:
docs/changes.rst.