Expose some initial Prometheus metrics

The Prometheus client library for Python seems not great, but we really need metrics to get a sense of some upcoming performance improvements.

containers/prometheus/Dockerfile

@@ -0,0 +1,2 @@
+FROM docker.io/prom/prometheus:v2.51.1
+COPY prometheus.yml /etc/prometheus/prometheus.yml

containers/prometheus/prometheus.yml

@@ -0,0 +1,8 @@
+global:
+  scrape_interval: 15s
+  evaluation_interval: 15s
+
+scrape_configs:
+  - job_name: web
+    static_configs:
+      - targets: ['web:8080']

docker-compose.yml

@@ -7,12 +7,14 @@ volumes:
   storage:
   logs:
   profile-stats:
+  prometheus:
   test-cache:
   test-coverage:
 
 networks:
   external-web:
   external-nginx:
+  external-prometheus:
   nginx-web:
     internal: true
   web-memcached:
@@ -21,6 +23,8 @@ networks:
     internal: true
   test-postgres:
     internal: true
+  prometheus-web:
+    internal: true
 
 services:
   nginx:
@@ -53,19 +57,23 @@ services:
       WEB_CONCURRENCY: 8
       PYTHONWARNINGS: d
       PYTHONUNBUFFERED: 1
+      PROMETHEUS_MULTIPROC_DIR: /weasyl/storage/prometheus
     volumes:
       - assets:/weasyl/build:ro
       - config:/run/config:ro
       - storage:/weasyl/storage/static
       - logs:/weasyl/storage/log
       - profile-stats:/weasyl/storage/profile-stats
+      - type: tmpfs
+        target: /weasyl/storage/prometheus
       - type: tmpfs
         target: /weasyl/storage/temp
       - type: tmpfs
         target: /tmp
     networks:
       - external-web
       - nginx-web
+      - prometheus-web
       - web-memcached
       - web-postgres
     read_only: false
@@ -95,6 +103,17 @@ services:
       - test-postgres
     read_only: true
 
+  prometheus:
+    build: containers/prometheus
+    volumes:
+      - prometheus:/prometheus
+    networks:
+      - external-prometheus
+      - prometheus-web
+    ports:
+      - ${WEASYL_BIND:-127.0.0.1}:9090:9090/tcp
+    read_only: true
+
   configure:
     profiles: [ configure ]
     image: docker.io/library/alpine:3.16

gunicorn.conf.py

@@ -1,3 +1,6 @@
+from prometheus_client import multiprocess
+
+
 wsgi_app = "weasyl.wsgi:make_wsgi_app()"
 
 proc_name = "weasyl"
@@ -8,3 +11,7 @@
     'X-FORWARDED-PROTO': 'https',
 }
 forwarded_allow_ips = '*'
+
+
+def child_exit(server, worker):
+    multiprocess.mark_process_dead(worker.pid)

pyproject.toml

@@ -27,6 +27,7 @@ pillow = "10.3.0"
 psycopg2cffi = "2.9.0"
 sqlalchemy = "1.4.45"
 lxml = "4.9.2"
+prometheus-client = "^0.20.0"
 
 # https://github.com/Weasyl/misaka
 misaka = {url = "https://pypi.weasyl.dev/misaka/misaka-1.0.3%2Bweasyl.7.tar.gz"}

weasyl/index.py

@@ -16,10 +16,15 @@
 from weasyl import searchtag
 from weasyl import siteupdate
 from weasyl import submission
+from weasyl.metrics import MemcachedHistogram
 
 
+recent_submissions_time = MemcachedHistogram("recent_submissions", "recent submissions fetch time")
+
+
+@recent_submissions_time.cached
 @region.cache_on_arguments(expiration_time=120)
-@d.record_timing
+@recent_submissions_time.uncached
 def recent_submissions():
     submissions = []
     for category in m.ALL_SUBMISSION_CATEGORIES:

