chore: improve prometheus metrics

apps/meteor/app/api/server/api.ts

@@ -102,11 +102,21 @@ settings.watch<number>('API_Enable_Rate_Limiter_Limit_Calls_Default', (value) =>
 export const startRestAPI = () => {
 	(WebApp.rawConnectHandlers as unknown as ReturnType<typeof express>).use(
 		API.api
+			.use(
+				metricsMiddleware({
+					basePathRegex: new RegExp(/^\/api\/v1\//),
+					api: API.v1,
+					settings,
+					endpointTimeSummary: metrics.rocketchatRestApi,
+					endpointTimeHistogram: metrics.rocketchatRestApiSeconds,
+					responseSizeHistogram: metrics.rocketchatRestApiResponseSizeBytes,
+					activeRequestsGauge: metrics.rocketchatRestApiActiveRequests,
+				}),
+			)
+			.use(tracerSpanMiddleware)
 			.use(remoteAddressMiddleware)
 			.use(cors(settings))
 			.use(loggerMiddleware(logger))
-			.use(metricsMiddleware({ basePathRegex: new RegExp(/^\/api\/v1\//), api: API.v1, settings, summary: metrics.rocketchatRestApi }))
-			.use(tracerSpanMiddleware)
 			.use(API.v1.router)
 			.use(API.default.router).router,
 	);

apps/meteor/app/api/server/middlewares/metrics.spec.ts

@@ -25,27 +25,42 @@ describe('Metrics middleware', () => {
 		const mockEndTimer = jest.fn();
 		summary.startTimer.mockReturnValue(mockEndTimer);
 
-		api.use(metricsMiddleware({ api: { version: 1 } as any, settings, summary: summary as any })).get(
-			'/test',
-			{
-				response: {
-					200: ajv.compile({
-						type: 'object',
-						properties: {
-							message: { type: 'string' },
+		const histogram = { startTimer: jest.fn().mockReturnValue(jest.fn()) };
+		const responseSizeHistogram = { observe: jest.fn() };
+		const activeRequestsGauge = { inc: jest.fn(), dec: jest.fn() };
+
+		api
+			.use(
+				metricsMiddleware({
+					api: { version: 1 } as any,
+					settings,
+					endpointTimeSummary: summary as any,
+					endpointTimeHistogram: histogram as any,
+					responseSizeHistogram: responseSizeHistogram as any,
+					activeRequestsGauge: activeRequestsGauge as any,
+				}),
+			)
+			.get(
+				'/test',
+				{
+					response: {
+						200: ajv.compile({
+							type: 'object',
+							properties: {
+								message: { type: 'string' },
+							},
+						}),
+					},
+				},
+				async () => {
+					return {
+						statusCode: 200,
+						body: {
+							message: 'Metrics test successful',
 						},
-					}),
+					};
 				},
-			},
-			async () => {
-				return {
-					statusCode: 200,
-					body: {
-						message: 'Metrics test successful',
-					},
-				};
-			},
-		);
+			);
 		app.use(api.router);
 		const response = await request(app).get('/api/test').set('user-agent', 'test');
 		expect(response.statusCode).toBe(200);
@@ -73,8 +88,22 @@ describe('Metrics middleware', () => {
 		const mockEndTimer = jest.fn();
 		summary.startTimer.mockReturnValue(mockEndTimer);
 
+		const histogram = { startTimer: jest.fn().mockReturnValue(jest.fn()) };
+		const responseSizeHistogram = { observe: jest.fn() };
+		const activeRequestsGauge = { inc: jest.fn(), dec: jest.fn() };
+
 		api
-			.use(metricsMiddleware({ basePathRegex: new RegExp(/^\/api\//), api: { version: 1 } as any, settings, summary: summary as any }))
+			.use(
+				metricsMiddleware({
+					basePathRegex: new RegExp(/^\/api\//),
+					api: { version: 1 } as any,
+					settings,
+					endpointTimeSummary: summary as any,
+					endpointTimeHistogram: histogram as any,
+					responseSizeHistogram: responseSizeHistogram as any,
+					activeRequestsGauge: activeRequestsGauge as any,
+				}),
+			)
 			.get(
 				'/test',
 				{
@@ -120,8 +149,22 @@ describe('Metrics middleware', () => {
 		const mockEndTimer = jest.fn();
 		summary.startTimer.mockReturnValue(mockEndTimer);
 
+		const histogram = { startTimer: jest.fn().mockReturnValue(jest.fn()) };
+		const responseSizeHistogram = { observe: jest.fn() };
+		const activeRequestsGauge = { inc: jest.fn(), dec: jest.fn() };
+
 		api
-			.use(metricsMiddleware({ basePathRegex: new RegExp(/^\/api\//), api: { version: 1 } as any, settings, summary: summary as any }))
+			.use(
+				metricsMiddleware({
+					basePathRegex: new RegExp(/^\/api\//),
+					api: { version: 1 } as any,
+					settings,
+					endpointTimeSummary: summary as any,
+					endpointTimeHistogram: histogram as any,
+					responseSizeHistogram: responseSizeHistogram as any,
+					activeRequestsGauge: activeRequestsGauge as any,
+				}),
+			)
 			.get(
 				'/method.call/:id',
 				{

apps/meteor/app/api/server/middlewares/metrics.ts

@@ -1,5 +1,5 @@
 import type { MiddlewareHandler } from 'hono';
-import type { Summary } from 'prom-client';
+import type { Gauge, Histogram, Summary } from 'prom-client';
 
 import type { CachedSettings } from '../../../settings/server/CachedSettings';
 import type { APIClass } from '../ApiClass';
@@ -9,28 +9,51 @@ export const metricsMiddleware =
 		basePathRegex,
 		api,
 		settings,
-		summary,
+		endpointTimeSummary,
+		endpointTimeHistogram,
+		responseSizeHistogram,
+		activeRequestsGauge,
 	}: {
 		basePathRegex?: RegExp;
 		api: APIClass;
 		settings: CachedSettings;
-		summary: Summary;
+		endpointTimeSummary: Summary;
+		endpointTimeHistogram: Histogram;
+		responseSizeHistogram: Histogram;
+		activeRequestsGauge: Gauge;
 	}): MiddlewareHandler =>
 	async (c, next) => {
-		const rocketchatRestApiEnd = summary.startTimer();
+		const rocketchatRestApiEnd = endpointTimeSummary.startTimer();
+		const rocketchatRestApiHistEnd = endpointTimeHistogram.startTimer();
+
+		const methodLabel = { method: c.req.method.toLowerCase() };
+		activeRequestsGauge.inc(methodLabel);
 
 		await next();
 
+		activeRequestsGauge.dec(methodLabel);
+
 		const { method, path, routePath } = c.req;
 
 		// get rid of the base path (i.e.: /api/v1/)
 		const entrypoint = basePathRegex ? routePath.replace(basePathRegex, '') : routePath;
 
-		rocketchatRestApiEnd({
+		const histogramLabels = {
 			status: c.res.status,
 			method: method.toLowerCase(),
 			version: api.version,
-			...(settings.get('Prometheus_API_User_Agent') && { user_agent: c.req.header('user-agent') }),
 			entrypoint: basePathRegex && entrypoint.startsWith('method.call') ? decodeURIComponent(path.replace(basePathRegex, '')) : entrypoint,
+		};
+
+		rocketchatRestApiEnd({
+			...histogramLabels,
+			...(settings.get('Prometheus_API_User_Agent') && { user_agent: c.req.header('user-agent') }),
 		});
+
+		rocketchatRestApiHistEnd(histogramLabels);
+
+		const contentLength = parseInt(c.res.headers.get('content-length') || '0', 10);
+		if (contentLength > 0) {
+			responseSizeHistogram.observe(histogramLabels, contentLength);
+		}
 	};

apps/meteor/app/integrations/server/api/api.ts

@@ -427,9 +427,19 @@ const Api = new WebHookAPI({
 });
 
 Api.router
-	.use(loggerMiddleware(integrationLogger))
-	.use(metricsMiddleware({ basePathRegex: new RegExp(/^\/hooks\//), api: Api, settings, summary: metrics.rocketchatRestApi }))
-	.use(tracerSpanMiddleware);
+	.use(
+		metricsMiddleware({
+			basePathRegex: new RegExp(/^\/hooks\//),
+			api: Api,
+			settings,
+			endpointTimeSummary: metrics.rocketchatRestApi,
+			endpointTimeHistogram: metrics.rocketchatRestApiSeconds,
+			responseSizeHistogram: metrics.rocketchatRestApiResponseSizeBytes,
+			activeRequestsGauge: metrics.rocketchatRestApiActiveRequests,
+		}),
+	)
+	.use(tracerSpanMiddleware)
+	.use(loggerMiddleware(integrationLogger));
 
 Api.addRoute(
 	':integrationId/:userId/:token',

apps/meteor/app/lib/server/functions/notifications/desktop.ts

@@ -67,6 +67,7 @@ export async function notifyDesktopUser({
 	};
 
 	metrics.notificationsSent.inc({ notification_type: 'desktop' });
+	metrics.notificationsSentTotal.inc({ notification_type: 'desktop' });
 
 	void api.broadcast('notify.desktop', userId, payload);
 }

apps/meteor/app/lib/server/functions/notifications/email.js

@@ -178,13 +178,14 @@ export async function getEmailData({ message, receiver, sender, subscription, ro
 		)}${message.tmid || message._id}@${replyto.split('@')[1]}`;
 	}
 
-	metrics.notificationsSent.inc({ notification_type: 'email' });
 	return email;
 }
 
 export function sendEmailFromData(data) {
-	metrics.notificationsSent.inc({ notification_type: 'email' });
-	return Mailer.send(data);
+	return Mailer.send(data).then(() => {
+		metrics.notificationsSent.inc({ notification_type: 'email' });
+		metrics.notificationsSentTotal.inc({ notification_type: 'email' });
+	});
 }
 
 export function shouldNotifyEmail({

apps/meteor/app/lib/server/lib/debug.js

@@ -57,11 +57,14 @@ const wrapMethods = function (name, originalHandler, methodsMap) {
 
 		const method = name === 'stream' ? `${name}:${originalArgs[0]}` : name;
 
-		const end = metrics.meteorMethods.startTimer({
+		const meteorMethodLabels = {
 			method,
 			has_connection: this.connection != null,
 			has_user: this.userId != null,
-		});
+		};
+
+		const end = metrics.meteorMethods.startTimer(meteorMethodLabels);
+		const endHistogram = metrics.meteorMethodsSeconds.startTimer(meteorMethodLabels);
 
 		logger.method({
 			method,
@@ -84,6 +87,7 @@ const wrapMethods = function (name, originalHandler, methodsMap) {
 			async () => {
 				const result = await originalHandler.apply(this, originalArgs);
 				end();
+				endHistogram();
 				return result;
 			},
 		);
@@ -115,10 +119,12 @@ Meteor.publish = function (name, func) {
 		});
 
 		const end = metrics.meteorSubscriptions.startTimer({ subscription: name });
+		const endHistogram = metrics.meteorSubscriptionsSeconds.startTimer({ subscription: name });
 
 		const originalReady = this.ready;
 		this.ready = function () {
 			end();
+			endHistogram();
 			return originalReady.apply(this, args);
 		};
 

apps/meteor/app/lib/server/lib/deprecationWarningLogger.ts

@@ -40,6 +40,7 @@ export const apiDeprecationLogger = ((logger) => {
 			writeDeprecationHeader(res, 'endpoint-deprecation', message, version);
 
 			metrics.deprecations.inc({ type: 'deprecation', kind: 'endpoint', name: endpoint });
+			metrics.deprecationsTotal.inc({ type: 'deprecation', kind: 'endpoint', name: endpoint });
 
 			logger.warn({ msg: message, endpoint, version, info });
 		},
@@ -63,6 +64,7 @@ export const apiDeprecationLogger = ((logger) => {
 			}
 
 			metrics.deprecations.inc({ type: 'parameter-deprecation', kind: 'endpoint', name: endpoint, params: parameter });
+			metrics.deprecationsTotal.inc({ type: 'parameter-deprecation', kind: 'endpoint', name: endpoint, params: parameter });
 
 			writeDeprecationHeader(res, 'parameter-deprecation', message, version);
 
@@ -92,6 +94,7 @@ export const apiDeprecationLogger = ((logger) => {
 			compareVersions(version, message);
 
 			metrics.deprecations.inc({ type: 'invalid-usage', kind: 'endpoint', name: endpoint, params: parameter });
+			metrics.deprecationsTotal.inc({ type: 'invalid-usage', kind: 'endpoint', name: endpoint, params: parameter });
 
 			writeDeprecationHeader(res, 'invalid-usage', message, version);
 
@@ -116,6 +119,7 @@ export const methodDeprecationLogger = ((logger) => {
 			}
 			compareVersions(version, message);
 			metrics.deprecations.inc({ type: 'deprecation', name: method, kind: 'method' });
+			metrics.deprecationsTotal.inc({ type: 'deprecation', name: method, kind: 'method' });
 			logger.warn({ msg: message, method, version, replacement });
 		},
 		parameter: (method: string, parameter: string, version: DeprecationLoggerNextPlannedVersion) => {
@@ -125,6 +129,7 @@ export const methodDeprecationLogger = ((logger) => {
 			}
 
 			metrics.deprecations.inc({ type: 'parameter-deprecation', name: method, params: parameter });
+			metrics.deprecationsTotal.inc({ type: 'parameter-deprecation', name: method, params: parameter });
 
 			compareVersions(version, message);
 			logger.warn({ msg: message, method, parameter, version });
@@ -151,6 +156,7 @@ export const methodDeprecationLogger = ((logger) => {
 			compareVersions(version, message);
 
 			metrics.deprecations.inc({ type: 'invalid-usage', name: method, params: parameter, kind: 'method' });
+			metrics.deprecationsTotal.inc({ type: 'invalid-usage', name: method, params: parameter, kind: 'method' });
 
 			logger.warn({ msg: message, method, parameter, version });
 		},

apps/meteor/app/lib/server/lib/processDirectEmail.ts

@@ -109,8 +109,6 @@ export const processDirectEmail = async function (email: ParsedMail): Promise<vo
 		}
 	}
 
-	metrics.messagesSent.inc(); // TODO This line needs to be moved to it's proper place. See the comments on: https://github.com/RocketChat/Rocket.Chat/pull/5736
-
 	const message: Pick<IMessage, 'ts' | 'msg' | 'groupable' | 'rid' | 'sentByEmail' | 'tmid'> = {
 		ts: tsDiff < 10000 ? ts : new Date(),
 		msg,
@@ -120,5 +118,10 @@ export const processDirectEmail = async function (email: ParsedMail): Promise<vo
 		rid: prevMessage.rid,
 	};
 
-	return sendMessage(user, message, roomInfo);
+	const result = await sendMessage(user, message, roomInfo);
+
+	metrics.messagesSent.inc();
+	metrics.messagesSentTotal.inc();
+
+	return result;
 };

apps/meteor/app/lib/server/methods/sendMessage.ts

@@ -105,8 +105,12 @@ export async function executeSendMessage(
 			}
 		}
 
-		metrics.messagesSent.inc(); // TODO This line needs to be moved to it's proper place. See the comments on: https://github.com/RocketChat/Rocket.Chat/pull/5736
-		return await sendMessage(user, message, room, { previewUrls: extraInfo?.previewUrls });
+		const result = await sendMessage(user, message, room, { previewUrls: extraInfo?.previewUrls });
+
+		metrics.messagesSent.inc();
+		metrics.messagesSentTotal.inc();
+
+		return result;
 	} catch (err: any) {
 		SystemLogger.error({ msg: 'Error sending message:', err });
 

apps/meteor/app/lib/server/startup/rateLimiter.js

@@ -126,14 +126,16 @@ const ruleIds = {};
 const callback = (msg, name) => async (reply, input) => {
 	if (reply.allowed === false) {
 		rateLimiterLog({ msg, reply, input });
-		metrics.ddpRateLimitExceeded.inc({
+		const rateLimitLabels = {
 			limit_name: name,
 			user_id: input.userId,
 			client_address: input.clientAddress,
 			type: input.type,
 			name: input.name,
 			connection_id: input.connectionId,
-		});
+		};
+		metrics.ddpRateLimitExceeded.inc(rateLimitLabels);
+		metrics.ddpRateLimitExceededTotal.inc(rateLimitLabels);
 		// sleep before sending the error to slow down next requests
 		if (slowDownRate > 0 && reply.numInvocationsExceeded) {
 			await sleep(slowDownRate * reply.numInvocationsExceeded);