PostgreSQL 実践講座 #3 性能診断のルーチン — pg_stat_statements で遅いクエリを見つける

インフラ PostgreSQL データベース
読了 4分

基礎第 5 回の EXPLAIN は「このクエリがなぜ遅いのか」に答えます。ところが実務の質問は一歩手前から来ます。「DB が遅いのだが、どのクエリが問題なのか。」サーバー全体が遅い場合の一般的なボトルネック探しはサーバーが遅い理由シリーズで扱ったので、今回はその中の DB 層を PostgreSQL の道具で掘り下げるルーチンです。

いま: pg_stat_activity #

「いまこの瞬間、DB で何が起きているか」の答えは pg_stat_activity ビューです。前回、コネクションの状態を数えるときにすでに使いました。

pg_stat_activityの確認 
SELECT pid, state, wait_event_type, wait_event,
       now() - query_start AS running_for,
       left(query, 60) AS query
FROM pg_stat_activity
WHERE state != 'idle'
ORDER BY running_for DESC;

読むポイントは 3 つです。長く走っているクエリ(running_for が大きい行)、待っているクエリ(wait_event_type が Lock ならロック待ち。実践第 6 回の領域)、そして見落としやすい idle in transaction です。トランザクションを開いたまま何もしていない状態で、ロックを握ったままかもしれず、VACUUM の掃除も妨げます(実践第 5 回で再会します)。アプリケーションがトランザクションを開いて外部 API を待つコードが典型的な犯人です。

累積: pg_stat_statements #

瞬間のスナップショットでは「ときどき遅い」問題は捕まえられません。累積統計が必要で、その標準が pg_stat_statements 拡張です。同じ形のクエリ(パラメータだけ違う)を 1 つにまとめて、呼び出し回数と時間を集計し続けてくれます。

pg_stat_statements上位10件 
-- postgresql.conf: shared_preload_libraries = 'pg_stat_statements' の後、再起動
CREATE EXTENSION pg_stat_statements;

-- 合計時間の上位 10 個
SELECT calls,
       round(total_exec_time::numeric / 1000, 1) AS total_sec,
       round(mean_exec_time::numeric, 2)         AS mean_ms,
       rows,
       left(query, 60) AS query
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 10;

再起動が必要な拡張なので、前もって有効にしておくことが重要です(障害が起きた後に有効にしても、その日のデータはありません)。マネージドサービスでは、たいていパラメータグループで有効にできます。

合計上位と平均上位は別々の犯人です #

ソートの基準によって、違う問題が見えます。

  • total_exec_time 上位: DB のリソースを一番使っているクエリです。平均 2ms でも毎秒数百回呼ばれれば 1 位になります。DB 全体の負荷を下げたいならここから見ます。改善はクエリチューニングだけでなく「呼ぶ回数を減らす」(キャッシュ、N+1 の解消)の場合も多いです。
  • mean_exec_time 上位: 1 回が遅いクエリです。ユーザーが「この画面が遅い」と感じるのはたいていこちらです。ここで出てきたクエリを EXPLAIN ANALYZE に持っていくのが、基礎編とのつなぎ目です。

rows / calls(呼び出しあたりの行数)も眺めておく価値があります。呼び出しごとに数万行を返すクエリは「DB が遅い」のではなく「取りすぎている」問題かもしれません。

ログ: log_min_duration_statement #

3 つ目の道具はスロークエリログです。

postgresql.conf 
log_min_duration_statement = 500   # 500ms を超えるクエリをログに残す

pg_stat_statements が「まとめて集計」なら、ログは実際のパラメータが入った個別の実行を残します。「特定のユーザーだけ遅い」のようなデータの偏りの問題はこちらが捕まえます。0 にすると全クエリのログになって負荷が大きいので、500ms〜1s 程度のしきい値が一般的です。

ルーチンにまとめる #

これで診断はこの順序で進めます。① 障害中なら pg_stat_activity で「いま」を見ます(長く走るクエリ、ロック待ち、idle in transaction)。② 平時の改善なら pg_stat_statements を合計と平均の 2 基準で抜き出します。③ 犯人のクエリを EXPLAIN ANALYZE で掘り、第 4 回のインデックスのチェックリストを回します。④ 直した後、pg_stat_statements の数値が実際に下がったかを確認します(SELECT pg_stat_statements_reset(); でリセットして比較するときれいです)。インデックスを作っても解決しない次の段階、インデックス戦略の応用が次回です。

まとめ #

  • 診断の順序は「どのクエリか」(今回)→「なぜ遅いか」(EXPLAIN)です。道具をこの順で使います。
  • いまの問題は pg_stat_activity です。長く走るクエリ、Lock 待ち、idle in transaction の 3 つを見ます。
  • 累積の標準は pg_stat_statements です。再起動が必要なので、障害の前に有効にしておきます。
  • 合計上位は DB 負荷の犯人、平均上位はユーザー体感の犯人です。両方の基準で抜き出します。
  • ログ(log_min_duration_statement)はパラメータまで残して、データの偏りの問題を捕まえます。次回はインデックス戦略の応用です。
X