この記事はPostgreSQL Advent Calendar 2024の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を取って
※ スキーマのみにしているのはデータが含まれているとファイルを開く際に重くなり扱いにくいため
pg_dump -U user -t 問題のテーブル -s -d db_name -f schema_only.sql
テーブル名をコピーとわかるようにしてからrestoreを実行
psql -U user -d db_name -f schema_only.sql
その後にデータをINSERTしてから
INSERT INTO コピーテーブル SELECT * FROM 問題のあるテーブル;
実行計画を確認してみたところなんとPlanning Timeが早いことに気づきました。
問題解消
なぜ新たなテーブルでPlanning Timeが早くなるのかは気になりますが、一旦開発エンジニアが困っているので問題の解消を優先してテーブル自体の入れ替えを次の流れて行いました。
- dumpの取得
pg_dump -U user -t 問題のテーブル -s -d db_name -f 問題のテーブル_schema.sql
- 念の為のバックアップを残しておく
cp 問題のテーブル_schema.sql 問題のテーブル_schema_yyyymmdd.sql
- dumpファイル内のテーブル名を書き換える
CREATE TABLEのテーブル名の他にINDEXにもテーブル名が記載されているので全て書き換える - 問題のテーブルの情報を控える
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ファイルから作成する
psql -U user -d db_name -f 問題のテーブル_schema.sql
- コピーテーブルにデータを入れる
INSERT INTO コピーテーブル_new SELECT * FROM 問題のテーブル;
- 問題テーブルのINDEXをRENAME
ALTER INDEX index_name RENAME TO index_name_old;
- コピーテーブルのINDEXをRENAME
ALTER INDEX index_name_new RENAME TO index_name;
- テーブル名の変更
ALTER TABLE 問題のテーブル RENAME TO 問題のテーブル_old;
ALTER TABLE コピーテーブル_new RENAME TO 問題のテーブル名と同じ名前;
- コピーテーブルの情報を控える
- 差分を確認する
差分がなければ元のテーブルと同じ状態である
diff 問題のテーブル_dt.sql コピーテーブル_dt.sql
diff 問題のテーブル_grants.sql コピーテーブル_grants.sql
原因追及
問題の解消ができたので原因の特定を進めていきます。
Planning Timeが遅いということで統計情報を読むのに時間がかかっていると考えました。統計情報はpg_statisticにあります。
このpg_statisticを参照するのに時間がかかっているのかもと思い試しにn_dead_tupを確認すると異常な数字が返ってきました。
select n_dead_tup from pg_stat_all_tables where relname = 'pg_statistic';
n_dead_tup
------------
4526400
(1 row)
異様に多いのではと思い、ファイルも確認してみました。
以下のSQLを実行してrelidを控えておきます。
select *
from pg_stat_all_tables
where relname in ('pg_statistic');
ファイルのサイズを確認してみたところなんと1Gもありました。
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の故障観点が目から鱗すぎて興奮してしまいその場で気づけなかったです。すみません。。