【パフォーマンスチューニング】謎にPlanning Timeが遅くなるのを解消した話

この記事は[PostgreSQL Advent Calendar 2024](https://qiita.com/advent-calendar/2024/postgresql)の13日目の記事です。是非とも他の記事も読んでみてください！

## 自己紹介
息子大好きDBエンジニアのだいちです。
今回は実務の中で行ったパフォーマンスチューニングが個人的にレアな事象だったので何かしらの知見になればと思い纏めていきます。

## 誰向けの話なのか
今回の話は次のような人に読んでいただけると参考になると思います。
- PostgreSQLを活用している
- チューニングの知見を深めたい
- 原因特定のフローを知りたい

原因と思われることはかなり稀なのかと思うのですが、そこに至るまでの経緯については状況関係なく参考になるかと思いますのでぜひと最後まで読んでみてください。


## 環境情報
検証環境A
- EC2
- PostgreSQL 12系

検証環境B（問題のある環境）
- EC2
- PostgreSQL 12系

踏み台サーバ
- EC2
※ SQLの実行は基本的に踏み台からDBに入って実行しています。

## 問題発覚
開発エンジニアにてブラウザから操作をした際に検証環境BではAと比べて格段に遅いという状況に気づきました。
開発エンジニア側で調べられることを調べてまず初めはEC2やEBSの設定値の相違があったので検証環境Bの設定をAに合わせてみました。
状況は変わらずDBが遅いのではということで話がきてこちらでの調査を進めました。


## 原因特定
結論としてはタイトルにある通り、対象のSQLのPlanning Timeが検証環境Aでは早くBでは遅くなることに気づきました。
単純に利用しているSQLにEXPLAINコマンドを追加して両環境で実行して見比べてみました。
次になんで遅くなるのかを考えましたが
先に調べたのはパラメーター設定です。両環境のpostgresql.confを見比べて相違があったので検証環境BをAに合わせて再起動を行いました。
結果は変わらず、なぜ遅くなるのかわからない状況が続いてました。

その次に試したのはVACUUMとANALYZE、REINDEXでした。
VACUUM FULLでも何も変わらなかったのでこの時はほんと何がなんだかわからない状況に陥りました。

対象のSQLはいくつかのテーブルを結合して利用していたのでテーブル単体で実行計画を確認することをしました。
すると一つのテーブル（以下：問題のテーブル）だけ以上にPlanning Timeに時間がかかることに気づき問題のテーブルに注目しました。

まずはデータ量ですが、多くても数千件しか入っていなかったのですが
念の為検証環境Aに件数を合わせて確認してみましたが何も変わりません。

問題のテーブルはテーブルそのものに問題があるのかを明確にするために問題のテーブルをコピーしてみました。
問題のテーブルに対してスキーマのみのdumpを取って
※ スキーマのみにしているのはデータが含まれているとファイルを開く際に重くなり扱いにくいため
``` shell
pg_dump -U user -t 問題のテーブル -s -d db_name -f schema_only.sql
```

テーブル名をコピーとわかるようにしてからrestoreを実行
``` shell
psql -U user -d db_name -f schema_only.sql
```
その後にデータをINSERTしてから
``` sql
INSERT INTO コピーテーブル SELECT * FROM 問題のあるテーブル;
```
実行計画を確認してみたところなんとPlanning Timeが早いことに気づきました。


## 問題解消
なぜ新たなテーブルでPlanning Timeが早くなるのかは気になりますが、一旦開発エンジニアが困っているので問題の解消を優先してテーブル自体の入れ替えを次の流れて行いました。

- dumpの取得
``` bash
pg_dump -U user -t 問題のテーブル -s -d db_name -f 問題のテーブル_schema.sql
```
- 念の為のバックアップを残しておく
``` bash
cp 問題のテーブル_schema.sql 問題のテーブル_schema_yyyymmdd.sql
```
- dumpファイル内のテーブル名を書き換える
`CREATE TABLE`のテーブル名の他にINDEXにもテーブル名が記載されているので全て書き換える
- 問題のテーブルの情報を控える
``` bash
psql -U user -d db_name -c "\d 問題のテーブル" > 問題のテーブル_dt.sql

psql -U user -d db_name -c "SELECT grantee, table_catalog, table_schema, table_name, privilege_type FROM information_schema.role_table_grants WHERE table_name = '問題のテーブル';" > 問題のテーブル_grants.sql
```
- コピーテーブルをdumpファイルから作成する
``` bash
psql -U user -d db_name -f 問題のテーブル_schema.sql
```
- コピーテーブルにデータを入れる
``` bash
INSERT INTO コピーテーブル_new SELECT * FROM 問題のテーブル;
```
- 問題テーブルのINDEXをRENAME
``` bash
ALTER INDEX index_name RENAME TO index_name_old;
```
- コピーテーブルのINDEXをRENAME
``` sql
ALTER INDEX index_name_new RENAME TO index_name;
```
- テーブル名の変更   
``` sql
ALTER TABLE 問題のテーブル RENAME TO 問題のテーブル_old;
```
``` sql
ALTER TABLE コピーテーブル_new RENAME TO 問題のテーブル名と同じ名前;
```
- コピーテーブルの情報を控える
- 差分を確認する
差分がなければ元のテーブルと同じ状態である
``` bash
diff 問題のテーブル_dt.sql コピーテーブル_dt.sql
diff 問題のテーブル_grants.sql コピーテーブル_grants.sql
```


## 原因追及
問題の解消ができたので原因の特定を進めていきます。
Planning Timeが遅いということで統計情報を読むのに時間がかかっていると考えました。統計情報は`pg_statistic`にあります。

この`pg_statistic`を参照するのに時間がかかっているのかもと思い試しに`n_dead_tup`を確認すると異常な数字が返ってきました。
``` sql
select n_dead_tup from pg_stat_all_tables where relname = 'pg_statistic';
 n_dead_tup
------------
    4526400
(1 row)
```

異様に多いのではと思い、ファイルも確認してみました。
以下のSQLを実行して`relid`を控えておきます。
``` sql
select *
from   pg_stat_all_tables
where  relname in ('pg_statistic');
```
ファイルのサイズを確認してみたところなんと1Gもありました。
``` bash
ll -h $PGDATA/base/DBのOID/pg_statisticのrelid
```
以上の状況から不要なタプルも読み込んでしまいPlanningに時間がかかってしまっているのではと仮説を立てました。

`pg_statistic`に対してはAUTO VACUUMがかかっていることは確認できているのですがなぜか`n_dead_tup`は減らない状況、また`n_tup_hot_upd`が検証環境Aと比べて活用されていないのも気になっています。

ここまで調べたましたが`pg_statistic`はシステムカタログなので管理者から色々と操作するのはできない＆別の理由から対応はここまでとしました。
検証環境だったのがせめてもの救いだったなと今となっては感じています。

## 終わりに
綺麗な解決とまではいけませんでしたが、貴重な経験ができたので自分自身の知見が深まったと感じています。
もしも似たような状況になったことがある人いたらぜひともコメントで教えてください。

実を言うと今回の件は先日行われたPostgreSQL カンファレンスの懇親会の中で有識者の方々に相談してたくさんの知見をいただいたこともあり調査をする幅が広がったと感じています。この場で名前を載せるのは迷惑になるかもなので伏せますが相談に乗ってくれた方々へ本当にありがとうございました。

P.S.
EBSの故障と言う件ですが、ストリーミングレプリケーション構成にしていて2台のEC2にそれぞれPostgresが入っている状態でそれぞれに対してSQLを実行してもPlanning Timeが遅かったので故障という線は薄くなりました！EBSが別なので。
ストリーミングのことを伝えてなかったかつ、自分もEBSの故障観点が目から鱗すぎて興奮してしまいその場で気づけなかったです。すみません。。