Add metrics for view/task time

src/pretix/base/metrics.py

@@ -210,5 +210,9 @@ Provided metrics
 """
 http_view_requests = Counter("http_view_requests", "Total number of HTTP requests made.",
                              ["status_code", "method", "url_name"])
+http_view_times = Histogram("http_view_times", "Return time of views.",
+                            ["status_code", "method", "url_name"])
 celery_task_runs = Counter("celery_task_runs", "Total calls to a celery task",
                            ["task_name", "status"])
+celery_task_times = Histogram("celery_task_times", "Call time of a celery task",
+                              ["task_name"])

src/pretix/base/services/async.py

@@ -15,25 +15,31 @@ import time
 from django.conf import settings
 from django.db import transaction
 
-from pretix.base.metrics import celery_task_runs
+from pretix.base.metrics import celery_task_runs, celery_task_times
 from pretix.celery_app import app
 
 
 class ProfiledTask(app.Task):
     def __call__(self, *args, **kwargs):
+
         if settings.PROFILING_RATE > 0 and random.random() < settings.PROFILING_RATE / 100:
             profiler = cProfile.Profile()
             profiler.enable()
-            starttime = time.time()
+            t0 = time.perf_counter()
             ret = super().__call__(*args, **kwargs)
+            tottime = time.perf_counter() - t0
             profiler.disable()
-            tottime = time.time() - starttime
             profiler.dump_stats(os.path.join(settings.PROFILE_DIR, '{time:.0f}_{tottime:.3f}_celery_{t}.pstat'.format(
                 t=self.name, tottime=tottime, time=time.time()
             )))
-            return ret
         else:
-            return super().__call__(*args, **kwargs)
+            t0 = time.perf_counter()
+            ret = super().__call__(*args, **kwargs)
+            tottime = time.perf_counter() - t0
+
+        if settings.METRICS_ENABLED:
+            celery_task_times.observe(tottime, task_name=self.name)
+        return ret
 
     def on_failure(self, exc, task_id, args, kwargs, einfo):
         if settings.METRICS_ENABLED:

src/pretix/base/services/cart.py

@@ -1,7 +1,6 @@
 from collections import Counter, namedtuple
 from datetime import timedelta
 from decimal import Decimal
-
 from typing import List, Optional
 
 from celery.exceptions import MaxRetriesExceededError

src/pretix/control/context.py

@@ -1,4 +1,5 @@
 import sys
+
 from django.conf import settings
 from django.core.urlresolvers import Resolver404, get_script_prefix, resolve
 

src/pretix/helpers/metrics/middleware.py

@@ -1,6 +1,8 @@
+import time
+
 from django.urls import resolve
 
-from pretix.base.metrics import http_view_requests
+from pretix.base.metrics import http_view_requests, http_view_times
 
 
 class MetricsMiddleware(object):
@@ -23,8 +25,12 @@ class MetricsMiddleware(object):
 
         url = resolve(request.path_info)
 
+        t0 = time.perf_counter()
         resp = self.get_response(request)
+        tdiff = time.perf_counter() - t0
         http_view_requests.inc(1, status_code=resp.status_code, method=request.method,
                                url_name=url.namespace + ':' + url.url_name)
+        http_view_times.observe(tdiff, status_code=resp.status_code, method=request.method,
+                                url_name=url.namespace + ':' + url.url_name)
 
         return resp

src/pretix/helpers/profile/middleware.py

@@ -26,10 +26,10 @@ class CProfileMiddleware(object):
         if settings.PROFILING_RATE > 0 and random.random() < settings.PROFILING_RATE / 100:
             profiler = cProfile.Profile()
             profiler.enable()
-            starttime = time.time()
+            starttime = time.perf_counter()
             response = self.get_response(request)
             profiler.disable()
-            tottime = time.time() - starttime
+            tottime = time.perf_counter() - starttime
             profiler.dump_stats(os.path.join(settings.PROFILE_DIR, '{time:.0f}_{tottime:.3f}_{path}.pstat'.format(
                 path=request.path[1:].replace("/", "_"), tottime=tottime, time=time.time()
             )))