feat(metrics): expose per-path per-status per-method express metrics

Author: djMax

__tests__/fake-serv.test.ts

@@ -78,6 +78,9 @@ describe('fake-serv', () => {
         expect(res.text).toMatch(/nodejs_version_info{version/);
         expect(res.text).toMatch(/# UNIT http_server_duration ms/);
         expect(res.text).toMatch(/world_requests_total{method="get"} 1/);
+        expect(res.text).toContain(
+          'http_request_duration_seconds_bucket{status_code="200",method="GET",path="/world"',
+        );
       });
 
     // Clean shutdown

src/express-app/app.ts

@@ -118,7 +118,11 @@ export async function startApp<
     app.set('trust proxy', config.trustProxy);
   }
 
-  app.use(loggerMiddleware(app, logging?.logRequestBody, logging?.logResponseBody));
+  const histogram = app.locals.meter.createHistogram('http_request_duration_seconds', {
+    description: 'Duration of HTTP requests in seconds',
+  });
+
+  app.use(loggerMiddleware(app, histogram, logging?.logRequestBody, logging?.logResponseBody));
 
   // Allow the service to add locals, etc. We put this before the body parsers
   // so that the req can decide whether to save the raw request body or not.
@@ -236,7 +240,7 @@ export async function startApp<
     app.use(notFoundMiddleware());
   }
   if (errors?.enabled) {
-    app.use(errorHandlerMiddleware(app, errors?.unnest, errors?.render));
+    app.use(errorHandlerMiddleware(app, histogram, errors?.unnest, errors?.render));
   }
 
   return app;

src/telemetry/index.ts

@@ -55,6 +55,16 @@ export function startGlobalTelemetry(serviceName: string) {
       resourceDetectors: getResourceDetectors(),
       metricReader: prometheusExporter,
       instrumentations: [getAutoInstrumentations()],
+      views: [
+        new opentelemetry.metrics.View({
+          instrumentName: 'http_request_duration_seconds',
+          instrumentType: opentelemetry.metrics.InstrumentType.HISTOGRAM,
+          aggregation: new opentelemetry.metrics.ExplicitBucketHistogramAggregation(
+            [0.003, 0.03, 0.1, 0.3, 1.5, 10],
+            true,
+          ),
+        }),
+      ],
     });
     telemetrySdk.start();
   }

src/telemetry/requestLogger.ts

@@ -1,4 +1,5 @@
 import type { RequestHandler, Request, Response, ErrorRequestHandler } from 'express';
+import { Histogram } from '@opentelemetry/api';
 
 import { ServiceError } from '../error';
 import type { AnyServiceLocals, RequestWithApp, ServiceExpress, ServiceLocals } from '../types';
@@ -44,6 +45,7 @@ function finishLog<SLocals extends AnyServiceLocals = ServiceLocals<Configuratio
   error: Error | undefined,
   req: Request,
   res: Response,
+  histogram: Histogram,
 ) {
   const prefs = (res.locals as WithLogPrefs)[LOG_PREFS];
   if (prefs.logged) {
@@ -61,6 +63,14 @@ function finishLog<SLocals extends AnyServiceLocals = ServiceLocals<Configuratio
     dur,
   };
 
+  const path = req.route ? req.route.path : null;
+  histogram.record(dur, {
+    status_code: endLog.s,
+    method: endLog.m,
+    path,
+    service: app.locals.name,
+  });
+
   if (res.locals.user?.id) {
     endLog.u = res.locals.user.id;
   }
@@ -95,7 +105,12 @@ function finishLog<SLocals extends AnyServiceLocals = ServiceLocals<Configuratio
 
 export function loggerMiddleware<
   SLocals extends AnyServiceLocals = ServiceLocals<ConfigurationSchema>,
->(app: ServiceExpress<SLocals>, logRequests?: boolean, logResponses?: boolean): RequestHandler {
+>(
+  app: ServiceExpress<SLocals>,
+  histogram: Histogram,
+  logRequests?: boolean,
+  logResponses?: boolean,
+): RequestHandler {
   const { logger, service } = app.locals;
   return function gblogger(req, res, next) {
     const prefs: LogPrefs = {
@@ -135,15 +150,15 @@ export function loggerMiddleware<
     service.getLogFields?.(req as RequestWithApp<SLocals>, preLog);
     logger.info(preLog, 'pre');
 
-    const logWriter = () => finishLog(app, undefined, req, res);
+    const logWriter = () => finishLog(app, undefined, req, res, histogram);
     res.on('finish', logWriter);
     next();
   };
 }
 
 export function errorHandlerMiddleware<
   SLocals extends AnyServiceLocals = ServiceLocals<ConfigurationSchema>,
->(app: ServiceExpress<SLocals>, unnest?: boolean, returnError?: boolean) {
+>(app: ServiceExpress<SLocals>, histogram: Histogram, unnest?: boolean, returnError?: boolean) {
   const gbErrorHandler: ErrorRequestHandler = (error, req, res, next) => {
     let loggable: Partial<ServiceError> = error;
     const body = error.response?.body || error.body;
@@ -159,7 +174,7 @@ export function errorHandlerMiddleware<
     // Set the status to error, even if we aren't going to render the error.
     res.status(loggable.status || 500);
     if (returnError) {
-      finishLog(app, error, req, res);
+      finishLog(app, error, req, res, histogram);
       const prefs = (res.locals as WithLogPrefs)[LOG_PREFS];
       prefs.logged = true;
       res.json({