diff --git a/src/lib/__snapshots__/create-config.test.ts.snap b/src/lib/__snapshots__/create-config.test.ts.snap index 9cbc9da5b965..03fdd0a538da 100644 --- a/src/lib/__snapshots__/create-config.test.ts.snap +++ b/src/lib/__snapshots__/create-config.test.ts.snap @@ -132,6 +132,7 @@ exports[`should create default config 1`] = ` "personalAccessTokensKillSwitch": false, "proPlanAutoCharge": false, "queryMissingTokens": false, + "responseTimeMetricsFix": false, "responseTimeWithAppNameKillSwitch": false, "scimApi": false, "sdkReporting": false, diff --git a/src/lib/middleware/response-time-metrics.test.ts b/src/lib/middleware/response-time-metrics.test.ts new file mode 100644 index 000000000000..38a459f49273 --- /dev/null +++ b/src/lib/middleware/response-time-metrics.test.ts @@ -0,0 +1,402 @@ +import { EventEmitter } from 'stream'; +import { + responseTimeMetrics, + storeRequestedRoute, +} from './response-time-metrics'; +import { REQUEST_TIME } from '../metric-events'; + +const fixedResponseTime = 100; +// mock response-time library +jest.mock('response-time', () => { + return (responseTimeMetricsFn) => { + return (req, res) => { + return responseTimeMetricsFn(req, res, fixedResponseTime); + }; + }; +}); + +const isDefined = async (timeInfo: any, limit = 10) => { + let counter = 0; + while (timeInfo === undefined) { + // Waiting for event to be triggered + await new Promise((resolve) => setTimeout(resolve, 10)); + counter++; + if (counter > limit) { + throw new Error('Event was not triggered'); + } + } +}; + +const flagResolver = { + isEnabled: jest.fn(), + getAll: jest.fn(), + getVariant: jest.fn(), +}; + +const flagResolverWithResponseTimeMetricsFix = { + ...flagResolver, + isEnabled: (name: string) => name === 'responseTimeMetricsFix', +}; + +// Make sure it's always cleaned up +let res: any; +beforeEach(() => { + res = { + statusCode: 200, + locals: {}, // res will always have locals (according to express RequestHandler type) + }; +}); + +describe('responseTimeMetrics old behavior', () => { + const instanceStatsService = { + getAppCountSnapshot: jest.fn(), + }; + const eventBus = new EventEmitter(); + + test('uses baseUrl and route path to report metrics', async () => { + let timeInfo: any; + // register a listener + eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + const middleware = responseTimeMetrics( + eventBus, + flagResolver, + instanceStatsService, + ); + const req = { + baseUrl: '/api/admin', + route: { + path: '/features', + }, + method: 'GET', + path: 'should-not-be-used', + }; + + // @ts-expect-error req and res doesn't have all properties + middleware(req, res); + + await isDefined(timeInfo); + expect(timeInfo).toMatchObject({ + path: '/api/admin/features', + method: 'GET', + statusCode: 200, + time: 100, + appName: undefined, + }); + }); + + test('uses baseUrl and route path to report metrics even with the new flag enabled', async () => { + let timeInfo: any; + // register a listener + eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + const middleware = responseTimeMetrics( + eventBus, + flagResolverWithResponseTimeMetricsFix, + instanceStatsService, + ); + const req = { + baseUrl: '/api/admin', + route: { + path: '/features', + }, + method: 'GET', + path: 'should-not-be-used', + }; + + // @ts-expect-error req and res doesn't have all properties + middleware(req, res); + + await isDefined(timeInfo); + expect(timeInfo).toMatchObject({ + path: '/api/admin/features', + }); + }); + + test('uses baseUrl and route path to report metrics even with res.locals.route but flag disabled', async () => { + let timeInfo: any; + // register a listener + eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + const middleware = responseTimeMetrics( + eventBus, + flagResolver, + instanceStatsService, + ); + const req = { + baseUrl: '/api/admin', + route: { + path: '/features', + }, + method: 'GET', + path: 'should-not-be-used', + }; + + // @ts-expect-error req and res doesn't have all properties + middleware(req, { + statusCode: 200, + locals: { route: '/should-not-be-used-eiter' }, + }); + + await isDefined(timeInfo); + expect(timeInfo).toMatchObject({ + path: '/api/admin/features', + }); + }); + + test('reports (hidden) when route is not present', async () => { + let timeInfo: any; + // register a listener + eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + const middleware = responseTimeMetrics( + eventBus, + flagResolver, + instanceStatsService, + ); + const req = { + baseUrl: '/api/admin', + method: 'GET', + path: 'should-not-be-used', + }; + + // @ts-expect-error req and res doesn't have all properties + middleware(req, res); + + await isDefined(timeInfo); + expect(timeInfo).toMatchObject({ + path: '(hidden)', + }); + }); + + test.each([ + ['/api/admin/features', '(hidden)'], + ['/api/admin/features/my-feature', '(hidden)'], + ['/api/frontend/client/metrics', '(hidden)'], + ['/api/client/metrics', '(hidden)'], + ['/edge/validate', '(hidden)'], + ['/whatever', '(hidden)'], + ['/healthz', '(hidden)'], + ['/internal-backstage/prometheus', '(hidden)'], + ])( + 'when path is %s and route is undefined, reports %s', + async (path: string, expected: string) => { + let timeInfo: any; + // register a listener + eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + const middleware = responseTimeMetrics( + eventBus, + flagResolver, + instanceStatsService, + ); + const req = { + baseUrl: '/api/admin', + method: 'GET', + path: 'should-not-be-used', + }; + const reqWithoutRoute = { + method: 'GET', + path, + }; + + // @ts-expect-error req and res doesn't have all properties + storeRequestedRoute(req, res, () => {}); + // @ts-expect-error req and res doesn't have all properties + middleware(reqWithoutRoute, res); + + await isDefined(timeInfo); + expect(timeInfo).toMatchObject({ + path: expected, + }); + }, + ); +}); + +describe('responseTimeMetrics new behavior', () => { + const instanceStatsService = { + getAppCountSnapshot: jest.fn(), + }; + const eventBus = new EventEmitter(); + + test('uses baseUrl and route path to report metrics with flag enabled, but no res.locals.route', async () => { + let timeInfo: any; + // register a listener + eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + const middleware = responseTimeMetrics( + eventBus, + flagResolverWithResponseTimeMetricsFix, + instanceStatsService, + ); + const req = { + baseUrl: '/api/admin', + route: { + path: '/features', + }, + method: 'GET', + path: 'should-not-be-used', + }; + + // @ts-expect-error req and res doesn't have all properties + middleware(req, res); + + await isDefined(timeInfo); + expect(timeInfo).toMatchObject({ + path: '/api/admin/features', + }); + }); + + test('uses res.locals.route to report metrics when flag enabled', async () => { + let timeInfo: any; + // register a listener + eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + const middleware = responseTimeMetrics( + eventBus, + flagResolverWithResponseTimeMetricsFix, + instanceStatsService, + ); + const req = { + baseUrl: '/api/admin', + route: { + path: '/features', + }, + method: 'GET', + path: 'should-not-be-used', + }; + const reqWithoutRoute = { + method: 'GET', + }; + + // @ts-expect-error req and res doesn't have all properties + storeRequestedRoute(req, res, () => {}); + // @ts-expect-error req and res doesn't have all properties + middleware(reqWithoutRoute, res); + + await isDefined(timeInfo); + expect(timeInfo).toMatchObject({ + path: '/api/admin/features', + }); + }); + + test('uses res.locals.route to report metrics when flag enabled', async () => { + let timeInfo: any; + // register a listener + eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + const middleware = responseTimeMetrics( + eventBus, + flagResolverWithResponseTimeMetricsFix, + instanceStatsService, + ); + const req = { + baseUrl: '/api/admin', + route: { + path: '/features', + }, + method: 'GET', + path: 'should-not-be-used', + }; + const reqWithoutRoute = { + method: 'GET', + }; + + // @ts-expect-error req and res doesn't have all properties + storeRequestedRoute(req, res, () => {}); + // @ts-expect-error req and res doesn't have all properties + middleware(reqWithoutRoute, res); + + await isDefined(timeInfo); + expect(timeInfo).toMatchObject({ + path: '/api/admin/features', + }); + }); + + test.each([undefined, '/'])( + 'reports (hidden) when route is undefined and path is %s', + async (path: string) => { + let timeInfo: any; + // register a listener + eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + const middleware = responseTimeMetrics( + eventBus, + flagResolverWithResponseTimeMetricsFix, + instanceStatsService, + ); + const req = { + baseUrl: '/api/admin', + method: 'GET', + path: 'should-not-be-used', + }; + const reqWithoutRoute = { + method: 'GET', + path, + }; + + // @ts-expect-error req and res doesn't have all properties + storeRequestedRoute(req, res, () => {}); + // @ts-expect-error req and res doesn't have all properties + middleware(reqWithoutRoute, res); + + await isDefined(timeInfo); + expect(timeInfo).toMatchObject({ + path: '(hidden)', + }); + }, + ); + + test.each([ + ['/api/admin/features', '/api/admin/(hidden)'], + ['/api/admin/features/my-feature', '/api/admin/(hidden)'], + ['/api/frontend/client/metrics', '/api/frontend/(hidden)'], + ['/api/client/metrics', '/api/client/(hidden)'], + ['/edge/validate', '/edge/(hidden)'], + ['/whatever', '(hidden)'], + ['/healthz', '(hidden)'], + ['/internal-backstage/prometheus', '(hidden)'], + ])( + 'when path is %s and route is undefined, reports %s', + async (path: string, expected: string) => { + let timeInfo: any; + // register a listener + eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + const middleware = responseTimeMetrics( + eventBus, + flagResolverWithResponseTimeMetricsFix, + instanceStatsService, + ); + const req = { + baseUrl: '/api/admin', + method: 'GET', + path: 'should-not-be-used', + }; + const reqWithoutRoute = { + method: 'GET', + path, + }; + + // @ts-expect-error req and res doesn't have all properties + storeRequestedRoute(req, res, () => {}); + // @ts-expect-error req and res doesn't have all properties + middleware(reqWithoutRoute, res); + + await isDefined(timeInfo); + expect(timeInfo).toMatchObject({ + path: expected, + }); + }, + ); +}); diff --git a/src/lib/middleware/response-time-metrics.ts b/src/lib/middleware/response-time-metrics.ts index fd585b12c3a9..357d74a36278 100644 --- a/src/lib/middleware/response-time-metrics.ts +++ b/src/lib/middleware/response-time-metrics.ts @@ -3,21 +3,62 @@ import EventEmitter from 'events'; import { REQUEST_TIME } from '../metric-events'; import { IFlagResolver } from '../types/experimental'; import { InstanceStatsService } from '../services'; +import { RequestHandler } from 'express'; -// eslint-disable-next-line @typescript-eslint/naming-convention const _responseTime = responseTime.default; - const appNameReportingThreshold = 1000; +export const storeRequestedRoute: RequestHandler = (req, res, next) => { + if (req.route) { + res.locals = { + ...res.locals, + route: `${req.baseUrl}${req.route.path}`, + }; + } + next(); +}; + +function collapse(path: string): string { + let prefix = ''; + if (path) { + if (path.startsWith('/api/admin')) { + prefix = '/api/admin/'; + } else if (path.startsWith('/api/client')) { + prefix = '/api/client/'; + } else if (path.startsWith('/api/frontend')) { + prefix = '/api/frontend/'; + } else if (path.startsWith('/api')) { + prefix = '/api/'; + } else if (path.startsWith('/edge')) { + prefix = '/edge/'; + } else if (path.startsWith('/auth')) { + prefix = '/auth/'; + } + } + + return `${prefix}(hidden)`; +} + export function responseTimeMetrics( eventBus: EventEmitter, flagResolver: IFlagResolver, instanceStatsService: Pick, -): any { +): RequestHandler { return _responseTime((req, res, time) => { const { statusCode } = res; - const pathname = req.route ? req.baseUrl + req.route.path : '(hidden)'; - + const responseTimeMetricsFix = flagResolver.isEnabled( + 'responseTimeMetricsFix', + ); + let pathname: string | undefined = undefined; + if (responseTimeMetricsFix && res.locals.route) { + pathname = res.locals.route; + } else if (req.route) { + pathname = req.baseUrl + req.route.path; + } + // when pathname is undefined use a fallback + pathname = + pathname ?? + (responseTimeMetricsFix ? collapse(req.path) : '(hidden)'); let appName: string | undefined; if ( !flagResolver.isEnabled('responseTimeWithAppNameKillSwitch') && @@ -34,6 +75,7 @@ export function responseTimeMetrics( time, appName, }; + eventBus.emit(REQUEST_TIME, timingInfo); }); } diff --git a/src/lib/routes/admin-api/index.ts b/src/lib/routes/admin-api/index.ts index ce554656e183..20f1ca02438a 100644 --- a/src/lib/routes/admin-api/index.ts +++ b/src/lib/routes/admin-api/index.ts @@ -37,7 +37,7 @@ import FeatureSearchController from '../../features/feature-search/feature-searc import { InactiveUsersController } from '../../users/inactive/inactive-users-controller'; import { UiObservabilityController } from '../../features/ui-observability-controller/ui-observability-controller'; -class AdminApi extends Controller { +export class AdminApi extends Controller { constructor(config: IUnleashConfig, services: IUnleashServices, db: Db) { super(config); @@ -171,5 +171,3 @@ class AdminApi extends Controller { ); } } - -module.exports = AdminApi; diff --git a/src/lib/routes/controller.ts b/src/lib/routes/controller.ts index 37f2995e7f21..a950bad05988 100644 --- a/src/lib/routes/controller.ts +++ b/src/lib/routes/controller.ts @@ -4,6 +4,7 @@ import { IUnleashConfig, NONE } from '../types'; import { handleErrors } from './util'; import requireContentType from '../middleware/content_type_checker'; import { PermissionError } from '../error'; +import { storeRequestedRoute } from '../middleware/response-time-metrics'; interface IRequestHandler< P = any, @@ -108,6 +109,7 @@ export default class Controller { route(options: IRouteOptions): void { this.app[options.method]( options.path, + storeRequestedRoute, checkPermission(options.permission), checkPrivateProjectPermissions(), this.useContentTypeMiddleware(options), @@ -195,6 +197,7 @@ export default class Controller { ): void { this.app.post( path, + storeRequestedRoute, checkPermission(permission), checkPrivateProjectPermissions(), filehandler.bind(this), @@ -206,12 +209,11 @@ export default class Controller { this.app.use(path, router); } - // eslint-disable-next-line @typescript-eslint/explicit-module-boundary-types useWithMiddleware(path: string, router: IRouter, middleware: any): void { this.app.use(path, middleware, router); } - get router(): any { + get router(): IRouter { return this.app; } } diff --git a/src/lib/routes/index.ts b/src/lib/routes/index.ts index 401070582f4e..8ee8951c7058 100644 --- a/src/lib/routes/index.ts +++ b/src/lib/routes/index.ts @@ -4,10 +4,10 @@ import { SimplePasswordProvider } from './auth/simple-password-provider'; import { IUnleashConfig, IUnleashServices } from '../types'; import LogoutController from './logout'; import rateLimit from 'express-rate-limit'; +import Controller from './controller'; +import { AdminApi } from './admin-api'; +import ClientApi from './client-api'; -const AdminApi = require('./admin-api'); -const ClientApi = require('./client-api'); -const Controller = require('./controller'); import { HealthCheckController } from './health-check'; import FrontendAPIController from './proxy-api'; import EdgeController from './edge-api'; diff --git a/src/lib/types/experimental.ts b/src/lib/types/experimental.ts index 3c0355dc44a0..1c46175c7cad 100644 --- a/src/lib/types/experimental.ts +++ b/src/lib/types/experimental.ts @@ -51,6 +51,7 @@ export type IFlagKey = | 'disableUpdateMaxRevisionId' | 'disablePublishUnannouncedEvents' | 'sdkReporting' + | 'responseTimeMetricsFix' | 'scimApi' | 'displayEdgeBanner'; @@ -257,6 +258,10 @@ const flags: IFlags = { process.env.UNLEASH_EXPERIMENTAL_DISPLAY_EDGE_BANNER, false, ), + responseTimeMetricsFix: parseEnvVarBoolean( + process.env.UNLEASH_EXPERIMENTAL_RESPONSE_TIME_METRICS_FIX, + false, + ), }; export const defaultExperimentalOptions: IExperimentalOptions = { diff --git a/src/test/e2e/api/client/metrics.e2e.test.ts b/src/test/e2e/api/client/metrics.e2e.test.ts index e81b63797969..6efe5b5a67f3 100644 --- a/src/test/e2e/api/client/metrics.e2e.test.ts +++ b/src/test/e2e/api/client/metrics.e2e.test.ts @@ -1,14 +1,24 @@ -import { IUnleashTest, setupApp } from '../../helpers/test-helper'; +import { + IUnleashTest, + setupAppWithCustomConfig, +} from '../../helpers/test-helper'; import metricsExample from '../../../examples/client-metrics.json'; import dbInit, { ITestDb } from '../../helpers/database-init'; import getLogger from '../../../fixtures/no-logger'; +import { REQUEST_TIME } from '../../../../lib/metric-events'; let app: IUnleashTest; let db: ITestDb; beforeAll(async () => { db = await dbInit('metrics_api_client', getLogger); - app = await setupApp(db.stores); + app = await setupAppWithCustomConfig(db.stores, { + experimental: { + flags: { + responseTimeMetricsFix: true, + }, + }, + }); }); afterEach(async () => { @@ -64,3 +74,31 @@ test('should create instance if does not exist', async () => { const finalInstances = await db.stores.clientInstanceStore.getAll(); expect(finalInstances.length).toBe(1); }); + +test('should emit response time metrics data in the correct path', async () => { + const badMetrics = { + ...metricsExample, + bucket: { ...metricsExample.bucket, stop: null }, + }; + + let timeInfo = undefined; + app.config.eventBus.on(REQUEST_TIME, (data) => { + timeInfo = data; + }); + + await app.request.post('/api/client/metrics').send(badMetrics).expect(400); + + // wait in a loop of 10 milliseconds step while triggered is false + // or until 1000 milliseconds have passed + while (timeInfo === undefined) { + console.log('Waiting for event to be triggered'); + await new Promise((resolve) => setTimeout(resolve, 10)); + } + + expect(timeInfo).toMatchObject({ + method: 'POST', + statusCode: 400, + path: '/api/client/metrics', + }); + app.config.eventBus.removeAllListeners(); +}); diff --git a/src/test/e2e/helpers/test-helper.ts b/src/test/e2e/helpers/test-helper.ts index f56b5aa6f725..74a0c0299bec 100644 --- a/src/test/e2e/helpers/test-helper.ts +++ b/src/test/e2e/helpers/test-helper.ts @@ -1,6 +1,5 @@ import supertest from 'supertest'; -import EventEmitter from 'events'; import getApp from '../../../lib/app'; import { createTestConfig } from '../../config/test-config'; import { IAuthType, IUnleashConfig } from '../../../lib/types/option'; @@ -321,8 +320,6 @@ async function createApp( }); const services = createServices(stores, config, db); const unleashSession = sessionDb(config, undefined); - const emitter = new EventEmitter(); - emitter.setMaxListeners(0); const app = await getApp(config, stores, services, unleashSession, db); const request = supertest.agent(app);