feat: add middleware for emitting GC events (#1181)

* feat: add middleware for emitting GC events

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

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

packages/client-sdk-nodejs/src/config/middleware/experimental-middleware-factory.ts

@@ -5,19 +5,40 @@ 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;
 }
 
 // Static class encapsulating the factory functionality
 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;
   }
 }

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

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