AWS SDK (v3) のソケットプール枯渇でLambdaがタイムアウトしたので、原因や設定値を調べてみた

ある日、Lambdaにて実行時間が15分を超えてタイムアウトする現象が発生し、CloudWatchログを調査したところ以下の警告を発見しました。

@smithy/node-http-handler:WARN - socket usage at capacity=50 and N additional requests are enqueued.

調べてみると、AWS SDK v3のHTTP通信の仕組みとソケットプールの制限に関わる問題だったので、今回はこの警告の意味と関連する設定値を深掘りしてみます。

発生したエラー

改めて、CloudWatchログに出ていたアラートはこちらです。

@smithy/node-http-handler:WARN - socket usage at capacity=50 and 2259 additional requests are enqueued.

このログは @smithy/node-http-handler パッケージから出力されているもので、AWS SDKが内部で使っているHTTPクライアントの警告です。要約すると「同時接続数の上限（50）に達していて、さらに2259件のリクエストがキューで空きを待っている」ということになります。

自分の環境の背景と原因

今回の構成はこんな感じでした。

S3 (JsonLineファイル) → SQS → Lambda
                                 ↓
                         S3 (設定ファイル)を参照

LambdaがS3に置かれたJsonLineファイル（複数のJSONオブジェクトがまとまったファイル）をSQS経由で受け取り、ファイル内の各JSONオブジェクトを最大100並列で処理します。処理中にS3にある設定ファイルを参照する必要があるのですが、それぞれの並列処理が毎回S3にアクセスすると処理時間に影響するため、Lambda起動直後に事前キャッシュしておく設計でした。

ところが、キャッシュが効かないパターンがあり、100並列の各処理がそれぞれS3にアクセスしてしまうケースが発生。S3へのリクエストが同時に大量に飛んだ結果、AWS SDKの最大ソケット数50を超えてしまい、キュー待ちのリクエストによって処理時間がどんどん伸びていき、最終的にLambdaがタイムアウトしました。

• AWS SDKの最大ソケット数50に対してリクエストが2000件以上発生し、処理待ちのリクエストによって処理時間が伸びていた
• それを踏まえて確認したところ、並列で処理する中でS3にあるファイルの読み込みが大量に発生する処理の見落としがあった

そもそも「AWS SDKのリクエスト」とはなんなのか？「50」はどこで設定されてる数字？といったところを詳しく見ていきます。

AWS SDKのソケットについて

使用していた言語がTypeScriptなのでAWS SDK for Javascript、かつ今回はS3のリクエストで発生したのでS3を例として実際にログが出るまでどんな経緯なのか深掘りしてみます。
公式ドキュメントはこちら

AWS SDKを使ってS3のクライアントを例えば下の感じで作成したとき:

import { S3Client } from "@aws-sdk/client-s3";
import { NodeHttpHandler } from "@smithy/node-http-handler";
import https from "https";

const s3Client = new S3Client({
  requestHandler: new NodeHttpHandler({
    connectionTimeout: 3_000,
    requestTimeout: 5_000,
    socketAcquisitionWarningTimeout: 3_000,
    httpsAgent: new https.Agent({
      maxSockets: 50,
      keepAlive: true,
    }),
  }),
  maxAttempts: 3,
});

実際にこのクライアントを使用して s3Client.getObject() を呼んだりすると以下のような流れで処理されます。

• SDK内部で HTTPS REST API リクエストに変換される
• NodeHttpHandler が https.Agent にリクエストを渡す
• https.Agent が空きソケット（TCPコネクション）を確認
  • 空いていればその場でリクエスト送信
  • ソケットがすでに埋まっているならキューに追加され、待ち状態に
    • このソケットの上限が、maxSockets で定義されている値（デフォルト50）
• キュー待ち状態で socketAcquisitionWarningTimeout が経過すると、例のログが出力される

↓ 言葉だけだと掴みづらいのでClaudeに図を出してもらいました

AWS SDK の世界 (Smithy)                  Node.js の世界
┌────────────────────────────┐          ┌────────────────────────┐
│ NodeHttpHandler            │          │ https.Agent            │
│                            │          │                        │
│  - connectionTimeout       │          │  - maxSockets          │
│  - requestTimeout          │──使う──→  │  - keepAlive           │
│  - socketAcquisitionWarning│          │  - maxTotalSockets     │
│    Timeout                 │          │                        │
│  - socketTimeout           │          │                        │
│  - throwOnRequestTimeout   │          │                        │
│                            │          │                        │
│  タイムアウトや警告の制御      │          │  TCPコネクションの管理    │
└────────────────────────────┘          └────────────────────────┘

WARNログの発火条件

ログの出力条件ですが、smithy-typescriptのソースコードを見ると実はもう一つルールがありました

// smithy-typescript の NodeHttpHandler 内部
if (socketsInUse >= maxSockets && requestsEnqueued >= 2 * maxSockets) {
  logger?.warn?.(
    `@smithy/node-http-handler:WARN - socket usage at capacity=${maxSockets} and ${requestsEnqueued} additional requests are enqueued.`
  );
}

maxSockets を超えていてかつ、キュー待ちのリクエスト数が maxSockets の2倍（デフォルト値50の場合は100以上）のときにログが出るとのことです。さらに15秒のクールダウンがあり連続でログが出続けないようにもなっています。

パッケージの提供元

ちなみにパッケージと提供元はこんな関係性です。