weasyl/metrics.py

@@ -0,0 +1,43 @@
+import functools
+import threading
+import time
+
+from prometheus_client import Histogram
+
+
+_MEMCACHED_BUCKETS = [0.001, 0.005, 0.01, 0.025]
+
+
+class MemcachedHistogram:
+    def __init__(self, name, documentation, *args, **kwargs):
+        self._state = threading.local()
+        self._cached = Histogram(f"{name}_cached", f"{documentation} (cached)", *args, buckets=_MEMCACHED_BUCKETS, **kwargs)
+        self._uncached = Histogram(f"{name}_uncached", f"{documentation} (uncached)", *args, **kwargs)
+
+    def cached(self, func):
+        @functools.wraps(func)
+        def wrapped(*args, **kwargs):
+            self._state.cached = True
+
+            start = time.perf_counter()
+            ret = func(*args, **kwargs)
+
+            if self._state.cached:
+                self._cached.observe(time.perf_counter() - start)
+
+            return ret
+
+        return wrapped
+
+    def uncached(self, func):
+        @functools.wraps(func)
+        def wrapped(*args, **kwargs):
+            self._state.cached = False
+
+            start = time.perf_counter()
+            ret = func(*args, **kwargs)
+            self._uncached.observe(time.perf_counter() - start)
+
+            return ret
+
+        return wrapped

weasyl/middleware.py

@@ -7,6 +7,7 @@
 from datetime import datetime, timedelta, timezone
 
 import multipart
+from prometheus_client import Histogram
 from pyramid.decorator import reify
 from pyramid.httpexceptions import (
     HTTPBadRequest,
@@ -154,6 +155,9 @@ def cache_clear_tween(request):
     return cache_clear_tween
 
 
+request_time = Histogram("request_time", "total request time")
+
+
 def db_timer_tween_factory(handler, registry):
     """
     A tween that records timing information in the headers of a response.
@@ -163,10 +167,11 @@ def db_timer_tween(request):
         request.sql_times = []
         request.memcached_times = []
         resp = handler(request)
-        ended_at = time.perf_counter()
+        time_total = time.perf_counter() - started_at
+        request_time.observe(time_total)
         time_in_sql = sum(request.sql_times)
         time_in_memcached = sum(request.memcached_times)
-        time_in_python = ended_at - started_at - time_in_sql - time_in_memcached
+        time_in_python = time_total - time_in_sql - time_in_memcached
         resp.headers['X-SQL-Time-Spent'] = '%0.1fms' % (time_in_sql * 1000,)
         resp.headers['X-Memcached-Time-Spent'] = '%0.1fms' % (time_in_memcached * 1000,)
         resp.headers['X-Python-Time-Spent'] = '%0.1fms' % (time_in_python * 1000,)

weasyl/wsgi.py

@@ -1,3 +1,8 @@
+from prometheus_client import (
+    CollectorRegistry,
+    multiprocess,
+)
+from prometheus_client.openmetrics import exposition as openmetrics
 from pyramid.config import Configurator
 from pyramid.response import Response
 
@@ -80,4 +85,22 @@ def make_wsgi_app(*, configure_cache=True):
             replace_existing_backend=True
         )
 
-    return wsgi_app
+    def app_with_metrics(environ, start_response):
+        if environ["PATH_INFO"] == "/metrics":
+            if "HTTP_X_FORWARDED_FOR" in environ:
+                start_response("403 Forbidden", [])
+                return []
+
+            registry = CollectorRegistry()
+            multiprocess.MultiProcessCollector(registry)
+            data = openmetrics.generate_latest(registry)
+
+            start_response("200 OK", [
+                ("Content-Type", openmetrics.CONTENT_TYPE_LATEST),
+                ("Content-Length", str(len(data))),
+            ])
+            return [data]
+
+        return wsgi_app(environ, start_response)
+
+    return app_with_metrics