AWS SDKのrequestTimeoutを2秒にしたのに、20秒待っても切れなかった。偽のS3を立ててリトライとタイムアウトの既定を数えた話

先週、夜間バッチの障害時の手順書を見直していて、ひとつの問いに答えられないことに気づきました。「S3 が返事をしなくなったら、このバッチは何秒で諦めるのか」。

設定には requestTimeout: 2000 と書いてあります。2 秒で切れて、SDK が何回か送り直して、それでもだめならエラーで終わる。チームの誰に聞いてもそういう答えでしたし、私もそう思っていました。ただ、それを実際に見た人はいませんでした。本物の S3 を都合よく黙らせることはできないので、障害のときの振る舞いは、障害が起きるまで確かめようがないんですよね。

そこで、社内のローカル環境に「わざと壊れる S3」を立てて、AWS SDK for JavaScript v3 の送り直しとタイムアウトを数えることにしました。先に結果を書くと、2 秒の設定は効いておらず、20 秒待っても返ってきませんでした。

偽の S3 は 30 行で足りた

最初は S3 互換の MinIO を使うつもりでした。普段のテストで使っていて、手元にもあるからです。ただ MinIO は正しく動くように作られているので、「500 を返し続ける」「接続だけ受けて黙る」「Retry-After を付けて 503 を返す」といった壊れ方を、思いどおりに起こせません。

運用を考えると、普段は既製品に寄せたいと考えています。ただ今回確かめたいのは SDK 側の振る舞いだけで、S3 の中身はいりません。Node.js の http モジュールで、決めたステータスと XML を返すだけのサーバーを書きました。エンドポイントを差し替えれば、SDK は相手が本物かどうかを気にしません。

使ったのは @aws-sdk/client-s3 3.1152.0（HTTP の部分は @smithy/node-http-handler 4.12.1）と Node.js 22.14.0 です。本物の AWS には一度もつないでいないので、費用は 0 円でした。

送り直しは 3 回。ただし「残高」があった

まずは 500（InternalError）を返し続けるサーバーに、同じクライアントで GetObject を 30 回呼びました。

// 500 を返し続ける偽の S3 を立て、同じクライアントで GetObject を 30 回呼ぶ
const http = require("node:http");
const { S3Client, GetObjectCommand } = require("@aws-sdk/client-s3");

let received = 0;
const fakeS3 = http.createServer((req, res) => {
  received++;
  req.resume();
  const xml = "<Error><Code>InternalError</Code><Message>fake</Message></Error>";
  res.writeHead(500, { "Content-Type": "application/xml", "Content-Length": Buffer.byteLength(xml) });
  res.end(xml);
});

fakeS3.listen(0, "127.0.0.1", async () => {
  const s3 = new S3Client({
    region: "ap-northeast-1",
    endpoint: `http://127.0.0.1:${fakeS3.address().port}`,
    forcePathStyle: true,
    credentials: { accessKeyId: "dummy", secretAccessKey: "dummy" },
  });

  const sentPerCall = [];
  for (let i = 0; i < 30; i++) {
    const before = received;
    await s3.send(new GetObjectCommand({ Bucket: "batch-input", Key: "a.csv" })).catch(() => {});
    sentPerCall.push(received - before);
  }
  console.log(sentPerCall.join(" "));
  fakeS3.close();
});

// 実行結果:
// 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 3 1 1 1 1 1

1 回の呼び出しで 3 回送る、は予想どおりでした。初回と、送り直しが 2 回です。リクエストのヘッダーには amz-sdk-request: attempt=1; max=3 のように何回目かが入り、amz-sdk-invocation-id は 3 回とも同じ値でした。

想定外だったのは 26 回目からです。急に 1 回しか送らなくなりました。

SDK のソースを読むと、送り直しには残高があります。クライアントごとに 500 から始まり、500 やタイムアウトのような一時的な失敗で 1 回送り直すたびに 10、スロットリング（503 SlowDown など）なら 5 を引く。残高が足りなければ、まだ 3 回に達していなくても送り直しません。1 回の呼び出しで 2 回送り直すと 20 減るので、25 回で使い切る計算です。503 SlowDown で同じことをすると、1 回の呼び出しで減るのは 10 なので、51 回目から 1 回になりました。

残高は、送り直さずに成功すると 1 ずつ戻ります。使い切った後に成功を 10 回挟んでから 500 を返すと、送信は 2 回（送り直し 1 回分だけ）で、その次からはまた 1 回でした。クライアントを作り直すと、残高は 500 に戻ります。

正直なところ、仕組みとしてはよくできていると思っています。相手が落ちているときに全員が 3 倍の量で叩き続ければ、復旧の足を引っ張るからです。ただ、Lambda のようにクライアントを関数の外で作って使い回していると、障害のさなかに長く温まっていた実行環境ほど残高が尽きていて、「3 回送り直すはず」という前提がこっそり外れます。エラーの $metadata.attempts を見ると、26 回目以降は 1 になっていました。

