Skip to content

Commit

Permalink
chore: decouple event loop metrics into its own middleware (#1171)
Browse files Browse the repository at this point in the history
This PR separates out event loop metrics to its own middleware. It also adds a factory method for clients to be able to call to toggle multiple metrics middleware.
  • Loading branch information
pratik151192 authored Mar 12, 2024
1 parent 3830326 commit 3288e19
Show file tree
Hide file tree
Showing 8 changed files with 326 additions and 175 deletions.
Original file line number Diff line number Diff line change
@@ -0,0 +1,78 @@
import {MomentoLogger, MomentoLoggerFactory} from '../../';
import {MiddlewareRequestHandlerContext} from './middleware';
import {
ExperimentalMetricsMiddleware,
ExperimentalMetricsMiddlewareRequestHandler,
ExperimentalRequestMetrics,
} from './impl/experimental-metrics-middleware';

class ExperimentalActiveRequestCountLoggingMiddlewareRequestHandler extends ExperimentalMetricsMiddlewareRequestHandler {
constructor(
parent: ExperimentalMetricsMiddleware,
logger: MomentoLogger,
context: MiddlewareRequestHandlerContext
) {
super(parent, logger, context);
}

protected recordMetrics(): void {
this.parent.decrementActiveRequestCount();
}

// eslint-disable-next-line @typescript-eslint/no-unused-vars
emitMetrics(metrics: ExperimentalRequestMetrics): Promise<void> {
return Promise.resolve();
}
}

/**
* This middleware enables a periodic task to emit the active request count every second as a JSON
*
* See `advanced.ts` in the examples directory for an example of how to set up
* your {Configuration} to enable this middleware.
*/
export class ExperimentalActiveRequestCountLoggingMiddleware extends ExperimentalMetricsMiddleware {
private isLoggingStarted = false;
private readonly metricsLogInterval = 1000;
// this is typed as any because JS returns a number for intervalId but
// TS returns a NodeJS.Timeout.
// eslint-disable-next-line @typescript-eslint/no-explicit-any
private intervalId: any | null = null; // Store the interval ID

constructor(loggerFactory: MomentoLoggerFactory) {
super(
loggerFactory,
(p, l, c) =>
new ExperimentalActiveRequestCountLoggingMiddlewareRequestHandler(
p,
l,
c
)
);
if (!this.isLoggingStarted) {
this.isLoggingStarted = true;
this.startLogging();
}
}

private startLogging(): void {
this.intervalId = setInterval(() => {
const metrics = {
activeRequestCount: this.activeRequestCount(),
timestamp: Date.now(),
};
this.logger.info(JSON.stringify(metrics));
}, this.metricsLogInterval);
}

close() {
if (this.intervalId !== null) {
this.logger.debug('Stopping active request count metrics logging.');
// eslint-disable-next-line @typescript-eslint/no-unsafe-argument
clearInterval(this.intervalId);
this.intervalId = null;
this.isLoggingStarted = false;
this.logger.debug('Active request count metrics logging stopped.');
}
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,163 @@
import {
Middleware,
MiddlewareMessage,
MiddlewareMetadata,
MiddlewareRequestHandler,
MiddlewareStatus,
} from './middleware';
import {
EventLoopDelayMonitor,
EventLoopUtilization,
monitorEventLoopDelay,
performance,
} from 'perf_hooks';
import {MomentoLogger, MomentoLoggerFactory} from '@gomomento/sdk-core';

interface StateMetrics {
/**
* The proportion of time the event loop was busy over the last second.
*/
eventLoopUtilization: number;

/**
* The average event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayMean: number;

/**
* The minimum event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayMin: number;

/**
* The 50th percentile event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayP50: number;

/**
* The 75th percentile event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayP75: number;

/**
* The 90th percentile event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayP90: number;

/**
* The 95th percentile event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayP95: number;

/**
* The 99th percentile event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayP99: number;

/**
* The maximum event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayMax: number;

/**
* The timestamp when the state metrics got recorded
*/
timestamp: number;
}

class ExperimentalEventLoopPerformanceMetricsMiddlewareRequestHandler
implements MiddlewareRequestHandler
{
onRequestBody(request: MiddlewareMessage): Promise<MiddlewareMessage> {
return Promise.resolve(request);
}

onRequestMetadata(metadata: MiddlewareMetadata): Promise<MiddlewareMetadata> {
return Promise.resolve(metadata);
}

onResponseMetadata(
metadata: MiddlewareMetadata
): Promise<MiddlewareMetadata> {
return Promise.resolve(metadata);
}

onResponseBody(
response: MiddlewareMessage | null
): Promise<MiddlewareMessage | null> {
return Promise.resolve(response);
}

onResponseStatus(status: MiddlewareStatus): Promise<MiddlewareStatus> {
return Promise.resolve(status);
}
}

/**
* This middleware enables event-loop performance metrics.It runs a periodic task specified by metricsLogInterval
* to gather various event-loop metrics that can be correlated with the overall application's performance. This is
* particularly helpful to analyze and correlate resource contention with higher network latencies.
*/
export class ExperimentalEventLoopPerformanceMetricsMiddleware
implements Middleware
{
private readonly metricsLogInterval = 1000;
private readonly eventLoopDelayInterval = 20;
private eldMonitor: EventLoopDelayMonitor;
private elu: EventLoopUtilization;
private isLoggingStarted = false;
// this is typed as any because JS returns a number for intervalId but
// TS returns a NodeJS.Timeout.
// eslint-disable-next-line @typescript-eslint/no-explicit-any
private intervalId: any | null = null; // Store the interval ID
private readonly logger: MomentoLogger;

constructor(loggerFactory: MomentoLoggerFactory) {
this.logger = loggerFactory.getLogger(this);
if (!this.isLoggingStarted) {
this.isLoggingStarted = true;
this.startLogging();
}
}

private startLogging(): void {
this.eldMonitor = monitorEventLoopDelay({
resolution: this.eventLoopDelayInterval,
});
this.eldMonitor.enable();
this.elu = performance.eventLoopUtilization();

this.intervalId = setInterval(() => {
this.elu = performance.eventLoopUtilization(this.elu);
const metrics: StateMetrics = {
eventLoopUtilization: this.elu.utilization,
eventLoopDelayMean: this.eldMonitor.mean,
eventLoopDelayMin: this.eldMonitor.min,
eventLoopDelayP50: this.eldMonitor.percentile(50),
eventLoopDelayP75: this.eldMonitor.percentile(75),
eventLoopDelayP90: this.eldMonitor.percentile(90),
eventLoopDelayP95: this.eldMonitor.percentile(95),
eventLoopDelayP99: this.eldMonitor.percentile(99),
eventLoopDelayMax: this.eldMonitor.max,
timestamp: Date.now(),
};
this.logger.info(JSON.stringify(metrics));
this.eldMonitor.reset();
}, this.metricsLogInterval);
}

onNewRequest(): MiddlewareRequestHandler {
return new ExperimentalEventLoopPerformanceMetricsMiddlewareRequestHandler();
}

close() {
if (this.intervalId !== null) {
this.logger.debug('Stopping event loop metrics logging.');
// eslint-disable-next-line @typescript-eslint/no-unsafe-argument
clearInterval(this.intervalId);
this.intervalId = null;
this.isLoggingStarted = false;
this.logger.debug('Event loop metrics logging stopped.');
}
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -5,59 +5,6 @@ import {
ExperimentalRequestMetrics,
} from './impl/experimental-metrics-middleware';
import {MiddlewareRequestHandlerContext} from './middleware';
import {
EventLoopDelayMonitor,
EventLoopUtilization,
monitorEventLoopDelay,
performance,
} from 'perf_hooks';

interface StateMetrics {
/**
* The proportion of time the event loop was busy over the last second.
*/
eventLoopUtilization: number;

/**
* The average event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayMean: number;

/**
* The minimum event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayMin: number;

/**
* The 50th percentile event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayP50: number;

/**
* The 75th percentile event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayP75: number;

/**
* The 90th percentile event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayP90: number;

/**
* The 95th percentile event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayP95: number;

/**
* The 99th percentile event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayP99: number;

/**
* The maximum event loop delay over the last second, measured in 20ms increments.
*/
eventLoopDelayMax: number;
}

class ExperimentalMetricsLoggingMiddlewareRequestHandler extends ExperimentalMetricsMiddlewareRequestHandler {
constructor(
Expand Down Expand Up @@ -99,60 +46,11 @@ class ExperimentalMetricsLoggingMiddlewareRequestHandler extends ExperimentalMet
* your {Configuration} to enable this middleware.
*/
export class ExperimentalMetricsLoggingMiddleware extends ExperimentalMetricsMiddleware {
private static readonly metricsLogInterval = 1000;
private static readonly eventLoopDelayInterval = 20;
private static eldMonitor: EventLoopDelayMonitor;
private static elu: EventLoopUtilization;
private static isLoggingStarted = false;
static numActiveRequests = 0;
// eslint-disable-next-line @typescript-eslint/no-explicit-any
private static intervalId: any | null = null; // Store the interval ID

constructor(loggerFactory: MomentoLoggerFactory) {
super(
loggerFactory,
(p, l, c) =>
new ExperimentalMetricsLoggingMiddlewareRequestHandler(p, l, c)
);
if (!ExperimentalMetricsLoggingMiddleware.isLoggingStarted) {
ExperimentalMetricsLoggingMiddleware.isLoggingStarted = true;
ExperimentalMetricsLoggingMiddleware.startLogging(this.logger);
}
}

private static startLogging(logger: MomentoLogger): void {
this.eldMonitor = monitorEventLoopDelay({
resolution: this.eventLoopDelayInterval,
});
this.eldMonitor.enable();
this.elu = performance.eventLoopUtilization();

this.intervalId = setInterval(() => {
this.elu = performance.eventLoopUtilization(this.elu);
const metrics: StateMetrics = {
eventLoopUtilization: this.elu.utilization,
eventLoopDelayMean: this.eldMonitor.mean,
eventLoopDelayMin: this.eldMonitor.min,
eventLoopDelayP50: this.eldMonitor.percentile(50),
eventLoopDelayP75: this.eldMonitor.percentile(75),
eventLoopDelayP90: this.eldMonitor.percentile(90),
eventLoopDelayP95: this.eldMonitor.percentile(95),
eventLoopDelayP99: this.eldMonitor.percentile(99),
eventLoopDelayMax: this.eldMonitor.max,
};
logger.info(JSON.stringify(metrics));
this.eldMonitor.reset();
}, this.metricsLogInterval);
}

close() {
if (ExperimentalMetricsLoggingMiddleware.intervalId) {
this.logger.debug('Stopping Metrics logging.');
// eslint-disable-next-line @typescript-eslint/no-unsafe-argument
clearInterval(ExperimentalMetricsLoggingMiddleware.intervalId);
ExperimentalMetricsLoggingMiddleware.intervalId = null;
ExperimentalMetricsLoggingMiddleware.isLoggingStarted = false;
this.logger.debug('Metrics logging stopped.');
}
}
}
Loading

0 comments on commit 3288e19

Please sign in to comment.