PostgreSQLでauto_explainを使ってどのクエリが遅いか把握する

ある機能が重いなどといった理由で、DBのどのクエリが遅いか把握したいことはよくあります。そんな時、PostgreSQLのauto_explainが便利だったので紹介。

auto_explainを使うと、指定した実行時間以上を利用しているクエリに対して、自動で実行計画をログファイルに出力してくれるというもの。詳細はこちら。

• https://www.postgresql.jp/document/9.6/html/auto-explain.html
• https://www.postgresql.jp/document/9.6/html/using-explain.html

最近便利に使えたのは以下の設定。

# 自動でEXPLAIN ANALYZEしてパフォーマンス解析したい時用
session_preload_libraries = 'auto_explain'
auto_explain.log_min_duration = 100 # 100ms以上かかっているクエリを自動でEXPLAINする
auto_explain.log_analyze = on # 出力にはEXPLAIN ANALYZEを使う
# 入れ子状の文に対してもEXPLAINする。
# 例えば外部キー制約でCASCADE DELETEなどを使っていた場合、その実行計画も出力する。
auto_explain.log_nested_statements = on
# あるクエリから発行されるトリガの実行計画も一緒に表示してくれる。
# 上記のlog_nested_statementsで実行時間などは分かるのだが、このオプションを有効にしておくと
# どのクエリからトリガが発行されているかひと目で分かって便利。
auto_explain.log_triggers = on

この辺りの設定をpostgresql.confあたりに追加して、重いページでどういうクエリが発行されているか様子見すると、まずはどの辺が悪そうかがざっくり判断できるのでおすすめです。