Amazon SQSの遅延キュー(delay queues)を理解しながら使ってみる

はじめに

サーバレスでイベント駆動なアーキテクチャを検討している中でどうしても「ちょっとSleepしてからのリトライ処理」を実装しなければいけない箇所が出てきて、実行中の処理でsleepするのはあまりにイケていないのでマネージドにやる方法として遅延キューがどれくらい使い物になるかを検討してみた。

遅延キューとは

その名の通り、キューイングされてからイベントトリガが引かれるまでの間にタイムラグがあるSQSのことだ。
正に「ちょっとSleepしてからのリトライ処理」をやるには良いのではないだろうか！
詳しくはAWS公式の開発者ガイド参照。

設定方法

マネージメントコンソール画面では以下の黄色蛍光ペンの設定部分にあたる。

Terraformで実装する場合は、以下のようなイメージになる。delay_seconds が該当の設定項目だ。

resource "aws_sqs_queue" "delay" {
  name                       = "delay-queue"
  delay_seconds              = 30
  visibility_timeout_seconds = 30
}

なお、マネージメントコンソール画面でピンク蛍光ペンを塗ったデフォルトの可視性タイムアウトが、Terraformの visibility_timeout_seconds にあたり、これも重要なので後程説明をする。

実際の動作を確認する

トリガ起動するLambdaの設定

さて、今回は、SQSのキューにPUTされたら、30秒後にLambdaが起動するということを実現しよう。
これにより、30秒後にリトライ処理を行ってあげれば、当初の目的が達成できる。

Lambda関数自体はテキトーに用意しよう。
reserved_concurrent_executions も重要なチューニング要素になるため、後程説明する。

data "archive_file" "scripts" {
  type        = "zip"
  source_dir  = "../scripts"
  output_path = "../outputs/lambda_function.zip"
}

resource "aws_lambda_function" "delay_queue" {
  depends_on = [
    aws_cloudwatch_log_group.lambda,
  ]

  function_name    = "delay-queue-function"
  filename         = data.archive_file.scripts.output_path
  role             = aws_iam_role.lambda.arn
  handler          = "lambda_function.lambda_handler"
  source_code_hash = data.archive_file.scripts.output_base64sha256
  runtime          = "python3.6"

  memory_size = 128
  timeout     = 30

  reserved_concurrent_executions = 1
}

SQSをイベントトリガとしてLambdaを起動する場合は、以下のように

      "sqs:DeleteMessage",
      "sqs:GetQueueAttributes",
      "sqs:ReceiveMessage",

のIAMポリシーの設定が必要なので注意。

resource "aws_iam_role" "lambda" {
  name               = "delay-queue-function-role"
  assume_role_policy = data.aws_iam_policy_document.lambda_assume.json
}

data "aws_iam_policy_document" "lambda_assume" {
  statement {
    effect = "Allow"

    actions = [
      "sts:AssumeRole",
    ]

    principals {
      type = "Service"
      identifiers = [
        "lambda.amazonaws.com",
      ]
    }
  }
}

resource "aws_iam_role_policy_attachment" "lambda" {
  role       = aws_iam_role.lambda.name
  policy_arn = aws_iam_policy.lambda_custom.arn
}

resource "aws_iam_policy" "lambda_custom" {
  name   = "delay-queue-function-policy"
  policy = data.aws_iam_policy_document.lambda_custom.json
}

data "aws_iam_policy_document" "lambda_custom" {
  statement {
    effect = "Allow"

    actions = [
      "sqs:DeleteMessage",
      "sqs:GetQueueAttributes",
      "sqs:ReceiveMessage",
      "logs:CreateLogGroup",
      "logs:CreateLogStream",
      "logs:PutLogEvents",
    ]

    resources = [
      "*",
    ]
  }
}

さて、Lambda関数が作れたら、SQSと接続をしよう。

resource "aws_lambda_event_source_mapping" "delay_queue" {
  event_source_arn = aws_sqs_queue.delay.arn
  function_name    = aws_lambda_function.delay_queue.arn
}

これで、準備は整った。

SQSにPUTしてみる

単発の実行

