Posted inデータベース

pg_stat_statementsによるPostgreSQLパフォーマンス分析：遅いクエリの発見と改善

Database tutorial - IT technology blog
Database tutorial - IT technology blog

誰も説明できない症状

PostgreSQLデータベースが重い。午前2時にレスポンスタイムが急増し、特定のAPIエンドポイントが負荷でタイムアウトし、アプリケーションログはタイムアウトエラーだらけ — しかしどのクエリが原因なのか、誰も分からない。

どのクエリを最適化すべきか当てずっぽうにやれば、何日も無駄になる。必要なのはデータであって、勘ではない。それでもほとんどのチームは、最初に間違ったツールに手を伸ばしてしまう。

pg_stat_statementsは、データベースを通過するすべてのクエリの実行統計（総呼び出し回数、総時間、平均時間、返却行数、キャッシュヒット率）を追跡するPostgreSQL組み込みの拡張機能だ。クエリのフライトレコーダーと思えばいい。PostgreSQL 9.2以降に同梱されており、ほぼ確実にすでにサーバーにインストールされている。

アプローチ比較：チームが遅いデータベースをデバッグする一般的な方法

セットアップに入る前に、代替手段を理解しておく価値がある — それぞれ異なる場面で痛い目を見る、現実的なトレードオフがあるからだ。

アプローチ1：アプリケーションレベルのログ

データベース呼び出しをタイミングコードでラップし、閾値を超えたものをログに記録する。ほとんどのチームはここから始める。

  • メリット：追加が簡単、ビジネスコンテキスト（どのユーザーがクエリを発行したか）が得られる、データベースの変更不要
  • デメリット：バックグラウンドジョブ、cronタスク、マイグレーション、サードパーティツールからのクエリが見えない。アプリケーションが計装した部分しか把握できない。またアプリコードにオーバーヘッドが加わる。

アプローチ2：PostgreSQLスロークエリログ

postgresql.confでlog_min_duration_statementを設定し、時間閾値を超えたクエリをログに記録する。

  • メリット：すべてを捕捉できる、拡張機能不要、有効化が簡単
  • デメリット：実際のパラメーター値を含む生のクエリテキストをログに記録するため、本番環境ではプライバシーとセキュリティのリスクがある。負荷が増えるとログ量が爆発する。個々のクエリインスタンスしか得られず、集計統計は得られない。「1日5万回実行されて平均200msのクエリはどれか？」という問いには答えられない。

アプローチ3：pg_stat_statements（推奨）

すべての接続、ユーザー、ツールにわたって、正規化されたクエリパターンごとに統計を集計するPostSQL公式拡張機能。

  • メリット：低オーバーヘッド（CPUの約1〜5%）、ソースを問わずすべてのクエリを捕捉、パラメーターを正規化（WHERE id = 1とWHERE id = 2を同じクエリパターンとして扱う）、優先順位付けに使える集計データが得られる
  • デメリット：有効化にスーパーユーザーが必要、初回インストール時にPostgreSQLの再起動が必要、デフォルトではクエリパラメーターを取得しない

継続的な本番運用では、pg_stat_statementsに軍配が上がる。スロークエリログは単発のデバッグセッションに便利だが、pg_stat_statementsはどこに時間を使うべきか優先順位をつけるための統計的な全体像を提供してくれる。

pg_stat_statementsのセットアップ

ステップ1：拡張機能を有効化する

postgresql.confのshared_preload_librariesに追加する。再起動が必要 — これだけは避けられないステップだ。

# postgresql.confを見つける
psql -U postgres -c "SHOW config_file;"

# postgresql.confを編集して以下の行を追加・更新する：
shared_preload_libraries = 'pg_stat_statements'

# 任意だが推奨の設定：
pg_stat_statements.max = 10000       # 追跡するステートメントの最大数
pg_stat_statements.track = all       # ネストされたものを含むすべてのステートメントを追跡
pg_stat_statements.track_utility = on  # COPY、VACUUMなどを追跡

# PostgreSQLを再起動する
sudo systemctl restart postgresql

# マネージドサービス（RDS、Cloud SQL）の場合、パラメーターグループを変更して
# 適用する — 通常は再起動が必要

ステップ2：データベースに拡張機能を作成する

-- 監視したい各データベースでスーパーユーザーとして実行する
CREATE EXTENSION IF NOT EXISTS pg_stat_statements;

-- 動作確認
SELECT count(*) FROM pg_stat_statements;

最悪のクエリを見つける

拡張機能に数時間 — 理想的には実際のトラフィック下で24〜48時間 — データを収集させてから、以下のクエリを実行しよう。

総時間でのトップクエリ（最大のボトルネック）

SELECT
  round(total_exec_time::numeric, 2) AS total_ms,
  calls,
  round(mean_exec_time::numeric, 2) AS mean_ms,
  round(stddev_exec_time::numeric, 2) AS stddev_ms,
  round((100 * total_exec_time /
    sum(total_exec_time) OVER ())::numeric, 2) AS percentage,
  left(query, 120) AS query_preview
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 15;

データベース負荷において実際に重要なのは総時間だ。平均5msのクエリが1日10万回実行されると、500秒のデータベース時間を消費する。週に1回だけ実行される500msのクエリはほとんど影響しない。ピークレイテンシーではなく、総コストで最適化しよう。

平均実行時間でのトップクエリ（最も遅い個別クエリ）

