Profiling panel improvements (#1669)

* Give users control over including more profiling data.

* The profiling panel will now include more user code.

By checking that the code lives in the settings.BASE_DIR directory, we know
that the code was likely written by the user and thus more important
to a developer when debugging code.

* Highlight the project function calls in the profiling panel.

* Add setting PROFILER_CAPTURE_PROJECT_CODE.

This can be used to disable the attempt to include all project code. This is
useful if dependencies are installed within the project.

* Fix bug with test_cum_time_threshold profiling.

* Include dist-packages in profiling panel docs.

Co-authored-by: Matthias Kestenholz <mk@feinheit.ch>

Author: tim-schilling

debug_toolbar/panels/profiling.py

@@ -3,6 +3,7 @@
 from colorsys import hsv_to_rgb
 from pstats import Stats
 
+from django.conf import settings
 from django.utils.html import format_html
 from django.utils.translation import gettext_lazy as _
 
@@ -32,6 +33,22 @@ def background(self):
         r, g, b = hsv_to_rgb(*self.hsv)
         return f"rgb({r * 100:f}%,{g * 100:f}%,{b * 100:f}%)"
 
+    def is_project_func(self):
+        """
+        Check if the function is from the project code.
+
+        Project code is identified by the BASE_DIR setting
+        which is used in Django projects by default.
+        """
+        if hasattr(settings, "BASE_DIR"):
+            file_name, _, _ = self.func
+            return (
+                str(settings.BASE_DIR) in file_name
+                and "/site-packages/" not in file_name
+                and "/dist-packages/" not in file_name
+            )
+        return None
+
     def func_std_string(self):  # match what old profile produced
         func_name = self.func
         if func_name[:2] == ("~", 0):
@@ -123,19 +140,25 @@ class ProfilingPanel(Panel):
     title = _("Profiling")
 
     template = "debug_toolbar/panels/profiling.html"
+    capture_project_code = dt_settings.get_config()["PROFILER_CAPTURE_PROJECT_CODE"]
 
     def process_request(self, request):
         self.profiler = cProfile.Profile()
         return self.profiler.runcall(super().process_request, request)
 
-    def add_node(self, func_list, func, max_depth, cum_time=0.1):
+    def add_node(self, func_list, func, max_depth, cum_time):
         func_list.append(func)
         func.has_subfuncs = False
         if func.depth < max_depth:
             for subfunc in func.subfuncs():
-                if subfunc.stats[3] >= cum_time:
+                # Always include the user's code
+                if subfunc.stats[3] >= cum_time or (
+                    self.capture_project_code
+                    and subfunc.is_project_func()
+                    and subfunc.stats[3] > 0
+                ):
                     func.has_subfuncs = True
-                    self.add_node(func_list, subfunc, max_depth, cum_time=cum_time)
+                    self.add_node(func_list, subfunc, max_depth, cum_time)
 
     def generate_stats(self, request, response):
         if not hasattr(self, "profiler"):
@@ -150,10 +173,13 @@ def generate_stats(self, request, response):
         if root_func in self.stats.stats:
             root = FunctionCall(self.stats, root_func, depth=0)
             func_list = []
+            cum_time_threshold = (
+                root.stats[3] / dt_settings.get_config()["PROFILER_THRESHOLD_RATIO"]
+            )
             self.add_node(
                 func_list,
                 root,
                 dt_settings.get_config()["PROFILER_MAX_DEPTH"],
-                root.stats[3] / 8,
+                cum_time_threshold,
             )
             self.record_stats({"func_list": func_list})

debug_toolbar/settings.py

@@ -33,7 +33,9 @@
         "django.utils.functional",
     ),
     "PRETTIFY_SQL": True,
+    "PROFILER_CAPTURE_PROJECT_CODE": True,
     "PROFILER_MAX_DEPTH": 10,
+    "PROFILER_THRESHOLD_RATIO": 8,
     "SHOW_TEMPLATE_CONTEXT": True,
     "SKIP_TEMPLATE_PREFIXES": ("django/forms/widgets/", "admin/widgets/"),
     "SQL_WARNING_THRESHOLD": 500,  # milliseconds

debug_toolbar/static/debug_toolbar/css/toolbar.css

@@ -621,6 +621,12 @@
 #djDebug .djdt-highlighted {
     background-color: lightgrey;
 }
