Merge branch 'feature/UTAPI-70/add_metrics_to_http_server' into tmp/o…

…ctopus/w/8.1/feature/UTAPI-70/add_metrics_to_http_server

.github/workflows/tests.yaml

@@ -112,7 +112,8 @@ jobs:
         test:
         - name: run unit tests
           command: yarn test
-          env: {}
+          env:
+            UTAPI_METRICS_ENABLED: 'true'
         - name: run client tests
           command: bash ./.github/scripts/run_ft_tests.bash false ft_test:client
           env: {}

libV2/models/RequestContext.js

@@ -3,6 +3,7 @@ const Joi = require('@hapi/joi');
 const { buildModel } = require('./Base');
 const { apiOperations } = require('../server/spec');
 const ResponseContainer = require('./ResponseContainer');
+const { httpRequestDurationSeconds } = require('../server/metrics');
 
 const apiTags = Object.keys(apiOperations);
 const apiOperationIds = Object.values(apiOperations)
@@ -21,6 +22,7 @@ const contextSchema = {
     logger: Joi.any(),
     request: Joi.any(),
     results: Joi.any(),
+    requestTimer: Joi.any(),
 };
 
 const RequestContextModel = buildModel('RequestContext', contextSchema);
@@ -34,6 +36,10 @@ class RequestContext extends RequestContextModel {
         const tag = request.swagger.operation['x-router-controller'];
         const { operationId } = request.swagger.operation;
 
+        const requestTimer = tag !== 'internal'
+            ? httpRequestDurationSeconds.startTimer({ action: operationId })
+            : null;
+
         request.logger.logger.addDefaultFields({
             tag,
             operationId,
@@ -50,6 +56,7 @@ class RequestContext extends RequestContextModel {
             encrypted,
             results: new ResponseContainer(),
             logger: request.logger,
+            requestTimer,
         });
     }
 

libV2/server/index.js

@@ -28,6 +28,7 @@ class UtapiServer extends Process {
         app.use(middleware.loggerMiddleware);
         await initializeOasTools(spec, app);
         app.use(middleware.errorMiddleware);
+        app.use(middleware.httpMetricsMiddleware);
         app.use(middleware.responseLoggerMiddleware);
         return app;
     }

libV2/server/metrics.js

@@ -0,0 +1,20 @@
+const promClient = require('prom-client');
+
+const httpRequestsTotal = new promClient.Counter({
+    name: 'utapi_http_requests_total',
+    help: 'Total number of HTTP requests',
+    labelNames: ['action', 'code'],
+});
+
+const httpRequestDurationSeconds = new promClient.Histogram({
+    name: 'utapi_http_request_duration_seconds',
+    help: 'Duration of HTTP requests in seconds',
+    labelNames: ['action', 'code'],
+    // buckets for response time from 0.1ms to 60s
+    buckets: [0.0001, 0.005, 0.015, 0.05, 0.1, 0.2, 0.3, 0.4, 0.5, 1.0, 5.0, 15.0, 30.0, 60.0],
+});
+
+module.exports = {
+    httpRequestDurationSeconds,
+    httpRequestsTotal,
+};

libV2/server/middleware.js

@@ -6,6 +6,7 @@ const config = require('../config');
 const { logger, buildRequestLogger } = require('../utils');
 const errors = require('../errors');
 const { translateAndAuthorize } = require('../vault');
+const metricHandlers = require('./metrics');
 
 const oasOptions = {
     controllers: path.join(__dirname, './API/'),
@@ -55,6 +56,23 @@ function responseLoggerMiddleware(req, res, next) {
     }
 }
 
+function httpMetricsMiddleware(request, response, next) {
+    // If the request.ctx is undefined then this is an internal oasTools request (/_/docs)
+    // No metrics should be pushed
+    if (config.metrics.enabled && request.ctx && request.ctx.tag !== 'internal') {
+        metricHandlers.httpRequestsTotal
+            .labels({
+                action: request.ctx.operationId,
+                code: response.statusCode,
+            }).inc(1);
+        request.ctx.requestTimer({ code: response.statusCode });
+    }
+
+    if (next) {
+        next();
+    }
+}
+
 // next is purposely not called as all error responses are handled here
 // eslint-disable-next-line no-unused-vars
 function errorMiddleware(err, req, res, next) {
@@ -82,7 +100,7 @@ function errorMiddleware(err, req, res, next) {
         code,
         message,
     });
-    responseLoggerMiddleware(req, res);
+    responseLoggerMiddleware(req, res, () => httpMetricsMiddleware(req, res));
 }
 
 // eslint-disable-next-line no-unused-vars
@@ -158,5 +176,6 @@ module.exports = {
         responseLoggerMiddleware,
         authV4Middleware,
         clientIpLimitMiddleware,
+        httpMetricsMiddleware,
     },
 };

tests/unit/v2/models/testRequestContext.js

@@ -10,6 +10,7 @@ const templateExpected = opts => ({
     operationId: 'healthcheck',
     tag: 'internal',
     encrypted: false,
+    requestTimer: null,
     ...(opts || {}),
 });
 

tests/unit/v2/server/testMiddleware.js

@@ -1,8 +1,11 @@
 const assert = require('assert');
 const sinon = require('sinon');
+const promClient = require('prom-client');
 
 const { middleware } = require('../../../../libV2/server/middleware');
 const { templateRequest, ExpressResponseStub } = require('../../../utils/v2Data');
+const RequestContext = require('../../../../libV2/models/RequestContext');
+const { getMetricValues, assertMetricValue } = require('../../../utils/prom');
 
 describe('Test middleware', () => {
     it('should build a request logger', next => {
@@ -86,4 +89,55 @@ describe('Test middleware', () => {
             }));
         });
     });
+
+    describe('test httpMetricsMiddleware', () => {
+        let resp;
+
+        beforeEach(() => {
+            resp = new ExpressResponseStub();
+            resp.status(200);
+        });
+
+        afterEach(() => {
+            promClient.register.clear();
+        });
+
+        it('should increment the counter if not an internal route', async () => {
+            const req = templateRequest({
+                swagger: {
+                    operation: {
+                        'x-router-controller': 'metrics',
+                        'operationId': 'listMetrics',
+                    },
+                },
+            });
+
+            req.ctx = new RequestContext(req);
+            middleware.httpMetricsMiddleware(req, resp);
+            await assertMetricValue('utapi_http_requests_total', 1);
+            const duration = await getMetricValues('utapi_http_request_duration_seconds');
+            // 14 defined buckets + 1 for Infinity
+            assert.strictEqual(
+                duration.filter(metric => metric.metricName === 'utapi_http_request_duration_seconds_bucket').length,
+                15,
+            );
+            const count = duration.filter(metric => metric.metricName === 'utapi_http_request_duration_seconds_count');
+            assert.deepStrictEqual(count, [{
+                labels: {
+                    action: 'listMetrics',
+                    code: 200,
+                },
+                metricName: 'utapi_http_request_duration_seconds_count',
+                value: 1,
+            }]);
+            assert.strictEqual(count[0].value, 1);
+        });
+
+        it('should not increment the counter if an internal route', async () => {
+            const req = templateRequest();
+            req.ctx = new RequestContext(req);
+            middleware.httpMetricsMiddleware(req, resp);
+            assert.rejects(() => getMetricValues('utapi_http_requests_total'));
+        });
+    });
 });