Replace time.time() with time.perf_counter() (#1777)

time.perf_counter() is guaranteed to use the highest-resolution clock
available, and is monotonically increasing, neither of which are true
for time.time().  Thanks @matthiask for the suggestion!

Author: living180

debug_toolbar/management/commands/debugsqlshell.py

@@ -1,4 +1,4 @@
-from time import time
+from time import perf_counter
 
 import sqlparse
 from django.core.management.commands.shell import Command
@@ -19,12 +19,12 @@
 
 class PrintQueryWrapper(base_module.CursorDebugWrapper):
     def execute(self, sql, params=()):
-        start_time = time()
+        start_time = perf_counter()
         try:
             return self.cursor.execute(sql, params)
         finally:
             raw_sql = self.db.ops.last_executed_query(self.cursor, sql, params)
-            end_time = time()
+            end_time = perf_counter()
             duration = (end_time - start_time) * 1000
             formatted_sql = sqlparse.format(raw_sql, reindent=True)
             print(f"{formatted_sql} [{duration:.2f}ms]")

debug_toolbar/panels/cache.py

@@ -1,5 +1,5 @@
 import functools
-import time
+from time import perf_counter
 
 from asgiref.local import Local
 from django.conf import settings
@@ -148,9 +148,9 @@ def _record_call(self, cache, name, original_method, args, kwargs):
         # the course of this call, and then reset it back afterward.
         cache._djdt_panel = None
         try:
-            t = time.time()
+            start_time = perf_counter()
             value = original_method(*args, **kwargs)
-            t = time.time() - t
+            t = perf_counter() - start_time
         finally:
             cache._djdt_panel = self
 

debug_toolbar/panels/sql/tracking.py

@@ -1,7 +1,7 @@
 import contextvars
 import datetime
 import json
-from time import time
+from time import perf_counter
 
 import django.test.testcases
 from django.db.backends.utils import CursorWrapper
@@ -162,11 +162,11 @@ def _record(self, method, sql, params):
             conn = self.db.connection
             initial_conn_status = conn.info.transaction_status
 
-        start_time = time()
+        start_time = perf_counter()
         try:
             return method(sql, params)
         finally:
-            stop_time = time()
+            stop_time = perf_counter()
             duration = (stop_time - start_time) * 1000
             _params = ""
             try:

debug_toolbar/panels/timer.py

@@ -1,4 +1,4 @@
-import time
+from time import perf_counter
 
 from django.template.loader import render_to_string
 from django.templatetags.static import static
@@ -59,15 +59,15 @@ def scripts(self):
         return scripts
 
     def process_request(self, request):
-        self._start_time = time.time()
+        self._start_time = perf_counter()
         if self.has_content:
             self._start_rusage = resource.getrusage(resource.RUSAGE_SELF)
         return super().process_request(request)
 
     def generate_stats(self, request, response):
         stats = {}
         if hasattr(self, "_start_time"):
-            stats["total_time"] = (time.time() - self._start_time) * 1000
+            stats["total_time"] = (perf_counter() - self._start_time) * 1000
         if hasattr(self, "_start_rusage"):
             self._end_rusage = resource.getrusage(resource.RUSAGE_SELF)
             stats["utime"] = 1000 * self._elapsed_ru("ru_utime")

docs/changes.rst

@@ -12,6 +12,8 @@ Pending
 * Reworked the cache panel instrumentation code to no longer attempt to undo
   monkey patching of cache methods, as that turned out to be fragile in the
   presence of other code which also monkey patches those methods.
+* Update all timing code that used :py:func:`time.time()` to use
+  :py:func:`time.perf_counter()` instead.
 
 4.0.0 (2023-04-03)
 ------------------