Lambda: 高負荷時の SQS リトライ挙動を検証する

はじめに

参画しているプロジェクトで、以下のような事象に遭遇しました。何が原因なのか、対策はあるのかを検証したいと思います。

遭遇した事象

1. 想定の流量を大きく超える大量データを S3 にアップロードしたところ、一部データが Lambda で処理された形跡がない
2. ログ上も、そもそも当該のファイルでトリガーされた記録がない
3. ((( メッセージが虚空に吸い込まれた... )))

構成

1. S3 の put を S3 Event Notification (S3通知) で監視し、SQS に配信
2. Lambda の Event Source Mapping (ESM) で SQS をポーリングし、処理

検証すること

1. 消えたメッセージはどこへ行ったのか (虚空? DLQ?)
2. 消える条件は何か
3. 回避の方法はあるか

作成するリソース

まずは検証環境で再現できるかの確認をやります。以下のように環境を用意しました。

※連携がうまく動くように、ポリシーは適宜追加が必要です。

また、重要そうなパラメータは以下の通り設定しました。

Lambda

頭書の事象が発生した環境が Node でしたので、合わせて Node にしました。起動したか・正しく終了したか・どのファイルがトリガーで起動したか のログを出すようにします。また、実行時間が短すぎると高負荷の再現でたくさんのテストファイルが必要になるので、5000ms 待機させてます。

export const handler = async (event) => {
  const body = JSON.parse(event.Records[0].body);
  const s3Path = body.Records[0].s3;
  const bucket = s3Path.bucket.name;
  const key = decodeURIComponent(s3Path.object.key.replace(/\+/g, ' '));
  const filename = key.split('/').pop();
  console.log("起動したよ", JSON.stringify({ bucket, key, filename }));

  await new Promise(resolve => setTimeout(resolve, 5000));

  console.log("終了したよ", JSON.stringify({ bucket, key, filename }));
};

検証方針

実際に S3 にファイルを投入して検証します。ファイルそのものは空ファイルです。各メトリクスを取得し、何が起きてるかみます。

起動数・終了数のチェック

CloudWatch Logs Insights で以下クエリを投げます。

filter @type = "REPORT" or @message like /起動したよ/ or @message like /終了したよ/
| stats
    count(@type = "REPORT") as start_counts,
    count(@initDuration != "" and @type = "REPORT") as cold_start_counts,
    sum(@message like /起動したよ/) as started_log_counts,
    sum(@message like /終了したよ/) as finished_log_counts

これで、以下の表のようなメトリクスが取れます。

処理したファイルのチェック

CloudWatch Logs Insights で以下クエリを投げます。

filter @message like /起動したよ/                   
  | stats count() by filename

これで、処理されたファイル名が全件取得できますので、欠損があればわかります。

DLQ の確認

用意した DLQ にメッセージが入ってくるか確認します。件数が、投入したファイル数 - 処理されたファイル数 と同じであれば、虚空に消えたファイルがいないことがいえそうです。

検証

200ファイルで検証

綺麗に終わりました。ファイル名も欠損なく、DLQ も空です。まだ捌けてそうなので投入するファイルを増やします。

300 ファイルで検証

欠損してますね。処理されたファイル名一覧を見ると、実際に3ファイル処理されていません。DLQ のメッセージも、以下のように3件取得でき、内容も未処理のファイルと一致しました。

一旦考える

以下のように、スロットルのカウントが上がってるので、途中からは「ポーリングしたけどスロットルで拒否される」を繰り返している気がします。

続いて、ESM の最大同時実行数と、Lambda の最大同時実行数の設定に違いがあるか、確認してみます。

300 ファイルで検証 ~Lambda の同時実行数を絞らない版~

通りました。逆もやってみます。

300 ファイルで検証 ~ESM の同時実行数を絞らない版~

だめでした。捌けているリクエストが、どちらも制限している時より減っているのは、Lambdaの上限のみだと ESM の制限がかからず、Lambda, ESM 両方の同時実行数を制限した時よりスロットルにかかるリクエストが増えたためだと考えられます。実際に、スロットルの件数は以下のように差異がありました。

(左が両方制限、右がLambdaのみ制限)

結論のようなもの

原因

1. Lambda の予約された同時実行で設定した並列数で捌ききれない量のリクエストを投げると、Lambda はスロットルを返す。
2. スロットルで拒否されたデータは SQS に戻り、ReceiveCount を増やす
3. リトライ数上限まで拒否され続けたタスクは、そのまま DLQ へ飛ばされる

対策

• 基本的には Lambda の予約された同時実行ではなく、ESM の Maximum concurrency で絞る
  • AWSのドキュメント での記載には、Lambdaの設定値はESMの設定値以上にすべし、とありますが、イコールだと負荷状況によっては破綻しうるようです。

最大同時実行数は、1 つのキューが関数の予約された同時実行のすべてを使用したり、アカウントの同時実行クォータの残りのすべてを使用したりしないようにするために使用できます。

ーーー

最大同時実行数を設定する場合は、関数の予約された同時実行数が、関数にマップされたすべての Amazon SQS イベントソースの合計最大同時実行数以上になるようにしてください。合計数未満になった場合は、Lambda がメッセージをスロットルする可能性があります。

https://docs.aws.amazon.com/ja_jp/lambda/latest/dg/services-sqs-scaling.html

簡単にまとめ

• Lambda の予約された同時実行を 「この並列数で実行してほしい」 の上限として使うのは危険で、DLQへの溢れが発生しうる。
• 特定の並列数までベストエフォートでやって欲しいなら、ESM の Maximum concurrency で制限をかけて、Lambda 側は設定しない or それより余裕を持って設定する方がいい。
• 公式ドキュメントには、関数の予約された同時実行数 >= Maximum concurrency と記載されているが、同じ設定値はストレスがかかったときに破綻するので余裕を持たせたほうが良さそう。

最後に

あくまで単純化した上での結果なので、プロジェクトで僕が直面している課題は他にも問題が隠れているのかもしれないですが、一因であることは間違いないです。結果としてほぼAWS公式ドキュメントに書いてある内容になってしまいましたが、理解が深まってよかったと思います。