今回の場合、JsonLineのS3ファイルがキー、そのファイルのJSONオブジェクトごとに並列で処理するようにしており、それぞれの処理でS3ファイルの getObject() が複数回走るような仕組みになってしまっていて、大量のリクエストが飛んでしまったという経緯です。

なぜ最大ソケット数のデフォルト値は50?

公式ドキュメントにて以下の記述があります

値または Agent オブジェクトを指定しない場合、SDK for JavaScript は maxSockets の値として 50 を使用します

SDK v3のリリース初期は Infinity（無限）だったそうですが、問題が発生してから50になったとのことです。

ソースはこちらのIssueで、まとめるとこんな経緯です。

• Node.js デフォルトの Infinity だと、例えば DynamoDB に30,000件の PutItem を一気に投げた場合、OSのファイルディスクリプタ上限（Lambdaは約1024）に達して EMFILE: too many open files エラーで落ちる
• SDKは利用者に合理的なデフォルト値を提供すべき、というのがAWSチームの方針
• 50という数字の根拠は v2 での実績と、各種ブログポストでの推奨値を参考にしたもの

ちなみに Node.js の https.Agent 単体で使う場合のデフォルトは Infinity です。Node.js公式ドキュメントの maxSockets の説明の最後に書いてあります。

Maximum number of sockets to allow per host. If the same host opens multiple concurrent connections, each request will use new socket until the maxSockets value is reached. If the host attempts to open more connections than maxSockets, the additional requests will enter into a pending request queue, and will enter active connection state when an existing connection terminates. This makes sure there are at most maxSockets active connections at any point in time, from a given host. Default: Infinity.

Node.js 単体だと Infinity ですが、AWS SDK の NodeHttpHandler を経由するとデフォルトが50になるように上書きされている、ということですね。

他の設定値

せっかくなので、maxSockets 以外の設定値も見てみます。

公式ドキュメントはこちら：NodeHttpHandlerOptions

以下はS3Clientをデフォルト値で明示的に宣言したコードです。

import { S3Client } from "@aws-sdk/client-s3";
import { NodeHttpHandler } from "@smithy/node-http-handler";
import https from "https";

const s3Client = new S3Client({
  requestHandler: new NodeHttpHandler({
    // TCP接続の確立にかかる時間の上限（0 = 無制限）
    connectionTimeout: 0,
    // TCP接続確立後、レスポンスを受け取り終わるまでの時間の上限（0 = 無制限）
    requestTimeout: 0,
    // リクエスト発行後、ソケット枯渇チェックを行うまでの時間
    // デフォルト: (requestTimeout ?? 2000) + (connectionTimeout ?? 1000) = 3000ms
    socketAcquisitionWarningTimeout: 3_000,
    // ソケットのアイドルタイムアウト。通信がない状態が続いたら切断（0 = 無制限）
    socketTimeout: 0,
    // requestTimeout超過時にエラーを投げるか（falseだと警告のみ）
    throwOnRequestTimeout: false,
    // Node.js の https.Agent（TCPコネクションの管理）
    httpsAgent: new https.Agent({
      // 1ホストあたりの同時TCPコネクション数の上限
      maxSockets: 50,
      // HTTPリクエスト完了後、TCPコネクションを閉じずに再利用する
      keepAlive: true,
      // 全ホスト合計のソケット上限
      maxTotalSockets: Infinity,
    }),
  }),
  // リクエストの最大試行回数（初回含む。リトライは maxAttempts - 1 回）
  maxAttempts: 3,
});

上の階層から順番に説明してみます

NodeHttpHandlerの設定値

• connectionTimeout
  • TCP接続の確立にかかる時間の上限
  • デフォルトの 0 は時間制限なし = タイムアウト無効化のため、何分でも待つ
• requestTimeout
  • TCP接続後、レスポンスを受け取るまでの時間の上限
  • これもデフォルトは 0 で時間制限なし
• socketAcquisitionWarningTimeout
  • リクエスト発行後、ソケット枯渇チェックを行うまでの時間
  • この秒数が過ぎてかつ、上記した待ちキュー数が maxSockets の2倍の場合にWARNログ出力
• socketTimeout
  • ソケットのアイドルタイムアウト。通信がない状態が続いたら切断する
• throwOnRequestTimeout
  • true にするとrequestTimeout 超過でエラーを投げるようにする（デフォルトは警告止まり）

https.Agentの設定値

• maxSockets
  • 今回解説した設定値
  • 1ホストあたりの同時TCPコネクション数の上限
• keepAlive
  • HTTPリクエスト完了後にTCPコネクションを再利用するかどうか
  • SDK v3だとデフォルトで true
• maxTotalSockets
  • 全てのホストのソケット上限数
  • 1つの Agent を複数クライアントで共有したときだけ意味を持つ
  • デフォルトは Infinity

SDKクライアントレベルの設定

• maxAttempts
  • リクエストの最大試行回数（初回含む。リトライは maxAttempts - 1 回）
  • デフォルトは 3

まとめ

以上、AWS SDK v3 の socket usage at capacity 警告の解説でした。同じ警告に遭遇した方がさっくり理解できたら幸いです。

参考リンク

• AWS公式 - Configure maxSockets in Node.js
• AWS SDK v3 API - NodeHttpHandlerOptions
• Node.js公式 - http.Agent options
• AWS公式 - Retry behavior
• smithy-typescript ソースコード
• GitHub Issue #1959 - maxSockets 50の経緯
• GitHub Issue #3722 - Connection timeouts don't include socket pool wait time