Ruby on JetsとRDBを組み合わせた場合のコネクションの使われ方を検証してみた

一般的にAWS LambdaとRDS(RDB)は相性が悪いと言われています。
その理由の一つは「Lambdaのスケールアウトに伴いRDSへのコネクションが増加し、**最悪の場合コネクション枯渇するため** 」です。

<img width="991" alt="Ruby_on_Jets___The_Ruby_Serverless_Framework.png" src="https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/60996/e05e20a4-79f1-191f-d083-f0b2d0dfec70.png">


この問題はLambdaを多用するRuby on Jetsでも同じだと思っていましたが、
Ruby on JetsのDocumentには以下のような記載があります。

https://rubyonjets.com/docs/database/activerecord/

> On AWS Lambda, there’s something called the Lambda Execution Context. The Lambda Execution Context gets reused between lambda function runs. Jets establishes the DB connection within the Lambda Execution Context outside the handler. So DB connections get reused between subsequent lambda function runs. This prevents DB connections from ever-increasing. The AWS docs specifically point out to use the Lambda Execution Context for things like establishing DB connections.

要約すると「[Lambda実行コンテキスト](https://docs.aws.amazon.com/ja_jp/lambda/latest/dg/running-lambda-code.html)を使うことでコネクションを使いまわし、コネクションが増加することを防ぎます」ということです。

実際のところコネクションはどのように使い回されるのか、検証してみました。

## 検証環境

以下記事でAWSへデプロイしたアプリケーションを活用します。

[Rubyのサーバレスフレームワーク「Ruby on Jets」を使ってAWSへアプリケーションをデプロイする](https://qiita.com/Y_uuu/items/9d4c7c2c8df0b856f6f8)

## 検証方法

今回の検証では[hey](https://github.com/rakyll/hey)というgolang製のCLIを使用します。
以下のようなコマンドをローカルマシンで実行することで、指定した並列数で指定した回数のリクエストを出すことができます。

```
$ hey -c (並列数) -n (実行数) https://(ホスト名)/posts
```

コネクション数はCloudWatchのDatabaseConnectionsというメトリクスで確認することとします。

## 検証実施

### 10並列で10回リクエスト

手始めに10並列から始めてみることにしました。

```
$ hey -c 10 -n 10 https://y2ew64ccd4.execute-api.ap-northeast-1.amazonaws.com/dev/posts

Summary:
  Total:	3.0347 secs
  Slowest:	3.0346 secs
  Fastest:	0.2670 secs
  Average:	2.6873 secs
  Requests/sec:	3.2952

  Total data:	16090 bytes
  Size/request:	1609 bytes

Response time histogram:
  0.267 [1]	|■■■■
  0.544 [0]	|
  0.821 [0]	|
  1.097 [0]	|
  1.374 [0]	|
  1.651 [0]	|
  1.928 [0]	|
  2.204 [0]	|
  2.481 [0]	|
  2.758 [0]	|
  3.035 [9]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■


Latency distribution:
  10% in 2.9394 secs
  25% in 2.9424 secs
  50% in 2.9449 secs
  75% in 2.9680 secs
  90% in 3.0346 secs
  0% in 0.0000 secs
  0% in 0.0000 secs

Details (average, fastest, slowest):
  DNS+dialup:	0.1575 secs, 0.2670 secs, 3.0346 secs
  DNS-lookup:	0.0553 secs, 0.0537 secs, 0.0570 secs
  req write:	0.0001 secs, 0.0001 secs, 0.0003 secs
  resp wait:	2.5293 secs, 0.1207 secs, 2.8786 secs
  resp read:	0.0001 secs, 0.0001 secs, 0.0003 secs

Status code distribution:
  [200]	10 responses
```

実行結果はいずれも200で特に問題無さそうです。

しかし、CloudWatchでDBのコネクションを確認したところ、10まで増加していました。

やはり、 **Lambdaの同時実行数分はコネクションを張る** ことがわかりました。
一方で、 **LambdaのコンテナがSTOPするまでコネクションが張られっぱなし** という状況なので、
次のリクエストではコネクションを使いまわしてくれるかもしれません。

<img width="797" alt="RDS_·_AWS_Console.png" src="https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/60996/b4dc9107-197f-6b76-96d7-ea6279b1d86d.png">

### 10並列で100回リクエスト

今度はリクエスト数を増やして、検証してみます。

```
$ hey -c 10 -n 100 https://y2ew64ccd4.execute-api.ap-northeast-1.amazonaws.com/dev/posts

Summary:
  Total:	4.1221 secs
  Slowest:	2.9957 secs
  Fastest:	0.0878 secs
  Average:	0.2688 secs
  Requests/sec:	24.2597

  Total data:	160900 bytes
  Size/request:	1609 bytes

Response time histogram:
  0.088 [1]	|
  0.379 [94]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.669 [0]	|
  0.960 [0]	|
  1.251 [0]	|
  1.542 [0]	|
  1.833 [0]	|
  2.123 [0]	|
  2.414 [0]	|
  2.705 [0]	|
  2.996 [5]	|■■


Latency distribution:
  10% in 0.1039 secs
  25% in 0.1119 secs
  50% in 0.1216 secs
  75% in 0.1325 secs
  90% in 0.2468 secs
  95% in 2.9185 secs
  99% in 2.9957 secs

Details (average, fastest, slowest):
  DNS+dialup:	0.0126 secs, 0.0878 secs, 2.9957 secs
  DNS-lookup:	0.0030 secs, 0.0000 secs, 0.0309 secs
  req write:	0.0000 secs, 0.0000 secs, 0.0002 secs
  resp wait:	0.2558 secs, 0.0875 secs, 2.8686 secs
  resp read:	0.0002 secs, 0.0001 secs, 0.0039 secs

Status code distribution:
  [200]	100 responses
```

実行結果はいずれも200で問題なし。
Lambdaのコンテナが立ち上がっていたためかレスポンスまでの時間が速いですね。

コネクション数は10でした。
つまり、 **リクエストを逐次実行する場合には前のコネクションを使いまわしてくれている** ことがわかります。

<img width="780" alt="RDS_·_AWS_Console.png" src="https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/60996/d1ebdded-b714-1e3a-2a6b-138994d61fed.png">

### 100並列で100回リクエスト

最後に100並列で100リクエストを実行してみました。
検証に使用しているRDSは `t2.micro` なのでおそらく **100並列できずにコネクションが枯渇する** はずです。

```
$ hey -c 100 -n 100 https://y2ew64ccd4.execute-api.ap-northeast-1.amazonaws.com/dev/posts

Summary:
  Total:	5.8446 secs
  Slowest:	5.8292 secs
  Fastest:	0.3307 secs
  Average:	3.0235 secs
  Requests/sec:	17.1097

  Total data:	146743 bytes
  Size/request:	1467 bytes

Response time histogram:
  0.331 [1]	|■
  0.881 [18]	|■■■■■■■■■■■■■■■■■■
  1.430 [0]	|
  1.980 [0]	|
  2.530 [0]	|
  3.080 [6]	|■■■■■■
  3.630 [32]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  4.180 [40]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  4.730 [0]	|
  5.279 [0]	|
  5.829 [3]	|■■■


Latency distribution:
  10% in 0.3975 secs
  25% in 3.1703 secs
  50% in 3.5691 secs
  75% in 3.7160 secs
  90% in 3.7609 secs
  95% in 3.7784 secs
  99% in 5.8292 secs

Details (average, fastest, slowest):
  DNS+dialup:	0.2313 secs, 0.3307 secs, 5.8292 secs
  DNS-lookup:	0.0392 secs, 0.0350 secs, 0.0466 secs
  req write:	0.0001 secs, 0.0000 secs, 0.0004 secs
  resp wait:	2.7916 secs, 0.1158 secs, 5.6134 secs
  resp read:	0.0002 secs, 0.0000 secs, 0.0018 secs

Status code distribution:
  [200]	91 responses
  [502]	9 responses
```

いくつか502(Bad Gateway)が返ってきました。

コネクション数は82で頭打ちとなっていました。

<img width="802" alt="RDS_·_AWS_Console.png" src="https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/60996/d28e7223-bc20-af90-48f3-b8ff2097accf.png">

### Lambdaの同時実行数を10として100並列で100回リクエスト

AWS Lambdaの設定に「同時実行数」というものがあるので、これを10に設定しました。

<img width="361" alt="Lambda_Management_Console.png" src="https://qiita-image-store.s3.ap-northeast-1.amazonaws.com/0/60996/5b939eaa-9042-3fea-4cc8-109e0288c325.png">

[同時実行数を設定しても冪等性を確保できるとは限らない](https://medium.com/@itooww/lambda-%E9%96%A2%E6%95%B0%E3%81%AE%E5%90%8C%E6%99%82%E5%AE%9F%E8%A1%8C%E6%95%B0%E3%82%921%E3%81%AB%E3%81%97%E3%81%A6%E3%82%82%E5%86%AA%E7%AD%89%E6%80%A7%E3%81%AE%E6%8B%85%E4%BF%9D%E3%81%8B%E3%82%89%E9%80%83%E3%82%8C%E3%82%8B%E3%81%93%E3%81%A8%E3%81%AF%E5%87%BA%E6%9D%A5%E3%81%AA%E3%81%84-24a7e414933d)とのことですが、
Lambdaの同時起動を抑制できればコネクションの枯渇は回避できるかもしれません。


```
$ hey -c 100 -n 100 https://y2ew64ccd4.execute-api.ap-northeast-1.amazonaws.com/dev/posts

Summary:
  Total:	0.3776 secs
  Slowest:	0.3767 secs
  Fastest:	0.3097 secs
  Average:	0.3345 secs
  Requests/sec:	264.8057

  Total data:	19330 bytes
  Size/request:	193 bytes

Response time histogram:
  0.310 [1]	|■■
  0.316 [6]	|■■■■■■■■■■
  0.323 [13]	|■■■■■■■■■■■■■■■■■■■■■■■
  0.330 [23]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.337 [20]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.343 [11]	|■■■■■■■■■■■■■■■■■■■
  0.350 [17]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.357 [2]	|■■■
  0.363 [2]	|■■■
  0.370 [1]	|■■
  0.377 [4]	|■■■■■■■


Latency distribution:
  10% in 0.3178 secs
  25% in 0.3251 secs
  50% in 0.3326 secs
  75% in 0.3438 secs
  90% in 0.3497 secs
  95% in 0.3680 secs
  99% in 0.3767 secs

Details (average, fastest, slowest):
  DNS+dialup:	0.2676 secs, 0.3097 secs, 0.3767 secs
  DNS-lookup:	0.0030 secs, 0.0012 secs, 0.0035 secs
  req write:	0.0001 secs, 0.0000 secs, 0.0003 secs
  resp wait:	0.0667 secs, 0.0404 secs, 0.1289 secs
  resp read:	0.0001 secs, 0.0000 secs, 0.0004 secs

Status code distribution:
  [200]	10 responses
  [500]	90 responses
```

残念ながら同時実行数を超えたリクエストは、キューイングされずに500を返すようです。

## まとめ

Ruby on JetsとRDS(RDB)を組み合わせて使う場合に考慮すべきことは以下の通りです。

- 同時実行数分のコネクションが張られることを留意する必要がある
- 同時実行されなければコネクションは使い回される
- Lambdaの初回起動には若干(検証では3秒前後)の時間がかかる
- Lambdaの同時実行数を超えたリクエストはキューイングされずに500を返す

少し残念な結果となってしまいましたが、これさえ留意しておけば運用に耐えうるものにはできそうです。