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

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

# 遅延キューとは
その名の通り、キューイングされてからイベントトリガが引かれるまでの間にタイムラグがあるSQSのことだ。
正に「ちょっとSleepしてからのリトライ処理」をやるには良いのではないだろうか！
詳しくは[AWS公式の開発者ガイド](https://docs.aws.amazon.com/ja_jp/AWSSimpleQueueService/latest/SQSDeveloperGuide/sqs-delay-queues.html)参照。

# 設定方法
マネージメントコンソール画面では以下の黄色蛍光ペンの設定部分にあたる。
![キャプチャ1.png](https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/111314/595af2be-cc33-971e-be78-ef1ff1b9842a.png)

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

```HCL
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``` も重要なチューニング要素になるため、後程説明する。

```HCL
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を起動する場合は、以下のように

```HCL
      "sqs:DeleteMessage",
      "sqs:GetQueueAttributes",
      "sqs:ReceiveMessage",
```

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

```HCL
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と接続をしよう。

```HCL
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)を出力するようにした。

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

```JSON
{
    "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 にしていることだ。

すると、

```CSV
"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を実装する必要があるのに注意をしなければいけない。

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