失敗の種類ごとの振る舞いを並べると、次のとおりです。待ちの範囲はソースの計算式から、括弧内は 20 回ずつ測った最大値（送信にかかる数ミリ秒を含む）です。

Retry-After は少し意外でした。サーバーが「30 秒待って」と言っても、SDK が待ったのは 5 秒あまりです。ソースでは、指示された時間を「自前の待ち時間＋5 秒」で頭打ちにしていました。相手の指示をそのまま信じて長く止まらないための上限だと思いますが、30 秒待ってくれる前提で組んでいると、早めに再送が届くことになります。

最初にやった対処は requestTimeout を書くこと。それが効いていなかった

次が本題です。接続は受け付けるのに何も返さないサーバーを、設定ごとに立てて、1 回ずつ投げました。

// 接続は受けるが何も返さない偽の S3 を設定ごとに立て、1 回ずつ GetObject を投げる
const http = require("node:http");
const { S3Client, GetObjectCommand } = require("@aws-sdk/client-s3");

const settings = {
  "設定なし": {},
  "requestTimeout だけ": { requestHandler: { requestTimeout: 2000 } },
  "throwOnRequestTimeout も": { requestHandler: { requestTimeout: 2000, throwOnRequestTimeout: true } },
};

async function tryOnce(label, extra) {
  let received = 0;
  const silentS3 = http.createServer((req) => { received++; req.resume(); });
  await new Promise((r) => silentS3.listen(0, "127.0.0.1", r));
  const s3 = new S3Client({
    region: "ap-northeast-1",
    endpoint: `http://127.0.0.1:${silentS3.address().port}`,
    forcePathStyle: true,
    credentials: { accessKeyId: "dummy", secretAccessKey: "dummy" },
    ...extra,
  });
  const started = Date.now();
  const outcome = await Promise.race([
    s3.send(new GetObjectCommand({ Bucket: "batch-input", Key: "a.csv" })).then(() => "成功", (e) => e.name),
    new Promise((r) => setTimeout(() => r("20 秒たっても未完了"), 20_000)),
  ]);
  console.log(`${label}: ${outcome}（送信 ${received} 回・${((Date.now() - started) / 1000).toFixed(1)} 秒）`);
  silentS3.closeAllConnections();
  silentS3.close();
}

(async () => {
  for (const [label, extra] of Object.entries(settings)) await tryOnce(label, extra);
  process.exit(0);
})();

// 実行結果:
// 設定なし: 20 秒たっても未完了（送信 1 回・20.0 秒）
// @smithy/node-http-handler - [WARN] a request has exceeded the configured 2000 ms requestTimeout. （以下略）
// requestTimeout だけ: 20 秒たっても未完了（送信 1 回・20.0 秒）
// throwOnRequestTimeout も: TimeoutError（送信 3 回・6.1 秒）

設定なしで待ち続けるのは、型定義のコメントに「既定は 0 で、タイムアウトしない」とあるとおりです。困ったのは 2 行目でした。手順書が頼りにしていた requestTimeout: 2000 は、2 秒たったところで警告を 1 行出すだけで、要求はそのまま待ち続けます。

調べると、これは @smithy/node-http-handler の 4.4.0（2025 年 10 月 13 日公開）からの振る舞いでした。それまでの requestTimeout は、実際には「ソケットが無通信のまま何ミリ秒たったら切るか」として働いていて、超えれば TimeoutError を投げていました。4.4.0 からは名前どおり「応答が返るまでの時間」になった代わりに、超えても警告だけで、例外にしたければ throwOnRequestTimeout: true を足す形に変わっています。型定義には、長いあいだ無通信のタイムアウトとして誤って使われてきたので、例外にするかどうかは利用者に選ばせる、という趣旨の説明がありました。

念のため、4.3.0 の HTTP ハンドラーを同じクライアントに差し込み、requestTimeout: 2000 だけで投げてみると、TimeoutError（送信 3 回・6.2 秒）で終わりました。今思えば、手順書の「2 秒で切れる」は、書いた当時は正しかったのだと思います。依存を上げたどこかで、警告を出すだけの設定に変わっていたわけです。

socketTimeout でも切れはしますが、こちらは「無通信の時間」なので、少しずつでもデータが届き続ける相手には効きません。今回は、応答が返るまでの時間で切れる throwOnRequestTimeout の方を選びました。ここは好みが分かれるところですが、手順書に「何秒で諦める」と 1 つの数字で書けることを優先しています。

層が重なると、回数も時間も掛け算になる

SDK の 3 回は、いちばん下の層の話です。その上にも送り直す仕組みがあります。たとえば Lambda を非同期で呼ぶと、関数がエラーで終わったときに、既定で 2 回まで呼び直されます。中で SDK が 3 回ずつ送るので、1 件のイベントで S3 に届く要求は最大 9 回です。EventBridge や Step Functions の再試行を重ねれば、さらに掛け算になります。

