Zenn
🌀

Lambda の同時実行数でハマった話

2023/12/04に公開
AWS
Python
Lambda
#
sns
SQS
tech

シンプルフォームでエンジニアをやっている 中山@h7kayama と申します。
本記事は SimpleForm Advent Calendar 2023 の 4 日目の記事になります。

本日は最近一番ハマった「Lambdaの同時実行数」についてお話したいと思います。

弊社では SimpleCheck という法人名を入力するだけで世の中の情報を瞬時に収集し、30秒でレポーティングするサービスを開発しています。そんな SimpleCheck の裏側は主に AWS の Lambda を使用しています。Lambda のイベントソースは、FIFO SQS キューを使用しており SQS - Lambda という構成になっています。

構成図

Lambda の同時実行数の制御

SQS の FIFO キューは、SQS メッセージにメッセージグループIDを指定することにより、同一のメッセージグループIDの場合、1つずつ順次処理され、同時実行数を制御することができます。

FIFOキューでは、メッセージはメッセージグループ IDに基づいて順序付けられます。複数のホスト (または同一ホストの異なるスレッド) から同じメッセージグループ IDのメッセージがFIFOキューに送信された場合、Amazon SQSはメッセージを受信順に保存して処理を待ちます。Amazon SQSでメッセージが送信および受信された順序が確実に保持されるように、各プロデューサーはすべてのメッセージ送信で固有のメッセージグループIDを使用するようにしてください。

https://docs.aws.amazon.com/ja_jp/AWSSimpleQueueService/latest/SQSDeveloperGuide/FIFO-queues-understanding-logic.html

SimpleCheckでは、メッセージグループIDを使用してレースコンディションを防いでいます。

発生した事象

SQS メッセージに同一のメッセージグループIDを指定しているにも関わらず、なぜか lambda が同時実行されてしまう事象が発生しました。

Lambda の実行ログ

2023-08-28T12:50:09 START RequestId: 68e925e2-ef06-417b-8a4c-04933defdc27
2023-08-28T12:50:45 START RequestId: 674118a9-a885-4ce4-9a3b-704eb904012f
2023-08-28T12:56:19 END RequestId: 68e925e2-ef06-417b-8a4c-04933defdc27
2023-08-28T12:56:28 END RequestId: 674118a9-a885-4ce4-9a3b-704eb904012f

本来であれば、START -> END -> START -> END と処理されて欲しいところ、START -> START -> END -> END と処理されており、Lambda の完了を待たずに次の Lambda が実行されていることが分かります。

原因

SQS メッセージの保持期間を Lambda の処理中に超過してしまい、自動的に SQS キューから対象メッセージが削除されたため、Lambda の処理完了前に次のメッセージの処理が開始されてしまっていた。

SQS の FIFO キューでは、先頭のメッセージが削除された後、次のメッセージの処理が可能となります。Lambda のイベントソースを SQS キューとする場合、Lambda の処理が完了した際に、Lambda が対象のメッセージを削除する動作となります。そのため、SQS - Lambda の連携において、メッセージが削除されるケースとしては以下の2通りが考えられます。

  • Lambda の処理完了[1]
  • SQS キューのメッセージ保持期間の超過[2]

今回発生した事象に関しては、後者の「SQS キューのメッセージ保持期間の超過」によりメッセージが削除されたため、意図せず、次のメッセージの処理が実行されておりました。

2023/08/28 12:50:09 : メッセージ1 ( "messageId": "68e925e2-ef06-417b-8a4c-04933defdc27" ) が SQS キュー内に格納される
2023/08/28 12:50:45 : メッセージ2 ( "messageId": "674118a9-a885-4ce4-9a3b-704eb904012f" ) が SQS キュー内に格納される
2023/08/28 12:55:03 : メッセージ1 の処理が Lambda にて開始される
2023/08/28 12:55:09 : メッセージ1 が SQS キューに設定されたメッセージ保持期間を超過したため削除される ( 以降メッセージ2の処理が可能となる )
2023/08/28 12:55:10 : メッセージ2 の処理が Lambda にて開始される ( 意図しない同時実行が開始される )
2023/08/28 12:56:19 : メッセージ1 の処理が Lambda にて完了する
2023/08/28 12:56:28 : メッセージ2 の処理が Lambda にて完了する

対策

対象 SQS キューのメッセージ保持期間をより長い時間に設定しました。

設定画面のキャプチャ

おわりに

AWSサポートの方にご協力して頂きながら、原因究明に約1ヶ月ほど掛かりました（汗）
根気強く原因調査に付き合って頂いたAWSサポートの方にはとても感謝です。

SimpleCheck はリリースして1年ちょいしか経っていない、まだ若いプロダクトです。
最近は、SimpleCheck をご利用頂くお客様が徐々に増えてきて嬉しい反面、以前まで問題にならなかった事象が徐々に起き始めてきており、プロダクトの成長を日々感じられる毎日を過ごしております。

明日は弊社CTOの小間さんによる音声に関するお話です。乞うご期待！

脚注

  1. https://docs.aws.amazon.com/ja_jp/lambda/latest/dg/with-sqs.html ↩︎

  2. https://docs.aws.amazon.com/ja_jp/AWSSimpleQueueService/latest/SQSDeveloperGuide/sqs-basic-architecture.html ↩︎

Discussion