Profiling panel isn't as helpful as pStats

[tim-schilling]

The profiling panel doesn't appear to be as useful as pStats. I think we should revisit how we aggregate the profiling metrics or more closely integrate with pStats.

I suspect with changes to Django our integration has weakened leading to the current situation where it mainly shows a bunch of wrappers and middlewares in the panel.

---

How to reproduce

Using the following code in our example app:

from time import sleep

from asgiref.sync import sync_to_async
from django.contrib.auth.models import User
from django.http import JsonResponse
from django.shortcuts import render

def slow_method(i):
    sleep(0.001)
    return i

def increment(request):
    try:
        value = int(request.session.get("value", 0)) + 1
    except ValueError:
        value = 1
    request.session["value"] = value
    for i in range(1000):
        summed = slow_method(i)
    return JsonResponse({"value": value})

Then using the Increment button, we get the following in the profiling panel:

Call 	CumTime 	Per 	TotTime 	Per 	Count
/home/schillingt/Projects/debug_toolbar/debug_toolbar/panels/__init__.py in process_request(221)
	1.059 	1.059 	0.000 	0.000 	2
/django/core/handlers/exception.py in inner(52)
	1.059 	1.059 	0.000 	0.000 	1
/django/core/handlers/base.py in _get_response(174)
	1.059 	1.059 	0.000 	0.000 	1

But if we update ProfilingPanel.generate_stats() to:

    def generate_stats(self, request, response):
        # ...
        self.profiler.create_stats()
        self.stats = Stats(self.profiler)
        self.stats.calc_callees()
        self.stats.sort_stats("cumtime")
        self.stats.print_stats(25)
        # ...

We get the following printed in the terminal:

   Ordered by: cumulative time
   List reduced from 128 to 25 due to restriction <25>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      2/1    0.000    0.000    1.059    1.059 /home/schillingt/Projects/debug_toolbar/debug_toolbar/panels/__init__.py:221(process_request)
     1000    0.002    0.000    1.057    0.001 /home/schillingt/Projects/debug_toolbar/example/views.py:10(slow_method)
 1000/894    1.026    0.001    0.915    0.001 {built-in method time.sleep}
      2/1    0.001    0.000    0.656    0.656 /home/schillingt/Projects/debug_toolbar/venv/lib/python3.12/site-packages/django/core/handlers/exception.py:52(inner)
      2/1    0.000    0.000    0.142    0.142 /home/schillingt/Projects/debug_toolbar/venv/lib/python3.12/site-packages/django/core/handlers/base.py:174(_get_response)
        1    0.000    0.000    0.142    0.142 /home/schillingt/Projects/debug_toolbar/example/views.py:14(increment)
      812    0.003    0.000    0.024    0.000 /home/schillingt/Projects/debug_toolbar/venv/lib/python3.12/site-packages/django/utils/autoreload.py:407(snapshot_files)
      812    0.000    0.000    0.011    0.000 /home/schillingt/Projects/debug_toolbar/venv/lib/python3.12/site-packages/django/utils/autoreload.py:298(watched_files)
       70    0.000    0.000    0.009    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:1081(glob)
      815    0.000    0.000    0.009    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:835(stat)
       69    0.000    0.000    0.008    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:234(_select_from)
      815    0.007    0.000    0.008    0.000 {built-in method posix.stat}
       61    0.000    0.000    0.005    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:228(_iterate_directories)
       61    0.001    0.000    0.003    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:1112(walk)
      124    0.001    0.000    0.003    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:200(_select_from)
     1604    0.002    0.000    0.003    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:519(__eq__)
      813    0.001    0.000    0.003    0.000 {method 'get' of 'dict' objects}
      176    0.001    0.000    0.003    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:1065(_make_child_relpath)
      176    0.001    0.000    0.002    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:380(with_segments)
        1    0.000    0.000    0.002    0.002 /home/schillingt/Projects/debug_toolbar/venv/lib/python3.12/site-packages/django/utils/autoreload.py:108(iter_all_python_module_files)
     3244    0.001    0.000    0.001    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:524(__hash__)
      116    0.000    0.000    0.001    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:1059(_scandir)
      931    0.001    0.000    0.001    0.000 /home/schillingt/.pyenv/versions/3.12.1/lib/python3.12/pathlib.py:447(__fspath__)
      116    0.001    0.000    0.001    0.000 {built-in method posix.scandir}
     2828    0.001    0.000    0.001    0.000 {built-in method builtins.isinstance}

We can see slow_method doesn't appear in the profiling panel, but is the second item on the pStats case. Given that this slow code is in the "project" and so expensive in terms of the request, the toolbar should do a better job of highlighting that concern.