+#djDebug tr.djdt-highlighted.djdt-profile-row {
+    background-color: #ffc;
+}
+#djDebug tr.djdt-highlighted.djdt-profile-row:nth-child(2n + 1) {
+    background-color: #dd9;
+}
 @keyframes djdt-flash-new {
     from {
         background-color: green;

debug_toolbar/templates/debug_toolbar/panels/profiling.html

@@ -12,7 +12,7 @@
   </thead>
   <tbody>
     {% for call in func_list %}
-      <tr class="{% for parent_id in call.parent_ids %} djToggleDetails_{{ parent_id }}{% endfor %}" id="profilingMain_{{ call.id }}">
+      <tr class="djdt-profile-row {% if call.is_project_func %}djdt-highlighted {% endif %} {% for parent_id in call.parent_ids %} djToggleDetails_{{ parent_id }}{% endfor %}" id="profilingMain_{{ call.id }}">
         <td>
           <div data-djdt-styles="paddingLeft:{{ call.indent }}px">
             {% if call.has_subfuncs %}

docs/changes.rst

@@ -4,6 +4,16 @@ Change log
 Pending
 -------
 
+* Added Profiling panel setting ``PROFILER_THRESHOLD_RATIO`` to give users
+  better control over how many function calls are included. A higher value
+  will include more data, but increase render time.
+* Update Profiling panel to include try to always include user code. This
+  code is more important to developers than dependency code.
+* Highlight the project function calls in the profiling panel.
+* Added Profiling panel setting ``PROFILER_CAPTURE_PROJECT_CODE`` to allow
+  users to disable the inclusion of all project code. This will be useful
+  to project setups that have dependencies installed under
+  ``settings.BASE_DIR``.
 * The toolbar's font stack now prefers system UI fonts.
 
 3.6.0 (2022-08-17)

docs/configuration.rst

@@ -250,6 +250,18 @@ Panel options
     WHERE "auth_user"."username" = '''test_username'''
     LIMIT 21
 
+* ``PROFILER_CAPTURE_PROJECT_CODE``
+
+  Default: ``True``
+
+  Panel: profiling
+
+  When enabled this setting will include all project function calls in the
+  panel. Project code is defined as files in the path defined at
+  ``settings.BASE_DIR``. If you install dependencies under
+  ``settings.BASE_DIR`` in a directory other than ``sites-packages`` or
+  ``dist-packages`` you may need to disable this setting.
+
 * ``PROFILER_MAX_DEPTH``
 
   Default: ``10``
@@ -259,6 +271,20 @@ Panel options
   This setting affects the depth of function calls in the profiler's
   analysis.
 
+* ``PROFILER_THRESHOLD_RATIO``
+
+  Default: ``8``
+
+  Panel: profiling
+
+  This setting affects the which calls are included in the profile. A higher
+  value will include more function calls. A lower value will result in a faster
+  render of the profiling panel, but will exclude data.
+
+  This value is used to determine the threshold of cumulative time to include
+  the nested functions. The threshold is calculated by the root calls'
+  cumulative time divided by this ratio.
+
 * ``SHOW_TEMPLATE_CONTEXT``
 
   Default: ``True``

docs/panels.rst

@@ -130,6 +130,12 @@ Profiling information for the processing of the request.
 This panel is included but inactive by default. You can activate it by default
 with the ``DISABLE_PANELS`` configuration option.
 
+The panel will include all function calls made by your project if you're using
+the setting ``settings.BASE_DIR`` to point to your project's root directory.
+If a function is in a file within that directory and does not include
+``"/site-packages/"`` or ``"/dist-packages/"`` in the path, it will be
+included.
+
 Third-party panels
 ------------------
 

docs/tips.rst

@@ -77,6 +77,8 @@ by disabling some configuration options that are enabled by default:
 
 - ``ENABLE_STACKTRACES`` for the SQL and cache panels,
 - ``SHOW_TEMPLATE_CONTEXT`` for the template panel.
+- ``PROFILER_CAPTURE_PROJECT_CODE`` and ``PROFILER_THRESHOLD_RATIO`` for the
+  profiling panel.
 
 Also, check ``SKIP_TEMPLATE_PREFIXES`` when you're using template-based
 form widgets.

tests/panels/test_profiling.py

@@ -33,6 +33,21 @@ def test_insert_content(self):
         # ensure the panel renders correctly.
         content = self.panel.content
         self.assertIn("regular_view", content)
+        self.assertIn("render", content)
+        self.assertValidHTML(content)
+
+    @override_settings(DEBUG_TOOLBAR_CONFIG={"PROFILER_THRESHOLD_RATIO": 1})
+    def test_cum_time_threshold(self):
+        """
+        Test that cumulative time threshold excludes calls
+        """
+        self._get_response = lambda request: regular_view(request, "profiling")
+        response = self.panel.process_request(self.request)
+        self.panel.generate_stats(self.request, response)
+        # ensure the panel renders but doesn't include our function.
+        content = self.panel.content
+        self.assertIn("regular_view", content)
+        self.assertNotIn("render", content)
         self.assertValidHTML(content)
 
     def test_listcomp_escaped(self):