feat: add checked socket exhaustion warning when throughput is slow

Author: kuhe

.changeset/strong-taxis-obey.md

@@ -0,0 +1,5 @@
+---
+"@smithy/node-http-handler": minor
+---
+
+add socket exhaustion checked warning when throughput is slow

packages/node-http-handler/src/node-http-handler.spec.ts

@@ -704,4 +704,37 @@ describe("NodeHttpHandler", () => {
       expect(nodeHttpHandler.httpHandlerConfigs()).toEqual({});
     });
   });
+
+  describe("checkSocketUsage", () => {
+    beforeEach(() => {
+      jest.spyOn(console, "warn").mockImplementation(jest.fn());
+    });
+
+    afterEach(() => {
+      jest.resetAllMocks();
+    });
+
+    it("warns when socket exhaustion is detected", async () => {
+      const lastTimestamp = Date.now() - 30_000;
+      const warningTimestamp = NodeHttpHandler.checkSocketUsage(
+        {
+          maxSockets: 2,
+          sockets: {
+            addr: [null, null],
+          },
+          requests: {
+            addr: [null, null, null, null],
+          },
+        } as any,
+        lastTimestamp
+      );
+
+      expect(warningTimestamp).toBeGreaterThan(lastTimestamp);
+      expect(console.warn).toHaveBeenCalledWith(
+        "@smithy/node-http-handler:WARN",
+        "socket usage at capacity=2 and 4 additional requests are enqueued.",
+        "See https://docs.aws.amazon.com/sdk-for-javascript/v3/developer-guide/node-configuring-maxsockets.html"
+      );
+    });
+  });
 });

packages/node-http-handler/src/node-http-handler.ts

@@ -26,6 +26,8 @@ export const DEFAULT_REQUEST_TIMEOUT = 0;
 export class NodeHttpHandler implements HttpHandler<NodeHttpHandlerOptions> {
   private config?: ResolvedNodeHttpHandlerConfig;
   private configProvider: Promise<ResolvedNodeHttpHandlerConfig>;
+  private socketWarningTimestamp = 0;
+  private socketCheckTimeoutId = (null as unknown) as NodeJS.Timeout;
 
   // Node http handler is hard-coded to http/1.1: https://github.com/nodejs/node/blob/ff5664b83b89c55e4ab5d5f60068fb457f1f5872/lib/_http_server.js#L286
   public readonly metadata = { handlerProtocol: "http/1.1" };
@@ -45,6 +47,53 @@ export class NodeHttpHandler implements HttpHandler<NodeHttpHandlerOptions> {
     return new NodeHttpHandler(instanceOrOptions as NodeHttpHandlerOptions);
   }
 
+  /**
+   * @internal
+   *
+   * @param agent - http(s) agent in use by the NodeHttpHandler instance.
+   * @returns timestamp of last emitted warning.
+   */
+  public static checkSocketUsage(agent: hAgent | hsAgent, socketWarningTimestamp: number): number {
+    // note, maxSockets is per origin.
+    const { sockets, requests, maxSockets } = agent;
+
+    if (typeof maxSockets !== "number" || maxSockets === Infinity) {
+      return socketWarningTimestamp;
+    }
+
+    const interval = 15_000;
+    if (Date.now() - interval < socketWarningTimestamp) {
+      return socketWarningTimestamp;
+    }
+
+    let socketsInUse = 0;
+    let requestsEnqueued = 0;
+
+    if (sockets) {
+      for (const key in sockets) {
+        socketsInUse = Math.max(socketsInUse, sockets[key]?.length ?? 0);
+      }
+    }
+
+    if (requests) {
+      for (const key in requests) {
+        requestsEnqueued = Math.max(requestsEnqueued, requests[key]?.length ?? 0);
+      }
+    }
+
+    // This threshold is somewhat arbitrary.
+    // A few enqueued requests is not worth warning about.
+    if (socketsInUse >= maxSockets && requestsEnqueued >= 2 * maxSockets) {
+      console.warn(
+        "@smithy/node-http-handler:WARN",
+        `socket usage at capacity=${socketsInUse} and ${requestsEnqueued} additional requests are enqueued.`,
+        "See https://docs.aws.amazon.com/sdk-for-javascript/v3/developer-guide/node-configuring-maxsockets.html"
+      );
+      return Date.now();
+    }
+    return socketWarningTimestamp;
+  }
+
   constructor(options?: NodeHttpHandlerOptions | Provider<NodeHttpHandlerOptions | void>) {
     this.configProvider = new Promise((resolve, reject) => {
       if (typeof options === "function") {
@@ -81,10 +130,13 @@ export class NodeHttpHandler implements HttpHandler<NodeHttpHandlerOptions> {
     if (!this.config) {
       this.config = await this.configProvider;
     }
+
     return new Promise((_resolve, _reject) => {
       let writeRequestBodyPromise: Promise<void> | undefined = undefined;
       const resolve = async (arg: { response: HttpResponse }) => {
         await writeRequestBodyPromise;
+        // if requests are still resolving, cancel the socket usage check.
+        clearTimeout(this.socketCheckTimeoutId);
         _resolve(arg);
       };
       const reject = async (arg: unknown) => {
@@ -106,6 +158,14 @@ export class NodeHttpHandler implements HttpHandler<NodeHttpHandlerOptions> {
 
       // determine which http(s) client to use
       const isSSL = request.protocol === "https:";
+      const agent = isSSL ? this.config.httpsAgent : this.config.httpAgent;
+
+      // If the request is taking a long time, check socket usage and potentially warn.
+      // This warning will be cancelled if the request resolves.
+      this.socketCheckTimeoutId = setTimeout(() => {
+        this.socketWarningTimestamp = NodeHttpHandler.checkSocketUsage(agent, this.socketWarningTimestamp);
+      }, (this.config.requestTimeout ?? 2000) + (this.config.connectionTimeout ?? 1000));
+
       const queryString = buildQueryString(request.query || {});
       let auth = undefined;
       if (request.username != null || request.password != null) {
@@ -126,7 +186,7 @@ export class NodeHttpHandler implements HttpHandler<NodeHttpHandlerOptions> {
         method: request.method,
         path,
         port: request.port,
-        agent: isSSL ? this.config.httpsAgent : this.config.httpAgent,
+        agent,
         auth,
       };