From 07e2e84c270ff72cc847dd891e5f97f54e493749 Mon Sep 17 00:00:00 2001 From: pratik151192 Date: Wed, 13 Mar 2024 15:27:37 -0300 Subject: [PATCH] feat: add middleware for emitting GC events (#1181) * feat: add middleware for emitting GC events --- ...experimental-event-loop-perf-middleware.ts | 2 + ...erimental-garbage-collection-middleware.ts | 94 +++++++++++++++++++ .../experimental-middleware-factory.ts | 33 ++++++- packages/client-sdk-nodejs/src/index.ts | 1 + .../integration/cache-client-close.test.ts | 15 ++- 5 files changed, 138 insertions(+), 7 deletions(-) create mode 100644 packages/client-sdk-nodejs/src/config/middleware/experimental-garbage-collection-middleware.ts diff --git a/packages/client-sdk-nodejs/src/config/middleware/experimental-event-loop-perf-middleware.ts b/packages/client-sdk-nodejs/src/config/middleware/experimental-event-loop-perf-middleware.ts index 6d57adb16..beff65481 100644 --- a/packages/client-sdk-nodejs/src/config/middleware/experimental-event-loop-perf-middleware.ts +++ b/packages/client-sdk-nodejs/src/config/middleware/experimental-event-loop-perf-middleware.ts @@ -97,6 +97,8 @@ class ExperimentalEventLoopPerformanceMetricsMiddlewareRequestHandler * 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. + * + * See {@link StateMetrics} for each heuristic/metric and their description. */ export class ExperimentalEventLoopPerformanceMetricsMiddleware implements Middleware diff --git a/packages/client-sdk-nodejs/src/config/middleware/experimental-garbage-collection-middleware.ts b/packages/client-sdk-nodejs/src/config/middleware/experimental-garbage-collection-middleware.ts new file mode 100644 index 000000000..3d4e2955d --- /dev/null +++ b/packages/client-sdk-nodejs/src/config/middleware/experimental-garbage-collection-middleware.ts @@ -0,0 +1,94 @@ +import { + Middleware, + MiddlewareMessage, + MiddlewareMetadata, + MiddlewareRequestHandler, + MiddlewareStatus, +} from './middleware'; +import {constants, PerformanceObserver} from 'perf_hooks'; +import {MomentoLogger, MomentoLoggerFactory} from '@gomomento/sdk-core'; + +class ExperimentalGarbageCollectionPerformanceMetricsMiddlewareRequestHandler + implements MiddlewareRequestHandler +{ + onRequestBody(request: MiddlewareMessage): Promise { + return Promise.resolve(request); + } + + onRequestMetadata(metadata: MiddlewareMetadata): Promise { + return Promise.resolve(metadata); + } + + onResponseMetadata( + metadata: MiddlewareMetadata + ): Promise { + return Promise.resolve(metadata); + } + + onResponseBody( + response: MiddlewareMessage | null + ): Promise { + return Promise.resolve(response); + } + + onResponseStatus(status: MiddlewareStatus): Promise { + return Promise.resolve(status); + } +} + +/** + * This middleware enables garbage collection metrics. It subscribers to a GC performance observer provided by + * node's built-in performance hooks, and logs key GC events. A sample log looks like: + * + * { + * "entryType": "gc", + * "startTime": 8221.879917, + * "duration": 2.8905000016093254, <-- most important field to analyze for stop the world events, measured in milliseconds. + * "detail": { + * "kind": 4, <-- constant for NODE_PERFORMANCE_GC_MAJOR. `MAJOR` events might point to GC events causing long delays. + * "flags": 32 + * }, + * "timestamp": 1710300309368 + * } + */ +export class ExperimentalGarbageCollectionPerformanceMetricsMiddleware + implements Middleware +{ + private readonly logger: MomentoLogger; + private readonly gcObserver: PerformanceObserver; + + constructor(loggerFactory: MomentoLoggerFactory) { + this.logger = loggerFactory.getLogger(this); + + this.gcObserver = new PerformanceObserver(items => { + items + .getEntries() + .filter( + // NODE_PERFORMANCE_GC_MAJOR indicates a major GC event such as STW (stop-the-world) pauses + // and other long delays. This filter is to control the volume of GC logs if we were to enable + // this on a customer's client. + item => item.kind === constants.NODE_PERFORMANCE_GC_MAJOR + ) + .forEach(item => { + const gcEventObject = { + entryType: item.entryType, + startTime: item.startTime, + duration: item.duration, + kind: item.kind, + flags: item.flags, + timestamp: Date.now(), + }; + this.logger.info(JSON.stringify(gcEventObject)); + }); + }); + this.gcObserver.observe({entryTypes: ['gc']}); + } + + onNewRequest(): MiddlewareRequestHandler { + return new ExperimentalGarbageCollectionPerformanceMetricsMiddlewareRequestHandler(); + } + + close() { + this.gcObserver.disconnect(); + } +} diff --git a/packages/client-sdk-nodejs/src/config/middleware/experimental-middleware-factory.ts b/packages/client-sdk-nodejs/src/config/middleware/experimental-middleware-factory.ts index b826ec7cb..7c2562966 100644 --- a/packages/client-sdk-nodejs/src/config/middleware/experimental-middleware-factory.ts +++ b/packages/client-sdk-nodejs/src/config/middleware/experimental-middleware-factory.ts @@ -5,11 +5,32 @@ import {ExperimentalMetricsLoggingMiddleware} from './experimental-metrics-loggi import {ExperimentalActiveRequestCountLoggingMiddleware} from './experimental-active-request-count-middleware'; import {Middleware} from './middleware'; import {ExperimentalMetricsCsvMiddleware} from './experimental-metrics-csv-middleware'; +import {ExperimentalGarbageCollectionPerformanceMetricsMiddleware} from './experimental-garbage-collection-middleware'; -interface ExperimenalMetricsMiddlewareOptions { +interface ExperimentalMetricsMiddlewareOptions { + /** + * Setting this to true will emit a periodic JSON log for the event loop profile of the nodeJS process. + */ eventLoopMetricsLog?: boolean; + /** + * Setting this to true will emit a JSON log during major GC events, as observed by node's perf_hooks. + */ + garbageCollectionMetricsLog?: boolean; + /** + * Setting this to true will emit a JSON log for each Momento request, that includes the client-side latency + * among other request profile statistics. + */ perRequestMetricsLog?: boolean; + /** + * Setting this to true will emit a periodic JSON log for active Momento request count on the nodeJS process + * as observed when the periodic task wakes up. This can be handy with eventLoopMetricsLog to observe the event loop + * delay against the maximum number of concurrent connections the application is observing. + */ activeRequestCountMetricsLog?: boolean; + /** + * Setting this to true will write a CSV recrd for each Momento request, that includes the client-side latency + * among other request profile statistics. The path is the file path on your disk where the CSV file is stored. + */ perRequestMetricsCSVPath?: string; } @@ -17,7 +38,7 @@ interface ExperimenalMetricsMiddlewareOptions { export class MiddlewareFactory { public static createMetricsMiddlewares( loggerFactory: MomentoLoggerFactory, - options: ExperimenalMetricsMiddlewareOptions + options: ExperimentalMetricsMiddlewareOptions ): Middleware[] { const middlewares: Middleware[] = []; @@ -43,6 +64,14 @@ export class MiddlewareFactory { ); } + if (options.garbageCollectionMetricsLog === true) { + middlewares.push( + new ExperimentalGarbageCollectionPerformanceMetricsMiddleware( + loggerFactory + ) + ); + } + return middlewares; } } diff --git a/packages/client-sdk-nodejs/src/index.ts b/packages/client-sdk-nodejs/src/index.ts index d04f0a2f5..8cd9f6553 100644 --- a/packages/client-sdk-nodejs/src/index.ts +++ b/packages/client-sdk-nodejs/src/index.ts @@ -228,6 +228,7 @@ export {ExperimentalMetricsCsvMiddleware} from './config/middleware/experimental export {ExperimentalMetricsLoggingMiddleware} from './config/middleware/experimental-metrics-logging-middleware'; export {ExperimentalActiveRequestCountLoggingMiddleware} from './config/middleware/experimental-active-request-count-middleware'; export {ExperimentalEventLoopPerformanceMetricsMiddleware} from './config/middleware/experimental-event-loop-perf-middleware'; +export {ExperimentalGarbageCollectionPerformanceMetricsMiddleware} from './config/middleware/experimental-garbage-collection-middleware'; export {ExampleAsyncMiddleware} from './config/middleware/example-async-middleware'; export {MiddlewareFactory} from './config/middleware/experimental-middleware-factory'; diff --git a/packages/client-sdk-nodejs/test/integration/cache-client-close.test.ts b/packages/client-sdk-nodejs/test/integration/cache-client-close.test.ts index 84d1b3981..a42d945e4 100644 --- a/packages/client-sdk-nodejs/test/integration/cache-client-close.test.ts +++ b/packages/client-sdk-nodejs/test/integration/cache-client-close.test.ts @@ -9,11 +9,15 @@ import { } from '../../src'; describe("Test exercises closing a client and jest doesn't hang", () => { - it('constructs a client with background task and closes it', () => { - const client = new CacheClient( - integrationTestCacheClientPropsWithExperimentalMetricsMiddleware() - ); - client.close(); + it('constructs a client with background task and closes it', async () => { + let client; + try { + client = await CacheClient.create( + integrationTestCacheClientPropsWithExperimentalMetricsMiddleware() + ); + } finally { + if (client) client.close(); + } }); }); @@ -27,6 +31,7 @@ function integrationTestCacheClientPropsWithExperimentalMetricsMiddleware(): Cac .withMiddlewares( MiddlewareFactory.createMetricsMiddlewares(loggerFactory, { eventLoopMetricsLog: true, + garbageCollectionMetricsLog: true, activeRequestCountMetricsLog: true, }) ),