SELECT
  calls,
  round(mean_exec_time::numeric, 2) AS mean_ms,
  round(max_exec_time::numeric, 2) AS max_ms,
  round(stddev_exec_time::numeric, 2) AS stddev_ms,
  left(query, 120) AS query_preview
FROM pg_stat_statements
WHERE calls > 100  -- 単発クエリは無視する
ORDER BY mean_exec_time DESC
LIMIT 15;

キャッシュミス率（バッファヒット率）

SELECT
  calls,
  round(mean_exec_time::numeric, 2) AS mean_ms,
  shared_blks_hit,
  shared_blks_read,
  round(100.0 * shared_blks_hit /
    NULLIF(shared_blks_hit + shared_blks_read, 0), 2) AS hit_rate_pct,
  left(query, 100) AS query_preview
FROM pg_stat_statements
WHERE shared_blks_hit + shared_blks_read > 0
ORDER BY shared_blks_read DESC
LIMIT 10;

頻繁に呼ばれるクエリでhit_rate_pctが90%を下回っている場合、ディスクを酷使しているということだ。インデックスが必要か、ワーキングセットに対してshared_buffersが小さすぎるかのどちらかだ。32GBのRAMを積んだサーバーでも、shared_buffersがデフォルトの128MBのままになっていることがよくある — 確認してみよう。

統計から行動へ：実践的な最適化ワークフロー

ステップ1：完全なクエリテキストを取得する

pg_stat_statementsのqueryカラムは正規化・切り詰められている。問題のあるクエリの全文を取得するには：

SELECT query
FROM pg_stat_statements
WHERE queryid = 1234567890;  -- 前の結果で得たqueryidを使う

ステップ2：EXPLAIN ANALYZEを実行する

実際のサンプルパラメーターを代入して、EXPLAIN ANALYZEでクエリを実行する。BUFFERSオプションは重要 — これなしではI/Oの挙動が見えない。

EXPLAIN (ANALYZE, BUFFERS, FORMAT TEXT)
SELECT u.id, u.email, o.total
FROM users u
JOIN orders o ON o.user_id = u.id
WHERE u.created_at > '2025-01-01'
  AND o.status = 'pending';

確認すべき3点：大きなテーブルへのSeq Scan（通常はインデックスが必要）、actual rowsとestimated rowsの大きな乖離（統計情報が古い — ANALYZEを実行する）、そしてディスクにスピルしているHash Joinノード。

ステップ3：的を絞ったインデックスを作成する

-- WHERE句とJOIN条件に合致する複合インデックス
CREATE INDEX CONCURRENTLY idx_orders_user_status
  ON orders (user_id, status)
  WHERE status = 'pending';  -- 特定のステータスのみクエリする場合は部分インデックス

-- 作成後、プランナーが使用することを確認する
EXPLAIN (ANALYZE, BUFFERS)
SELECT ... -- 対象のクエリ

本番環境では必ずCONCURRENTLYを使うこと。これなしでは、インデックス構築がACCESS EXCLUSIVEロックを取得し、完了するまですべての読み書きがブロックされる。

メンテナンス：リセットと経時的な追跡

最適化後は、クリーンなベースラインで改善効果を測定できるよう統計をリセットしよう：

-- すべてのクエリの統計をリセットする（スーパーユーザーのみ）
SELECT pg_stat_statements_reset();

-- または特定のクエリの統計をリセットする（PostgreSQL 12以降）
SELECT pg_stat_statements_reset(0, 0, queryid)
FROM pg_stat_statements
WHERE query LIKE '%your_table%'
LIMIT 1;

上位20クエリをCSVにエクスポートするシンプルな週次cronジョブがあれば、時系列のトレンドが把握できる。そのCSVをモニタリングダッシュボードへのインポート用にJSONに変換する必要があるときは、toolcraft.app/ja/tools/data/csv-to-jsonがブラウザ上で処理してくれる — サードパーティサーバーへのアップロードが不要なため、CSVに本番システムのクエリパターンが含まれる場合に安心だ。

本番環境での推奨設定

どの本番インスタンスでも使う価値のあるpostgresql.confの設定を紹介する：

# postgresql.conf
shared_preload_libraries = 'pg_stat_statements'
pg_stat_statements.max = 10000
pg_stat_statements.track = all
pg_stat_statements.track_utility = on
pg_stat_statements.save = on  # 再起動後も統計を保持する

# スロークエリログを補完として使う（代替ではない）
log_min_duration_statement = 1000  # 1秒を超えるクエリをログに記録
log_line_prefix = '%t [%p]: [%l-1] db=%d,user=%u,app=%a,client=%h '

pg_stat_statements.save = onは見落とされがちだ。再起動をまたいで統計を保持する — 数日かけて積み上がったパターンを追いかけているときにサーバーが再起動されると困るので、これは重要だ。

ダッシュボードについては、pgBadger（ログベース）もpganalyze（SaaS）も同じデータの上に構築されている。AWS RDS Performance Insightsも同様だ。始めるためにこれらは必須ではない — 上記の生SQLクエリで80%のケースはカバーできる。

実際に活用しよう

拡張機能を有効化し、24〜48時間の実トラフィックを収集したら、総時間クエリを実行しよう。一貫して、データベース負荷の80%は3〜5つのクエリから来ている。まずそこを直そう。リストのトップを処理するまで、他はすべてノイズだ。

統計は嘘をつかない。total_exec_timeランキングのトップにクエリがあれば、そこに注力するのが最も効果的だ。当てずっぽうをやめて、計測から始めよう。

Share:
Tags: