From 5a8c11dfb7b3f5d3c4a3125956c69bb4e159ca53 Mon Sep 17 00:00:00 2001 From: Daniel Harding Date: Tue, 17 May 2022 17:54:25 +0300 Subject: [PATCH 1/5] Add new stack trace functionality * Add a private _StackTraceRecorder class to debug_toolbar.utils which implements caching to reduce the overhead of expensive file system operations. This class has a get_stack_trace() method which combines the functionality of the get_stack() and tidy_stacktrace() functions. * Add a new debug_toolbar.utils function, get_stack_trace() which gets or instantiates a thread/async task context-local _StackTraceRecorder instance and returns a stack trace using its get_stack_trace() method. * Add a new debug_toolbar.utils function, clear_stack_trace_caches(), which removes any thread/async task context-local _StackTraceRecorder instance. * Update the DebugToolbarMiddleware to call the clear_stack_trace_caches() function after processing a request to ensure that each subsequent request gets a clean cache. --- debug_toolbar/middleware.py | 2 + debug_toolbar/utils.py | 98 +++++++++++++++++++++++++++++++++++++ 2 files changed, 100 insertions(+) diff --git a/debug_toolbar/middleware.py b/debug_toolbar/middleware.py index f131861fc..f62904cf9 100644 --- a/debug_toolbar/middleware.py +++ b/debug_toolbar/middleware.py @@ -10,6 +10,7 @@ from debug_toolbar import settings as dt_settings from debug_toolbar.toolbar import DebugToolbar +from debug_toolbar.utils import clear_stack_trace_caches _HTML_TYPES = ("text/html", "application/xhtml+xml") @@ -56,6 +57,7 @@ def __call__(self, request): # Run panels like Django middleware. response = toolbar.process_request(request) finally: + clear_stack_trace_caches() # Deactivate instrumentation ie. monkey-unpatch. This must run # regardless of the response. Keep 'return' clauses below. for panel in reversed(toolbar.enabled_panels): diff --git a/debug_toolbar/utils.py b/debug_toolbar/utils.py index 13f7472ad..e916b44f6 100644 --- a/debug_toolbar/utils.py +++ b/debug_toolbar/utils.py @@ -1,10 +1,12 @@ import inspect +import linecache import os.path import sys from importlib import import_module from pprint import pformat import django +from asgiref.local import Local from django.core.exceptions import ImproperlyConfigured from django.template import Node from django.utils.html import format_html @@ -18,6 +20,9 @@ threading = None +_local_data = Local() + + # Figure out some paths django_path = os.path.realpath(os.path.dirname(django.__file__)) @@ -242,6 +247,99 @@ def get_stack(context=1): return framelist +def _stack_frames(depth=1): + frame = inspect.currentframe() + while frame is not None: + if depth > 0: + depth -= 1 + else: + yield frame + frame = frame.f_back + + +class _StackTraceRecorder: + def __init__(self, excluded_paths): + self.excluded_paths = excluded_paths + self.filename_cache = {} + self.is_excluded_cache = {} + + def get_source_file(self, frame): + frame_filename = frame.f_code.co_filename + + value = self.filename_cache.get(frame_filename) + if value is None: + filename = inspect.getsourcefile(frame) + if filename is None: + is_source = False + filename = frame_filename + else: + is_source = True + # Ensure linecache validity the first time this recorder + # encounters the filename in this frame. + linecache.checkcache(filename) + value = (filename, is_source) + self.filename_cache[frame_filename] = value + + return value + + def is_excluded_path(self, path): + excluded = self.is_excluded_cache.get(path) + if excluded is None: + resolved_path = os.path.realpath(path) + excluded = any( + resolved_path.startswith(excluded_path) + for excluded_path in self.excluded_paths + ) + self.is_excluded_cache[path] = excluded + return excluded + + def get_stack_trace(self, include_locals=False, depth=1): + trace = [] + for frame in _stack_frames(depth=depth + 1): + filename, is_source = self.get_source_file(frame) + + if self.is_excluded_path(filename): + continue + + line_no = frame.f_lineno + func_name = frame.f_code.co_name + + if is_source: + module = inspect.getmodule(frame, filename) + module_globals = module.__dict__ if module is not None else None + source_line = linecache.getline( + filename, line_no, module_globals + ).strip() + else: + source_line = "" + + frame_locals = frame.f_locals if include_locals else None + + trace.append((filename, line_no, func_name, source_line, frame_locals)) + trace.reverse() + return trace + + +def get_stack_trace(depth=1): + config = dt_settings.get_config() + if config["ENABLE_STACKTRACES"]: + stack_trace_recorder = getattr(_local_data, "stack_trace_recorder", None) + if stack_trace_recorder is None: + stack_trace_recorder = _StackTraceRecorder(hidden_paths) + _local_data.stack_trace_recorder = stack_trace_recorder + return stack_trace_recorder.get_stack_trace( + include_locals=config["ENABLE_STACKTRACES_LOCALS"], + depth=depth, + ) + else: + return [] + + +def clear_stack_trace_caches(): + if hasattr(_local_data, "stack_trace_recorder"): + del _local_data.stack_trace_recorder + + class ThreadCollector: def __init__(self): if threading is None: From 0b4a623c8ba6e059f398c2ccc9f5c993c1bee476 Mon Sep 17 00:00:00 2001 From: Daniel Harding Date: Wed, 25 May 2022 19:02:23 +0300 Subject: [PATCH 2/5] Use new stack trace functionality for SQLPanel --- debug_toolbar/panels/sql/tracking.py | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/debug_toolbar/panels/sql/tracking.py b/debug_toolbar/panels/sql/tracking.py index c479a8b5d..8a15977de 100644 --- a/debug_toolbar/panels/sql/tracking.py +++ b/debug_toolbar/panels/sql/tracking.py @@ -6,7 +6,7 @@ from django.utils.encoding import force_str from debug_toolbar import settings as dt_settings -from debug_toolbar.utils import get_stack, get_template_info, tidy_stacktrace +from debug_toolbar.utils import get_stack_trace, get_template_info try: from psycopg2._json import Json as PostgresJson @@ -155,10 +155,6 @@ def _record(self, method, sql, params): finally: stop_time = time() duration = (stop_time - start_time) * 1000 - if dt_settings.get_config()["ENABLE_STACKTRACES"]: - stacktrace = tidy_stacktrace(reversed(get_stack())) - else: - stacktrace = [] _params = "" try: _params = json.dumps(self._decode(params)) @@ -180,7 +176,7 @@ def _record(self, method, sql, params): "raw_sql": sql, "params": _params, "raw_params": params, - "stacktrace": stacktrace, + "stacktrace": get_stack_trace(), "start_time": start_time, "stop_time": stop_time, "is_slow": duration > dt_settings.get_config()["SQL_WARNING_THRESHOLD"], From d70257c65fd53941b4873bba9e662660a9de92a4 Mon Sep 17 00:00:00 2001 From: Daniel Harding Date: Wed, 25 May 2022 19:14:06 +0300 Subject: [PATCH 3/5] Use new stack trace functionality for CachePanel --- debug_toolbar/panels/cache.py | 15 ++------------- 1 file changed, 2 insertions(+), 13 deletions(-) diff --git a/debug_toolbar/panels/cache.py b/debug_toolbar/panels/cache.py index 8294d7734..4ca36a387 100644 --- a/debug_toolbar/panels/cache.py +++ b/debug_toolbar/panels/cache.py @@ -6,14 +6,8 @@ from django.core.cache import CacheHandler, caches from django.utils.translation import gettext_lazy as _, ngettext -from debug_toolbar import settings as dt_settings from debug_toolbar.panels import Panel -from debug_toolbar.utils import ( - get_stack, - get_template_info, - render_stacktrace, - tidy_stacktrace, -) +from debug_toolbar.utils import get_stack_trace, get_template_info, render_stacktrace # The order of the methods in this list determines the order in which they are listed in # the Commands table in the panel content. @@ -135,18 +129,13 @@ def _record_call(self, cache, name, original_method, args, kwargs): t = time.time() - t cache._djdt_recording = False - if dt_settings.get_config()["ENABLE_STACKTRACES"]: - stacktrace = tidy_stacktrace(reversed(get_stack())) - else: - stacktrace = [] - self._store_call_info( name=name, time_taken=t, return_value=value, args=args, kwargs=kwargs, - trace=stacktrace, + trace=get_stack_trace(), template_info=get_template_info(), backend=cache, ) From 1ea9dfb32b773c7d55ba076eb3438d29a7bad643 Mon Sep 17 00:00:00 2001 From: Daniel Harding Date: Sun, 29 May 2022 19:32:14 +0300 Subject: [PATCH 4/5] Add deprecation warnings to old stack trace functions --- debug_toolbar/utils.py | 14 ++++++++++++++ tests/test_utils.py | 17 ++++++++++++++++- 2 files changed, 30 insertions(+), 1 deletion(-) diff --git a/debug_toolbar/utils.py b/debug_toolbar/utils.py index e916b44f6..6ae036456 100644 --- a/debug_toolbar/utils.py +++ b/debug_toolbar/utils.py @@ -2,6 +2,7 @@ import linecache import os.path import sys +import warnings from importlib import import_module from pprint import pformat @@ -49,6 +50,15 @@ def omit_path(path): return any(path.startswith(hidden_path) for hidden_path in hidden_paths) +def _stack_trace_deprecation_warning(): + warnings.warn( + "get_stack() and tidy_stacktrace() are deprecated in favor of" + " get_stack_trace()", + DeprecationWarning, + stacklevel=2, + ) + + def tidy_stacktrace(stack): """ Clean up stacktrace and remove all entries that are excluded by the @@ -57,6 +67,8 @@ def tidy_stacktrace(stack): ``stack`` should be a list of frame tuples from ``inspect.stack()`` or ``debug_toolbar.utils.get_stack()``. """ + _stack_trace_deprecation_warning() + trace = [] for frame, path, line_no, func_name, text in (f[:5] for f in stack): if omit_path(os.path.realpath(path)): @@ -239,6 +251,8 @@ def get_stack(context=1): Modified version of ``inspect.stack()`` which calls our own ``getframeinfo()`` """ + _stack_trace_deprecation_warning() + frame = sys._getframe(1) framelist = [] while frame: diff --git a/tests/test_utils.py b/tests/test_utils.py index 9cfc33bc7..d884b050a 100644 --- a/tests/test_utils.py +++ b/tests/test_utils.py @@ -1,6 +1,11 @@ import unittest -from debug_toolbar.utils import get_name_from_obj, render_stacktrace +from debug_toolbar.utils import ( + get_name_from_obj, + get_stack, + render_stacktrace, + tidy_stacktrace, +) class GetNameFromObjTestCase(unittest.TestCase): @@ -47,3 +52,13 @@ def test_importlib_path_issue_1612(self): '<frozen importlib._bootstrap> in', result, ) + + +class StackTraceTestCase(unittest.TestCase): + def test_deprecated_functions(self): + with self.assertWarns(DeprecationWarning): + stack = get_stack() + self.assertEqual(stack[0][1], __file__) + with self.assertWarns(DeprecationWarning): + stack_trace = tidy_stacktrace(reversed(stack)) + self.assertEqual(stack_trace[-1][0], __file__) From 1c586c964c7656c3423e2fdf49ddce2a7fcb51ad Mon Sep 17 00:00:00 2001 From: Daniel Harding Date: Sun, 29 May 2022 15:33:11 +0300 Subject: [PATCH 5/5] Update change log --- docs/changes.rst | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/docs/changes.rst b/docs/changes.rst index 7a7cc48fd..f981b3d61 100644 --- a/docs/changes.rst +++ b/docs/changes.rst @@ -11,6 +11,17 @@ Change log * Fixed the cache panel to correctly count cache misses from the get_many() cache method. * Removed some obsolete compatibility code from the stack trace recording code. +* Added a new mechanism for capturing stack traces which includes per-request + caching to reduce expensive file system operations. Updated the cache and + SQL panels to record stack traces using this new mechanism. + +Deprecated features +~~~~~~~~~~~~~~~~~~~ + +* The ``debug_toolbar.utils.get_stack()`` and + ``debug_toolbar.utils.tidy_stacktrace()`` functions are deprecated in favor + of the new ``debug_toolbar.utils.get_stack_trace()`` function. They will + removed in the next major version of the Debug Toolbar. 3.4.0 (2022-05-03) ------------------