feat: start tracking operation duration (#6514)

src/lib/features/frontend-api/frontend-api-service.ts

@@ -16,12 +16,14 @@ import {
 import { validateOrigins } from '../../util';
 import { BadDataError, InvalidTokenError } from '../../error';
 import {
+    OPERATION_TIME,
     FRONTEND_API_REPOSITORY_CREATED,
     PROXY_REPOSITORY_CREATED,
 } from '../../metric-events';
 import { FrontendApiRepository } from './frontend-api-repository';
 import { GlobalFrontendApiCache } from './global-frontend-api-cache';
 import { ProxyRepository } from './proxy-repository';
+import metricsHelper from '../../util/metrics-helper';
 
 export type Config = Pick<
     IUnleashConfig,
@@ -61,6 +63,8 @@ export class FrontendApiService {
 
     private cachedFrontendSettings?: FrontendSettings;
 
+    private timer: Function;
+
     constructor(
         config: Config,
         stores: Stores,
@@ -72,17 +76,23 @@ export class FrontendApiService {
         this.stores = stores;
         this.services = services;
         this.globalFrontendApiCache = globalFrontendApiCache;
+
+        this.timer = (operationId) =>
+            metricsHelper.wrapTimer(config.eventBus, OPERATION_TIME, {
+                operationId,
+            });
     }
 
     async getFrontendApiFeatures(
         token: IApiUser,
         context: Context,
     ): Promise<FrontendApiFeatureSchema[]> {
+        const stopTimer = this.timer('getFrontendApiFeatures');
         const client = await this.clientForFrontendApiToken(token);
         const definitions = client.getFeatureToggleDefinitions() || [];
         const sessionId = context.sessionId || String(Math.random());
 
-        return definitions
+        const resultDefinitions = definitions
             .filter((feature) =>
                 client.isEnabled(feature.name, {
                     ...context,
@@ -98,17 +108,20 @@ export class FrontendApiService {
                 }),
                 impressionData: Boolean(feature.impressionData),
             }));
+        stopTimer();
+        return resultDefinitions;
     }
 
     async getNewFrontendApiFeatures(
         token: IApiUser,
         context: Context,
     ): Promise<FrontendApiFeatureSchema[]> {
+        const stopTimer = this.timer('getNewFrontendApiFeatures');
         const client = await this.newClientForFrontendApiToken(token);
         const definitions = client.getFeatureToggleDefinitions() || [];
         const sessionId = context.sessionId || String(Math.random());
 
-        return definitions
+        const resultDefinitions = definitions
             .filter((feature) => {
                 const enabled = client.isEnabled(feature.name, {
                     ...context,
@@ -125,6 +138,8 @@ export class FrontendApiService {
                 }),
                 impressionData: Boolean(feature.impressionData),
             }));
+        stopTimer();
+        return resultDefinitions;
     }
 
     async registerFrontendApiMetrics(

src/lib/metric-events.ts

@@ -1,5 +1,6 @@
 const REQUEST_TIME = 'request_time';
 const DB_TIME = 'db_time';
+const OPERATION_TIME = 'operation_time';
 const SCHEDULER_JOB_TIME = 'scheduler_job_time';
 const FEATURES_CREATED_BY_PROCESSED = 'features_created_by_processed';
 const EVENTS_CREATED_BY_PROCESSED = 'events_created_by_processed';
@@ -11,6 +12,7 @@ export {
     REQUEST_TIME,
     DB_TIME,
     SCHEDULER_JOB_TIME,
+    OPERATION_TIME,
     FEATURES_CREATED_BY_PROCESSED,
     EVENTS_CREATED_BY_PROCESSED,
     FRONTEND_API_REPOSITORY_CREATED,

src/lib/metrics.test.ts

@@ -2,7 +2,7 @@ import { register } from 'prom-client';
 import EventEmitter from 'events';
 import { IEventStore } from './types/stores/event-store';
 import { createTestConfig } from '../test/config/test-config';
-import { DB_TIME, REQUEST_TIME } from './metric-events';
+import { DB_TIME, OPERATION_TIME, REQUEST_TIME } from './metric-events';
 import {
     CLIENT_METRICS,
     CLIENT_REGISTER,
@@ -172,6 +172,18 @@ test('should collect metrics for db query timings', async () => {
     );
 });
 
+test('should collect metrics for operation timings', async () => {
+    eventBus.emit(OPERATION_TIME, {
+        operationId: 'getToggles',
+        time: 0.1337,
+    });
+
+    const metrics = await prometheusRegister.metrics();
+    expect(metrics).toMatch(
+        /operation_duration_seconds\{quantile="0\.99",operationId="getToggles"\} 0.1337/,
+    );
+});
+
 test('should collect metrics for feature toggle size', async () => {
     const metrics = await prometheusRegister.metrics();
     expect(metrics).toMatch(/feature_toggles_total\{version="(.*)"\} 0/);

src/lib/metrics.ts

@@ -85,6 +85,14 @@ export default class MetricsMonitor {
             maxAgeSeconds: 600,
             ageBuckets: 5,
         });
+        const operationDuration = createSummary({
+            name: 'operation_duration_seconds',
+            help: 'Operation duration time',
+            labelNames: ['operationId'],
+            percentiles: [0.1, 0.5, 0.9, 0.95, 0.99],
+            maxAgeSeconds: 600,
+            ageBuckets: 5,
+        });
         const featureToggleUpdateTotal = createCounter({
             name: 'feature_toggle_update_total',
             help: 'Number of times a toggle has been updated. Environment label would be "n/a" when it is not available, e.g. when a feature toggle is created.',
@@ -405,6 +413,10 @@ export default class MetricsMonitor {
             schedulerDuration.labels(jobId).observe(time);
         });
 
+        eventBus.on(events.OPERATION_TIME, ({ operationId, time }) => {
+            operationDuration.labels(operationId).observe(time);
+        });
+
         eventBus.on(events.EVENTS_CREATED_BY_PROCESSED, ({ updated }) => {
             eventCreatedByMigration.inc(updated);
         });