時間も同じです。2 秒で切る設定でも、3 回送れば 6.1〜6.2 秒かかりました。Lambda の既定のタイムアウトは 3 秒なので、この組み合わせのままだと、SDK が 2 回目の応答を待っている途中で関数の方が先に打ち切られます。どの層に「最後まで粘る役」を任せるかを決めないまま、それぞれの既定値を重ねると、回数も時間も、誰も意図していない値になる。今回いちばん強く感じたのはそこでした。

お金の面でも差が出ます。メモリ 1GB の Lambda が、応答しない S3 を相手に 1 万回呼ばれたとします。関数のタイムアウトを上限の 900 秒にしていて SDK 側で切らなければ、1 万回 × 900 秒で 900 万 GB 秒。東京リージョンの x86 の単価（1GB 秒あたり 0.0000166667 ドル、無料枠は除く）で約 150 ドル、1 ドル 150 円なら約 2 万 2,500 円です。下の設定で約 15 秒で諦めれば 15 万 1,000 GB 秒、約 2.5 ドル（約 380 円）で済みます。運用を考えると、お金より痛いのは、その間ずっと同時実行数を食いつぶして、関係のない関数まで詰まらせることの方ですが。

決め直した設定

最終的に、バッチの S3 クライアントは次の形にしました。回数と時間は、既定と同じ値でもあえて書いておく方針です。

// バッチ用に決めた S3 クライアントの作り方（応答しない偽の S3 で所要時間も測る）
const http = require("node:http");
const { S3Client, GetObjectCommand } = require("@aws-sdk/client-s3");

function createBatchS3Client(overrides = {}) {
  return new S3Client({
    region: "ap-northeast-1",
    maxAttempts: 3, // 既定と同じ値だが、読む人に回数が見えるように書いておく
    requestHandler: {
      connectionTimeout: 1_000,
      requestTimeout: 5_000,
      throwOnRequestTimeout: true, // これが無いと requestTimeout は警告を出すだけ
    },
    ...overrides,
  });
}

let received = 0;
const silentS3 = http.createServer((req) => { received++; req.resume(); });
silentS3.listen(0, "127.0.0.1", async () => {
  const s3 = createBatchS3Client({
    endpoint: `http://127.0.0.1:${silentS3.address().port}`,
    forcePathStyle: true,
    credentials: { accessKeyId: "dummy", secretAccessKey: "dummy" },
  });
  const started = Date.now();
  const outcome = await s3.send(new GetObjectCommand({ Bucket: "batch-input", Key: "a.csv" })).catch((e) => e.name);
  console.log(`${outcome}（送信 ${received} 回・${((Date.now() - started) / 1000).toFixed(1)} 秒）`);
  process.exit(0);
});

// 実行結果:
// TimeoutError（送信 3 回・15.1 秒）

// 改善の余地あり: 5 秒 × 3 回と待ち時間の合計が、関数のタイムアウト（30 秒にした）に収まるかを、
// いまは人が計算して確かめているだけ。設定から自動で検査する仕組みはまだ無い。

2 回測って 15.1 秒と 15.3 秒でした。5 秒 × 3 回に、送り直しの待ちが最大 0.3 秒ほど乗る計算と合っています。関数のタイムアウトは 30 秒にして、SDK が先に諦めるようにしました。ログには、エラー名と一緒に $metadata.attempts も出すようにしています。残高が尽きて送り直していないときは、ここが 1 になるので、障害のさなかに「なぜか送り直していない」状態が後から追えます。

ソースの中にあった、2026 年版の送り直し

SDK のソースを読んでいて、もう 1 つ見つけたものがあります。SMITHY_NEW_RETRIES_2026 という環境変数を true にすると、送り直しの値の組が丸ごと入れ替わる作りになっていました。

同じ測り方で比べると、500 の待ちは半分（1 回目 0〜50ms、2 回目 0〜100ms。実測の最大は 59ms と 111ms）、SlowDown の待ちは倍（0〜1,000ms と 0〜2,000ms。実測の最大は 837ms と 1,992ms）になりました。500 で 1 回送り直すと残高が 14 減るので、500 を返し続けると 17 回目までが 3 回、18 回目が 2 回、19 回目からは 1 回です。一時的な失敗には早く少なく、スロットリングにはゆっくり、という方向に寄せた値に見えます。

既定がいつこちらに切り替わるのかは、私には分かりません。手順書に書いてあることと実際の振る舞いがずれる、という今回のような話は、依存を上げた日に静かに起きます。どちらの値でも困らないよう、回数と時間の上限はこちらで書いておくのが安全だと考えています。

おわりに

手順書の「2 秒で切れる」は、「5 秒 × 3 回、約 15 秒で諦める。関数のタイムアウトは 30 秒」に書き換えました。数字が増えて読みにくくなりましたが、測った値なので、前よりは信用できます。

次は、今回の偽の S3 を CI に置いて、SDK を上げるたびに「何回送るか」「何秒で諦めるか」が変わっていないかを自動で確かめるようにしたいと思っています。上の「改善の余地」も、そこで一緒に片付けるつもりです。Python で書いたバッチも別の SDK を使っているので、同じ偽の S3 で数え直すところから始めます。