今回、Lambda側でCloudWatch Logsに、キューにPUTされた日時(sendDatetime)と、実際に処理を行った日時(receiveDateTime)、および試行回数(ApproximateReceiveCount)を出力するようにした。

単発で実行した場合の出力は以下のようになった。

{
    "messageId": "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx",
    "sendDatetime": "2020/09/19 12:01:30.712000",
    "approxSqsFirstReceiveTime": "2020/09/19 12:02:00.914000",
    "ApproximateReceiveCount": "1",
    "receiveDateTime": "2020/09/19 12:02:00.962043"
}

sendDatetimeとreceiveDateTimeがしっかり30秒離れているので、想定通りの動作をしてくれているようだ。

では、複数同時実行してみたらどうなるだろうか？

30連発の実行

SQSに10tps程度で30連発で書き込んでみる。
ここでのポイントは、Lambdaの reserved_concurrent_executions を 1 にしていることだ。

すると、

"messageId",                          ,"sendDatetime"              ,"receiveDateTime"          ","ApproximateReceiveCount"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:09.989000","2020/09/19 12:23:40.049147","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.001000","2020/09/19 12:23:40.070388","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.034000","2020/09/19 12:23:40.115585","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.038000","2020/09/19 12:23:40.115585","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.039000","2020/09/19 12:23:40.115585","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.023000","2020/09/19 12:23:40.315442","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.052000","2020/09/19 12:23:40.315442","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.065000","2020/09/19 12:23:40.315442","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.067000","2020/09/19 12:23:40.315442","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.047000","2020/09/19 12:23:40.315442","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.321000","2020/09/19 12:23:40.361676","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.301000","2020/09/19 12:23:40.361676","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.208000","2020/09/19 12:23:40.361676","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.511000","2020/09/19 12:23:43.794862","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.468000","2020/09/19 12:23:44.170619","1"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.089000","2020/09/19 12:24:10.155469","2"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.072000","2020/09/19 12:24:10.155469","2"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.147000","2020/09/19 12:24:10.293371","2"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.205000","2020/09/19 12:24:10.334936","2"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.145000","2020/09/19 12:24:10.425845","2"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.164000","2020/09/19 12:24:10.425845","2"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.164000","2020/09/19 12:24:13.925537","2"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.090000","2020/09/19 12:24:40.152953","3"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.085000","2020/09/19 12:24:40.200360","3"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.100000","2020/09/19 12:24:40.200360","3"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.103000","2020/09/19 12:24:43.237281","3"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.114000","2020/09/19 12:24:43.237281","3"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.110000","2020/09/19 12:24:43.237281","3"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.107000","2020/09/19 12:24:43.237281","3"
"xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx","2020/09/19 12:23:10.061000","2020/09/19 12:24:43.237281","3"

といった感じで、3ターンに分かれて実行された。
また、2ターン目、3ターン目に起動したトランザクションは、試行回数が増えている。
これは何を意味しているかと言うと、Lambdaの同時実行数が1であるがためにThrottleが発生しエラーとなり、visibility_timeout_seconds で設定している30秒後に起動してきて再実行されていると考えられる(試しにこの値を45秒にしたら2回目の施行は30+45秒後になった)。

ここで、2つの選択肢が登場する。

• redrive_policy を設定することで「最大N回リトライしたらDLQに入る」という動作をさせることができる
• message_retention_seconds の期間はリトライをし続ける(リトライ間隔は visibility_timeout_seconds で制御)

いずれのケースも、スロットル意外にLambdaのハンドラ関数がエラーを返した場合もリトライが行われることに留意する。
後者の手段の場合は、期限超過してリトライをした場合はロストする。
基本的には reserved_concurrent_executions や イベントソースマップの batch_size で同時実行数を充分に確保し、Throttle が発生しないように監視をしておくべきだろう。
※10tpsの30連発程度であれば、reserved_concurrent_executions を少し増やせば余裕でリトライは行われなくなった。

また、標準タイプのキューについては、イベントが2回トリガされる可能性があるため、そうなっても問題ないようにLambdaを実装する必要があるのに注意をしなければいけない。

便利な機能ではあるが、チューニング要素をしっかり理解しながら使っていこう。