Aurora PostgreSQL 互換版（9.6.9）のキャッシュについて追加で確かめてみた

これは **[インフラ勉強会 Advent Calendar 2018](https://qiita.com/advent-calendar/2018/infra-workshop)** 9 日目の記事です。

昨日は wannabe さんでした。

---

インフラ勉強会とのかかわりについては、**[Adventar のカレンダーの今日の記事](https://hmatsu47.qrunch.io/entries/cVjx95r2B5o5nnnS)**として書いていますので、こちらでは省略します。

さて、インフラ勉強会でかかわりのある方々から、わたしは「DB の人」と認識されているような気がするので、DB ネタでカレンダーを埋めたいと思います（まあ、Qiita にはほとんど DB か AWS のことしか書いていないわけですが）。

**[PostgreSQL Advent Calendar 2018](https://qiita.com/advent-calendar/2018/postgresql)** 7 日目で書いたことの続きにあたります。

# Amazon Aurora とは

インフラ勉強会のカレンダーの記事ですので、ちょっとだけ説明を。

Amazon Aurora は、AWS が提供する RDBMS のマネージドサービス（ミドルウェアをユーザが管理しなくていいやつ）で、簡単に言うと、

 * オープンソースの RDBMS と互換性がある
   * MySQL 5.6
   * MySQL 5.7
   * PostgreSQL 9.6
   * PostgreSQL 10（これを書いている現在、まだ東京リージョンでは使えません）
 * 並列性を重視：多数のクライアントが同時に接続し、クエリ／コマンドを投げても速度が落ちにくい設計
 * データを複数のアベイラビリティゾーン（データセンター群）に多重保管することで、データロストが発生しづらい構成

という特徴があります。

 * **[Amazon Aurora 製品の詳細](https://aws.amazon.com/jp/rds/aurora/details/)（AWS）**

わたしは普段 MySQL 5.6 互換を使っているのですが、諸事情（というほどのことでもない）で PostgreSQL 9.6 互換版について調べることになりました。

---

**12/25追記：**
この件（1 つ前の記事も含む）についてまとめて某所の LT で発表したときのスライドがこちらです。

 * **[Aurora PostgreSQL をちょっとだけ（12/12 の某所 LT）](https://speakerdeck.com/hmatsu47/jaws-n-20181212)（Speaker Deck）**

話の全体像はこのスライドを見ていただいたほうがわかりやすいです。

---

# この記事で確かめること

 * **[Aurora PostgreSQL 互換版（9.6.9）でフェイルオーバー時にバッファ／キャッシュの生きのこり方を雑に確かめてみた](https://qiita.com/hmatsu47/items/16b8d3e1eaff9e5a6247)**

Aurora の特徴として、**「フェイルオーバーしてもメモリ上のバッファ／キャッシュが消えない」**があるので、実際に確かめてみましたが、

 * 確かに共有バッファ（PostgreSQL が管理しているキャッシュのようなもの）は消えない
 * OS のディスクキャッシュは消えたのか消えていないのかよくわからない
 * そもそも OS のディスクキャッシュって効いてるの？

という、中途半端な結果に終わりました。

そのため、今回は

 * 比較対象として、EC2 の r4.large インスタンスを立てる
 * 本家の PostgreSQL 9.6（Aurora にできるだけ近いバージョンでパッケージインストール可能な 9.6.11）をインストール
 * この環境で前回同様のクエリを流してみる
    * 1 行の容量は確認しやすいように調整
 * 以下のパターンでクエリの所要時間を確認

| パターン | 共有バッファ | OS ディスクキャッシュ |
|:-:|:-:|:-:|
| １ | 載っている | 載っている |
| ２ | 載っていない | 載っている |
| ３ | 載っている | 載っていない |
| ４ | 載っていない | 載っていない |

 * Aurora で以下のケースの所要時間を確認（本家と比較）
   * `INSERT`直後の`EXPLAN`
   * 別の大きな行の`INSERT`後（共有バッファから追い出された状態）の`EXPLAIN`

※Aurora は念のため 2 行共有バッファに溜めてから追い出して平均値を取る

をやってみて、Aurora の OS ディスクキャッシュが有効なのかどうかを推測してみます。

そして、もし有効なようなら、あらためてフェイルオーバーして確認してみます。

# 結果

いきなりですが、過程が長いので結果を先に示します（過程は後ろのほうに記しておきます）。

 * 本家 PostgreSQL（9.6.11）

| パターン | 共有バッファ | OS ディスクキャッシュ | 所要時間 (ms) |
|:-:|:-:|:-:|--:|
| １ | 載っている | 載っている | 318.185 |
| ２ | 載っていない | 載っている | 350.233 |
| ３ | 載っている | 載っていない | 319.678 |
| ４ | 載っていない | 載っていない | 1207.248 |

共有バッファに載っている状態と OS ディスクキャッシュのみに載っている状態の差は小さいことがわかります。

 * Aurora（2 行分の平均値）

| パターン | 所要時間 (ms) |
|:-:|--:|
| 共有バッファに載っている状態 | 367.668 |
| 共有バッファから追い出された状態 | 21,336.373 |

共有バッファに載っているときの所要時間は誤差の範囲とも言えますが、共有バッファから追い出したときの所要時間は、**明らかに「ストレージノードからデータを取り直している」**ことがわかるほど遅くなっています。

つまり、この結果を見る限りでは、

**「Aurora PostgreSQL 9.6 互換版では OS のディスクキャッシュは効いていない」**

ということになります。

**MySQL 互換版で言うところの「バッファプール（バッファキャッシュ）とストレージノードの関係」と、PostgreSQL 互換版での「共有バッファとストレージノードの関係」がほぼ同じ**、と推測できます。本家 PostgreSQL で「活用」されていた OS のディスクキャッシュの層が存在しない（のと同じ）ことになりますね。

ちょっと意外、でした。

~~並列数の低い低負荷な状況では、MySQL 互換版以上に「Aurora のほうが遅いケース」が出そうですね。~~

---

**12/10 追記：**

…と思っていましたが、**パラメータグループの`shared_buffers`の初期値が「全メモリ容量の 1/4」ではない**ことに気付き（RDS の約 3 倍、全メモリ容量の 3/4）、資料を漁ってみたところ出てきました。

 * **[Deep Dive on the Amazon Aurora PostgreSQL-compatible Edition - DAT402 - re:Invent 2017](https://www.slideshare.net/AmazonWebServices/deep-dive-on-the-amazon-aurora-postgresqlcompatible-edition-dat402-reinvent-2017)（SlideShare）**

29 ～ 30 ページのところです。**「No Double Buffering」**と書いてあります。なーんだ。

※今年の re:Invent の**「GPSCT406:Migrate from Oracle to Aurora PostgreSQL: Best Practices, Design Patterns, & Setup」**でも触れられていた可能性があります（資料はまだ見つからず）。

でも、PostgreSQL の共有バッファが「全メモリ容量の 1/4 程度にとどめたほうが良い」のはバッファの管理機構の問題（増やしすぎても性能が上がらない）だったはずなので、この部分の PostgreSQL オリジナルのコードになにか手が入っているのでしょうか？

---

10 日目は、いまのところ誰も入れていません（残念！）。次は来週？

---

# 補足資料：操作の流れ

## 本家 PostgreSQL／テーブル準備

```sql:テーブル準備
sb_test=# \timing
Timing is on.
sb_test=# SHOW shared_buffers;
 shared_buffers
----------------
 256MB
(1 row)

Time: 0.470 ms
sb_test=# CREATE TABLE txt (id INT PRIMARY KEY, txt TEXT);
CREATE TABLE
Time: 8.303 ms
sb_test=# ALTER TABLE txt ALTER txt SET STORAGE EXTERNAL;
ALTER TABLE
Time: 1.024 ms
```

## パターン１

```sql:パターン１
sb_test=# INSERT INTO txt VALUES(1, REPEAT(md5(clock_timestamp()::text), 3000000));
INSERT 0 1
Time: 1065.240 ms
sb_test=# EXPLAIN (ANALYZE true, BUFFERS true) SELECT id, md5(txt) FROM txt WHERE id = 1;
                                                    QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
 Index Scan using txt_pkey on txt  (cost=0.15..8.17 rows=1 width=36) (actual time=316.782..317.159 rows=1 loops=1)
   Index Cond: (id = 1)
   Buffers: shared hit=12160 dirtied=1
 Planning time: 0.313 ms
 Execution time: 317.198 ms
(5 rows)

Time: 318.185 ms
```

## パターン２

```sql:パターン２（共有バッファ追い出し）
sb_test=# INSERT INTO txt VALUES(2, REPEAT(md5(clock_timestamp()::text), 10000000));
INSERT 0 1
Time: 10668.244 ms
sb_test=# EXPLAIN (ANALYZE true, BUFFERS true) SELECT id, md5(txt) FROM txt WHERE id = 2;
                                                     QUERY PLAN
---------------------------------------------------------------------------------------------------------------------
 Index Scan using txt_pkey on txt  (cost=0.15..8.17 rows=1 width=36) (actual time=1087.416..1088.455 rows=1 loops=1)
   Index Cond: (id = 2)
   Buffers: shared hit=26006 read=14518 written=96
 Planning time: 0.061 ms
 Execution time: 1088.480 ms
(5 rows)

Time: 1088.901 ms
```
```sql:パターン２（EXPLAIN）
sb_test=# EXPLAIN (ANALYZE true, BUFFERS true) SELECT id, md5(txt) FROM txt WHERE id = 1;
                                                    QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
 Index Scan using txt_pkey on txt  (cost=0.15..8.17 rows=1 width=36) (actual time=349.374..349.736 rows=1 loops=1)
   Index Cond: (id = 1)
   Buffers: shared hit=4 read=12157 written=36
 Planning time: 0.070 ms
 Execution time: 349.817 ms
(5 rows)

Time: 350.233 ms
```

## パターン３

```bash:パターン３（キャッシュ消去）
# free
              total        used        free      shared  buff/cache   available
Mem:       15491044      181860    14321352      297204      987832    14708104
Swap:             0           0           0
# sync ; echo 3 > /proc/sys/vm/drop_caches
# free
              total        used        free      shared  buff/cache   available
Mem:       15491044      173748    14948396      297204      368900    14799408
Swap:             0           0           0
```
```sql:パターン３（EXPLAIN）
sb_test=# EXPLAIN (ANALYZE true, BUFFERS true) SELECT id, md5(txt) FROM txt WHERE id = 1;
                                                    QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
 Index Scan using txt_pkey on txt  (cost=0.15..8.17 rows=1 width=36) (actual time=319.229..319.650 rows=1 loops=1)
   Index Cond: (id = 1)
   Buffers: shared hit=12160 read=1
 Planning time: 0.061 ms
 Execution time: 319.678 ms
(5 rows)

Time: 320.197 ms
```

## パターン４

```sql:パターン４（共有バッファ追い出し）
sb_test=# EXPLAIN (ANALYZE true, BUFFERS true) SELECT id, md5(txt) FROM txt WHERE id = 2;
                                                     QUERY PLAN
---------------------------------------------------------------------------------------------------------------------
 Index Scan using txt_pkey on txt  (cost=0.15..8.17 rows=1 width=36) (actual time=3264.515..3265.563 rows=1 loops=1)
   Index Cond: (id = 2)
   Buffers: shared hit=9 read=40515 written=12530
 Planning time: 0.061 ms
 Execution time: 3265.590 ms
(5 rows)

Time: 3266.017 ms
```
```bash:パターン４（キャッシュ消去）
# free
              total        used        free      shared  buff/cache   available
Mem:       15491044      173608    14612100      297204      705336    14726748
Swap:             0           0           0
# sync ; echo 3 > /proc/sys/vm/drop_caches
# free
              total        used        free      shared  buff/cache   available
Mem:       15491044      173900    14948584      297204      368560    14799632
Swap:             0           0           0
```
```sql:パターン４（EXPLAIN）
sb_test=# EXPLAIN (ANALYZE true, BUFFERS true) SELECT id, md5(txt) FROM txt WHERE id = 1;
                                                     QUERY PLAN
---------------------------------------------------------------------------------------------------------------------
 Index Scan using txt_pkey on txt  (cost=0.15..8.17 rows=1 width=36) (actual time=1206.813..1207.216 rows=1 loops=1)
   Index Cond: (id = 1)
   Buffers: shared hit=3 read=12158
 Planning time: 0.109 ms
 Execution time: 1207.248 ms
(5 rows)

Time: 1207.711 ms
```

## Aurora

```sql:Aurora準備
sb_test=> \timing
Timing is on.
sb_test=> CREATE TABLE txt (id INT PRIMARY KEY, txt TEXT);
CREATE TABLE
Time: 128.611 ms
sb_test=> ALTER TABLE txt ALTER txt SET STORAGE EXTERNAL;
ALTER TABLE
Time: 5.327 ms
```
```sql:Aurora共有バッファ上
sb_test=> INSERT INTO txt VALUES(3, REPEAT(md5(clock_timestamp()::text), 3000000));
INSERT 0 1
Time: 1400.081 ms
sb_test=> INSERT INTO txt VALUES(4, REPEAT(md5(clock_timestamp()::text), 3000000));
INSERT 0 1
Time: 1412.131 ms
sb_test=> EXPLAIN (ANALYZE true, BUFFERS true) SELECT id, md5(txt) FROM txt WHERE id = 3;
                                                    QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
 Index Scan using txt_pkey on txt  (cost=0.15..8.17 rows=1 width=36) (actual time=352.236..355.310 rows=1 loops=1)
   Index Cond: (id = 3)
   Buffers: shared hit=12160
 Planning time: 19.191 ms
 Execution time: 355.337 ms
(5 rows)

Time: 388.222 ms
sb_test=> EXPLAIN (ANALYZE true, BUFFERS true) SELECT id, md5(txt) FROM txt WHERE id = 4;
                                                    QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
 Index Scan using txt_pkey on txt  (cost=0.15..8.17 rows=1 width=36) (actual time=341.066..344.112 rows=1 loops=1)
   Index Cond: (id = 4)
   Buffers: shared hit=12160
 Planning time: 0.053 ms
 Execution time: 344.134 ms
(5 rows)

Time: 347.114 ms
```
```sql:Aurora共有バッファ追い出し
sb_test=> INSERT INTO txt VALUES(5, REPEAT(md5(clock_timestamp()::text), 10000000));
INSERT 0 1
Time: 4530.795 ms
```
```sql:Aurora共有バッファ追い出し後
sb_test=> EXPLAIN (ANALYZE true, BUFFERS true) SELECT id, md5(txt) FROM txt WHERE id = 3;
                                                      QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------
 Index Scan using txt_pkey on txt  (cost=0.15..8.17 rows=1 width=36) (actual time=21436.238..21439.674 rows=1 loops=1)
   Index Cond: (id = 3)
   Buffers: shared hit=4 read=12157
 Planning time: 0.055 ms
 Execution time: 21439.695 ms
(5 rows)

Time: 21442.846 ms
sb_test=> EXPLAIN (ANALYZE true, BUFFERS true) SELECT id, md5(txt) FROM txt WHERE id = 4;
                                                      QUERY PLAN
-----------------------------------------------------------------------------------------------------------------------
 Index Scan using txt_pkey on txt  (cost=0.15..8.17 rows=1 width=36) (actual time=21223.353..21226.846 rows=1 loops=1)
   Index Cond: (id = 4)
   Buffers: shared hit=14 read=12403
 Planning time: 0.076 ms
 Execution time: 21226.868 ms
(5 rows)

Time: 21229.899 ms
```