SequelでPG::ConnectionBad: PQconsumeInput()エラーが出るようになって困った話

# 急に出始めた PG::ConnectionBad: PQconsumeInput() エラー

RailsでActiveRecordを使わずSequelをORMとして使っているのだが、いつからかRails起動直後のRDS（Postgresql）接続時に「PG::ConnectionBad: PQconsumeInput()」エラーが出るようになってしまった。

```
PG::ConnectionBad: PQconsumeInput() SSL error: decryption failed or bad record mac
PG::ConnectionBad: PQconsumeInput() server closed the connection unexpectedly
PG::ConnectionBad: PQconsumeInput() SSL error: sslv3 alert bad record mac
```

Sequel側は変えていないのでRDSで何か仕様変更があったのか・・・。RDSのCA証明書の変更の影響かと思ったが、変更する前から当エラーは出てた。

## 状況

- Rails起動直後にいくつかのリクエストでこのエラーになる。全てではない。
- ある程度エラーが出るとその後は出ない。
- ステージング環境などで8時間くらいアクセスがないとまたでるようになる。
- なので、本番環境ではRails再起動直後だけこのエラーがでる。
- 開発環境のRDSではないPostgresqlだと出ない。

このエラーが出たらretryする仕組みも入れたけど、やはりそもそも出ないようにしたい。

# connection_validatorを試す

真偽はわからないがpumaのようなマルチスレッドのアプリケーションサーバを使っているとこのエラーが出るらしい。Sequelのコネクションプーリングがスレッドセーフではない？

で、色々ググったところ日本語の情報はさっぱりの中、海外のサイトで以下の設定を入れれば解決するらしい情報を入手。

```
DB.extension(:connection_validator)
DB.pool.connection_validation_timeout = -1
```

https://sequel.jeremyevans.net/rdoc-plugins/files/lib/sequel/extensions/connection_validator_rb.html

コネクションプーリング内のコネクションが有効かどうかチェックして、有効でなければ再接続する設定。
`DB.pool.connection_validation_timeout` はチェックする間隔（秒）で、デフォルト3600秒、−1のときは常にチェック。


## connection_validation_timeoutの値を変えて検証
- -1：　エラーが出なくなった！
- 1以上：　起動直後はエラーでる

### 検証結果

`DB.pool.connection_validation_timeout = -1` なら効果あり。
3600で効果出て欲しかったなあ。

## パフォーマンス試験

公式にもあるように、常にチェックだと気になるのがパフォーマンスの劣化。
connection_validatorありなしでApacheBenchでパフォーマンステストしてみた。

### connection_validatorなし

```
$ ab -c 100 -n 10000 "http://xxxxxxxxxx"

Concurrency Level:      100
Time taken for tests:   22.620 seconds
Complete requests:      10000
Failed requests:        0
Total transferred:      15650000 bytes
HTML transferred:       11390000 bytes
Requests per second:    442.09 [#/sec] (mean)
Time per request:       226.196 [ms] (mean)
Time per request:       2.262 [ms] (mean, across all concurrent requests)
Transfer rate:          675.66 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.4      0       5
Processing:     5  226 162.3    178    1102
Waiting:        5  226 162.3    178    1102
Total:          5  226 162.3    178    1102
```

### connection_validatorあり　（connection_validation_timeout = -1）

```
$ ab -c 100 -n 10000 "http://xxxxxxxxxx"

Concurrency Level:      100
Time taken for tests:   26.522 seconds
Complete requests:      10000
Failed requests:        0
Total transferred:      15650000 bytes
HTML transferred:       11390000 bytes
Requests per second:    377.05 [#/sec] (mean)
Time per request:       265.216 [ms] (mean)
Time per request:       2.652 [ms] (mean, across all concurrent requests)
Transfer rate:          576.26 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.1      0       2
Processing:    10  264 157.8    231    1126
Waiting:       10  264 157.8    231    1126
Total:         10  264 157.9    231    1126
```

（結果は3回試して一番良かった結果）

### テスト結果

1リクエストあたり約40ms遅くなった。

# 結論

超絶負荷のかかる様なサーバではないので、40msのパフォーマンス劣化は許容範囲としてconnection_validatorを採用することにした。
auto_reconnectオプションとかあれば良いのに。