Merge branch 'http-metrics' into 'main'

Record HTTP response time metrics

See merge request soapbox-pub/ditto!541

deno.json

@@ -36,6 +36,7 @@
     "@b-fuze/deno-dom": "jsr:@b-fuze/deno-dom@^0.1.47",
     "@bradenmacdonald/s3-lite-client": "jsr:@bradenmacdonald/s3-lite-client@^0.7.4",
     "@electric-sql/pglite": "npm:@electric-sql/pglite@^0.2.8",
+    "@esroyo/scoped-performance": "jsr:@esroyo/scoped-performance@^3.1.0",
     "@gfx/canvas-wasm": "jsr:@gfx/canvas-wasm@^0.4.2",
     "@hono/hono": "jsr:@hono/hono@^4.4.6",
     "@isaacs/ttlcache": "npm:@isaacs/ttlcache@^1.4.1",

deno.lock

@@ -4,6 +4,7 @@
     "jsr:@b-fuze/deno-dom@~0.1.47": "0.1.48",
     "jsr:@bradenmacdonald/s3-lite-client@~0.7.4": "0.7.6",
     "jsr:@denosaurs/plug@1.0.3": "1.0.3",
+    "jsr:@esroyo/scoped-performance@^3.1.0": "3.1.0",
     "jsr:@gfx/canvas-wasm@~0.4.2": "0.4.2",
     "jsr:@gleasonator/policy@*": "0.2.0",
     "jsr:@gleasonator/policy@0.2.0": "0.2.0",
@@ -142,6 +143,9 @@
         "jsr:@std/path@0.213.1"
       ]
     },
+    "@esroyo/scoped-performance@3.1.0": {
+      "integrity": "e6a12a1d4edb32cbea7afce005123c1ef684e1815bf9b6caadfbf3e89fe66222"
+    },
     "@gfx/canvas-wasm@0.4.2": {
       "integrity": "d653be3bd12cb2fa9bbe5d1b1f041a81b91d80b68502761204aaf60e4592532a",
       "dependencies": [
@@ -2062,6 +2066,7 @@
     "dependencies": [
       "jsr:@b-fuze/deno-dom@~0.1.47",
       "jsr:@bradenmacdonald/s3-lite-client@~0.7.4",
+      "jsr:@esroyo/scoped-performance@^3.1.0",
       "jsr:@gfx/canvas-wasm@~0.4.2",
       "jsr:@hono/hono@^4.4.6",
       "jsr:@lambdalisue/async@^2.1.1",

src/db/KyselyLogger.ts

@@ -9,12 +9,14 @@ export const KyselyLogger: Logger = (event) => {
   const { query, queryDurationMillis } = event;
   const { sql, parameters } = query;
 
+  const queryDurationSeconds = queryDurationMillis / 1000;
+
   dbQueriesCounter.inc();
-  dbQueryDurationHistogram.observe(queryDurationMillis);
+  dbQueryDurationHistogram.observe(queryDurationSeconds);
 
   console.debug(
     sql,
     JSON.stringify(parameters),
-    `\x1b[90m(${(queryDurationMillis / 1000).toFixed(2)}s)\x1b[0m`,
+    `\x1b[90m(${(queryDurationSeconds / 1000).toFixed(2)}s)\x1b[0m`,
   );
 };

src/metrics.ts

@@ -12,6 +12,12 @@ export const httpResponsesCounter = new Counter({
   labelNames: ['method', 'path', 'status'],
 });
 
+export const httpResponseDurationHistogram = new Histogram({
+  name: 'ditto_http_response_duration_seconds',
+  help: 'Histogram of HTTP response times in seconds',
+  labelNames: ['method', 'path', 'status'],
+});
+
 export const streamingConnectionsGauge = new Gauge({
   name: 'ditto_streaming_connections',
   help: 'Number of active connections to the streaming API',
@@ -91,7 +97,7 @@ export const dbAvailableConnectionsGauge = new Gauge({
 });
 
 export const dbQueryDurationHistogram = new Histogram({
-  name: 'ditto_db_query_duration_ms',
+  name: 'ditto_db_query_duration_seconds',
   help: 'Duration of database queries',
 });
 

src/middleware/metricsMiddleware.ts

@@ -1,9 +1,14 @@
+import { ScopedPerformance } from '@esroyo/scoped-performance';
 import { MiddlewareHandler } from '@hono/hono';
 
-import { httpRequestsCounter, httpResponsesCounter } from '@/metrics.ts';
+import { httpRequestsCounter, httpResponseDurationHistogram, httpResponsesCounter } from '@/metrics.ts';
 
 /** Prometheus metrics middleware that tracks HTTP requests by methods and responses by status code. */
 export const metricsMiddleware: MiddlewareHandler = async (c, next) => {
+  // Start a timer to measure the duration of the response.
+  using perf = new ScopedPerformance();
+  perf.mark('start');
+
   // HTTP Request.
   const { method } = c.req;
   httpRequestsCounter.inc({ method });
@@ -17,4 +22,8 @@ export const metricsMiddleware: MiddlewareHandler = async (c, next) => {
   // Tries to find actual route names first before falling back on potential middleware handlers like `app.use('*')`.
   const path = c.req.matchedRoutes.find((r) => r.method !== 'ALL')?.path ?? c.req.routePath;
   httpResponsesCounter.inc({ method, status, path });
+
+  // Measure the duration of the response.
+  const { duration } = perf.measure('total', 'start');
+  httpResponseDurationHistogram.observe({ method, status, path }, duration / 1000);
 };