From 49fecb200570d8d7ecaac266fb0ec196f5e5c8e2 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Nuno=20G=C3=B3is?= Date: Wed, 31 Jul 2024 13:52:39 +0100 Subject: [PATCH] chore: request origin prom metrics (#7709) https://linear.app/unleash/issue/2-2501/adapt-origin-middleware-to-stop-logging-ui-requests-and-start This adapts the new origin middleware to stop logging UI requests (too noisy) and adds new Prometheus metrics. image This should allow us to better analyze this data. If we see a lot of API requests, we can dive into the logs for that instance and check the logged data, like the user agent. This PR adds some helper methods to make listening and emitting metric events more strict in terms of types. I think it's a positive change aligned with our scouting principle, but if you think it's complex and does not belong here I'm happy with dropping it. --- src/lib/metric-events.ts | 52 ++++++++++++++++++++ src/lib/metrics.ts | 16 ++++++ src/lib/middleware/origin-middleware.test.ts | 40 +++++++++++---- src/lib/middleware/origin-middleware.ts | 13 ++++- 4 files changed, 110 insertions(+), 11 deletions(-) diff --git a/src/lib/metric-events.ts b/src/lib/metric-events.ts index 413f47a06c..b6b4976b00 100644 --- a/src/lib/metric-events.ts +++ b/src/lib/metric-events.ts @@ -1,3 +1,5 @@ +import type EventEmitter from 'events'; + const REQUEST_TIME = 'request_time'; const DB_TIME = 'db_time'; const FUNCTION_TIME = 'function_time'; @@ -9,6 +11,51 @@ const PROXY_REPOSITORY_CREATED = 'proxy_repository_created'; const PROXY_FEATURES_FOR_TOKEN_TIME = 'proxy_features_for_token_time'; const STAGE_ENTERED = 'stage-entered' as const; const EXCEEDS_LIMIT = 'exceeds-limit' as const; +const REQUEST_ORIGIN = 'request_origin' as const; + +type MetricEvent = + | typeof REQUEST_TIME + | typeof DB_TIME + | typeof FUNCTION_TIME + | typeof SCHEDULER_JOB_TIME + | typeof FEATURES_CREATED_BY_PROCESSED + | typeof EVENTS_CREATED_BY_PROCESSED + | typeof FRONTEND_API_REPOSITORY_CREATED + | typeof PROXY_REPOSITORY_CREATED + | typeof PROXY_FEATURES_FOR_TOKEN_TIME + | typeof STAGE_ENTERED + | typeof EXCEEDS_LIMIT + | typeof REQUEST_ORIGIN; + +type RequestOriginEventPayload = { + type: 'UI' | 'API'; + method: Request['method']; +}; + +type MetricEventPayloads = { + [key: string]: unknown; + [REQUEST_ORIGIN]: RequestOriginEventPayload; +}; + +type MetricEventPayload = MetricEventPayloads[T]; + +type MetricEventListener = ( + payload: MetricEventPayload, +) => void; + +const emitMetricEvent = ( + eventBus: EventEmitter, + event: T, + payload: MetricEventPayload, +) => eventBus.emit(event, payload); + +const onMetricEvent = ( + eventBus: EventEmitter, + event: T, + listener: MetricEventListener, +) => { + eventBus.on(event, listener); +}; export { REQUEST_TIME, @@ -22,4 +69,9 @@ export { PROXY_FEATURES_FOR_TOKEN_TIME, STAGE_ENTERED, EXCEEDS_LIMIT, + REQUEST_ORIGIN, + type MetricEvent, + type MetricEventPayload, + emitMetricEvent, + onMetricEvent, }; diff --git a/src/lib/metrics.ts b/src/lib/metrics.ts index 9213783590..90ff60efa4 100644 --- a/src/lib/metrics.ts +++ b/src/lib/metrics.ts @@ -347,6 +347,12 @@ export default class MetricsMonitor { labelNames: ['resource', 'limit'], }); + const requestOriginCounter = createCounter({ + name: 'request_origin_counter', + help: 'Number of authenticated requests, including origin information.', + labelNames: ['type', 'method'], + }); + async function collectStaticCounters() { try { const stats = await instanceStatsService.getStats(); @@ -694,6 +700,16 @@ export default class MetricsMonitor { mapFeaturesForClientDuration.observe(duration); }); + events.onMetricEvent( + eventBus, + events.REQUEST_ORIGIN, + ({ type, method }) => { + if (flagResolver.isEnabled('originMiddleware')) { + requestOriginCounter.increment({ type, method }); + } + }, + ); + eventStore.on(FEATURE_CREATED, ({ featureName, project }) => { featureFlagUpdateTotal.increment({ toggle: featureName, diff --git a/src/lib/middleware/origin-middleware.test.ts b/src/lib/middleware/origin-middleware.test.ts index e0f940ee53..0adef86f32 100644 --- a/src/lib/middleware/origin-middleware.test.ts +++ b/src/lib/middleware/origin-middleware.test.ts @@ -2,6 +2,8 @@ import { originMiddleware } from './origin-middleware'; import type { IUnleashConfig } from '../types'; import { createTestConfig } from '../../test/config/test-config'; import type { Request, Response } from 'express'; +import { EventEmitter } from 'events'; +import { REQUEST_ORIGIN } from '../metric-events'; const TEST_UNLEASH_TOKEN = 'TEST_UNLEASH_TOKEN'; const TEST_USER_AGENT = 'TEST_USER_AGENT'; @@ -18,18 +20,23 @@ describe('originMiddleware', () => { fatal: jest.fn(), }; const getLogger = jest.fn(() => loggerMock); + const eventBus = new EventEmitter(); + eventBus.emit = jest.fn(); let config: IUnleashConfig; beforeEach(() => { - config = createTestConfig({ - getLogger, - experimental: { - flags: { - originMiddleware: true, + config = { + ...createTestConfig({ + getLogger, + experimental: { + flags: { + originMiddleware: true, + }, }, - }, - }); + }), + eventBus, + }; }); it('should call next', () => { @@ -40,12 +47,27 @@ describe('originMiddleware', () => { expect(next).toHaveBeenCalled(); }); - it('should log UI request', () => { + it('should emit UI request origin event', () => { const middleware = originMiddleware(config); middleware(req, res, next); - expect(loggerMock.info).toHaveBeenCalledWith('UI request', { + expect(eventBus.emit).toHaveBeenCalledWith(REQUEST_ORIGIN, { + type: 'UI', + method: req.method, + }); + }); + + it('should emit API request origin event', () => { + const middleware = originMiddleware(config); + + req.headers.authorization = TEST_UNLEASH_TOKEN; + req.headers['user-agent'] = TEST_USER_AGENT; + + middleware(req, res, next); + + expect(eventBus.emit).toHaveBeenCalledWith(REQUEST_ORIGIN, { + type: 'API', method: req.method, }); }); diff --git a/src/lib/middleware/origin-middleware.ts b/src/lib/middleware/origin-middleware.ts index 85bb8bb1c0..7a1b07a3aa 100644 --- a/src/lib/middleware/origin-middleware.ts +++ b/src/lib/middleware/origin-middleware.ts @@ -1,10 +1,12 @@ import type { Request, Response, NextFunction } from 'express'; import type { IUnleashConfig } from '../types'; +import { REQUEST_ORIGIN, emitMetricEvent } from '../metric-events'; export const originMiddleware = ({ getLogger, + eventBus, flagResolver, -}: Pick) => { +}: Pick) => { const logger = getLogger('/middleware/origin-middleware.ts'); logger.debug('Enabling origin middleware'); @@ -16,12 +18,19 @@ export const originMiddleware = ({ const isUI = !req.headers.authorization; if (isUI) { - logger.info('UI request', { method: req.method }); + emitMetricEvent(eventBus, REQUEST_ORIGIN, { + type: 'UI', + method: req.method, + }); } else { logger.info('API request', { method: req.method, userAgent: req.headers['user-agent'], }); + emitMetricEvent(eventBus, REQUEST_ORIGIN, { + type: 'API', + method: req.method, + }); } next();