1
0
mirror of https://github.com/Unleash/unleash.git synced 2025-05-31 01:16:01 +02:00

fix: path metric labels (#6400)

## About the changes
Some of our metrics are not labeled correctly, one example is
`<base-path>/api/frontend/client/metrics` is labeled as
`/client/metrics`. We can see that in internal-backstage/prometheus:

![image](https://github.com/Unleash/unleash/assets/455064/0d8f1f40-8b5b-49d4-8a88-70b523e9be09)

This issue affects all endpoints that fail to validate the request body.
Also, endpoints that are rejected by the authorization-middleware or the
api-token-middleware are reported as `(hidden)`.

To gain more insights on our api usage but being protective of metrics
cardinality we're prefixing `(hidden)` with some well known base urls:
https://github.com/Unleash/unleash/pull/6400/files#diff-1ed998ca46ffc97c9c0d5d400bfd982dbffdb3004b78a230a8a38e7644eee9b6R17-R33

## How to reproduce:
Make an invalid call to metrics (e.g. stop set to null), then check
/internal-backstage/prometheus and find the 400 error. Expected to be at
`path="/api/client/metrics"` but will have `path=""`:
```shell
curl -H"Authorization: *:development.unleash-insecure-client-api-token" -H'Content-type: application/json' localhost:4242/api/client/metrics -d '{
  "appName": "bash-test",
  "instanceId": "application-name-dacb1234",
  "environment": "development",
  "bucket": {
    "start": "2023-07-27T11:23:44Z",
    "stop": null,
    "toggles": {
      "myCoolToggle": {
        "yes": 25,
        "no": 42,
        "variants": {
          "blue": 6,
          "green": 15,
          "red": 46
        }
      },
      "myOtherToggle": {
        "yes": 0,
        "no": 100
      }
    }
  }
}'
```
This commit is contained in:
Gastón Fournier 2024-03-05 15:25:06 +01:00 committed by GitHub
parent a44c3a3fa7
commit e8e1d6e9f0
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
9 changed files with 503 additions and 18 deletions

View File

@ -132,6 +132,7 @@ exports[`should create default config 1`] = `
"personalAccessTokensKillSwitch": false,
"proPlanAutoCharge": false,
"queryMissingTokens": false,
"responseTimeMetricsFix": false,
"responseTimeWithAppNameKillSwitch": false,
"scimApi": false,
"sdkReporting": false,

View File

@ -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,
});
},
);
});

View File

@ -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<InstanceStatsService, 'getAppCountSnapshot'>,
): 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);
});
}

View File

@ -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;

View File

@ -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;
}
}

View File

@ -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';

View File

@ -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 = {

View File

@ -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();
});

View File

@ -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);