pg_stat_statements は、PostgreSQL で実行された SQL を「形」ごとにまとめ、回数・時間・読んだブロック数を集計する拡張機能です。 WHERE id = 1 と WHERE id = 2 は WHERE id = $1 という1つの行にまとまるので、「どの SQL がデータベースの時間をいちばん使っているか」が分かります。有効化には shared_preload_libraries への追加と再起動が必要です。

-- postgresql.conf に shared_preload_libraries = 'pg_stat_statements' を書いて再起動したあと
CREATE EXTENSION pg_stat_statements;

-- データベースの時間を多く使っている SQL の上位10件
SELECT queryid, calls,
       round(total_exec_time::numeric, 0) AS total_ms,
       round(mean_exec_time::numeric, 2)  AS mean_ms,
       left(query, 60) AS query
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 10;
知りたいこと 並べる列
データベース全体への負荷が大きい SQL total_exec_time(合計時間)
1回が遅い SQL mean_exec_time(平均時間)
回数が多すぎる SQL(N+1 など) calls(呼び出し回数)
ディスクから読んでいる SQL shared_blks_read(共有バッファに無かったブロック)
メモリが足りず一時ファイルを使う SQL temp_blks_written
書き込み(WAL)が多い SQL wal_bytes

確認環境:PostgreSQL 16.15(Ubuntu 24.04、apt)、pg_stat_statements 1.10。pgbench でスケール 10(100万行・157MB)のデータを作り、8クライアントで60秒の負荷をかけて、この記事の分析クエリを実行しました。出力はすべてそのときの実際の値です。列の意味と設定の既定値、PostgreSQL 13・15・17・18 との列の違いは、各版の公式ドキュメントで確かめています(確認日 2026年10月13日)。

本記事の内容は、ご自由にお使いください。
ご利用の際は、出典として本ページへのリンクを記載いただけますようお願いします。

(記載例)出典:株式会社RJC「pg_stat_statementsで遅いSQLを探す|設定と分析クエリ集」

有効化の手順

1. shared_preload_libraries に追加して再起動

pg_stat_statements は共有メモリを使うので、サーバーの起動時に読み込む必要があります。 設定を変えたら再起動します(再読み込みでは反映されません)。

# postgresql.conf
shared_preload_libraries = 'pg_stat_statements'   # すでにほかのものがあればカンマで並べる
compute_query_id = auto                            # 既定値。auto なら pg_stat_statements が有効にする
track_io_timing = on                               # 読み書きの時間も取りたいとき(任意)
pg_stat_statements.max = 5000                      # 記録する SQL の種類の上限(既定 5000、再起動で反映)
pg_stat_statements.track = top                     # top(既定)/all(関数の中の SQL も)/none
sudo systemctl restart postgresql

ALTER SYSTEM でも設定できます。

ALTER SYSTEM SET shared_preload_libraries = 'pg_stat_statements';
-- 再起動後に確認
SHOW shared_preload_libraries;

注意:ALTER SYSTEM SET shared_preload_libraries = '' は使いません。 試したところ、postgresql.auto.conf に shared_preload_libraries = '""' と書かれ、再起動で FATAL: could not access file "": No such file or directory となり、PostgreSQL が起動しなくなりました。外すときは ALTER SYSTEM RESET shared_preload_libraries; を使います。

2. 使うデータベースで CREATE EXTENSION

CREATE EXTENSION pg_stat_statements;
\dx pg_stat_statements
        Name        | Version | Schema |                              Description                               
--------------------+---------+--------+------------------------------------------------------------------------
 pg_stat_statements | 1.10    | public | track planning and execution statistics of all SQL statements executed

集計はサーバー全体(全データベース)で1つです。 CREATE EXTENSION は、ビューを見たいデータベースで行います。ほかのデータベースの SQL も同じビューに出てくるので、データベースで絞るときは dbid を使います。

3. よくあるエラー

状況 エラー・症状 直し方
shared_preload_libraries に入れずに参照 ERROR: pg_stat_statements must be loaded via shared_preload_libraries 設定して再起動
CREATE EXTENSION をしていない relation "pg_stat_statements" does not exist そのデータベースで CREATE EXTENSION
他人の SQL の query が <insufficient privilege> 一般ユーザーには文面と queryid が見えない GRANT pg_read_all_stats TO 監視用ロール;
pg_stat_statements.track = all が構文エラー syntax error at or near "all" 'all' と引用符で囲む

1つ目のエラーは、shared_preload_libraries から外して再起動した状態で、実際にこの文面で出ました。

列の意味

PostgreSQL 16 の主な列です。時間の単位はミリ秒、ブロックは 1つ 8kB(block_size の既定値)です。

列 意味
queryid 正規化した SQL のハッシュ。同じ形の SQL は同じ値
query 代表の SQL 文。定数は $1・$2 に置き換わる
userid / dbid 実行したユーザー・データベースの OID
toplevel 最上位の文なら true(track = all のとき関数の中の文は false)
calls 実行回数
total_exec_time 実行時間の合計
mean_exec_time / min_exec_time / max_exec_time 実行時間の平均・最小・最大
stddev_exec_time 実行時間の標準偏差(ばらつき)
rows 返した・変更した行数の合計
plans / total_plan_time 計画(プラン)の回数と時間。track_planning = on のときだけ
shared_blks_hit 共有バッファ(メモリ)で見つかったブロック数
shared_blks_read 共有バッファに無く、OS から読んだブロック数
shared_blks_dirtied / shared_blks_written 変更した・書き出したブロック数
local_blks_* 一時テーブルのブロック数
temp_blks_read / temp_blks_written 並べ替え・ハッシュがメモリに入らず使った一時ファイルのブロック数
blk_read_time / blk_write_time ブロックの読み書きの時間(track_io_timing = on のとき)
temp_blk_read_time / temp_blk_write_time 一時ファイルの読み書きの時間(track_io_timing = on のとき)
wal_records / wal_fpi / wal_bytes 作った WAL のレコード数・全ページ書き込み数・バイト数
jit_* JIT コンパイルの回数と時間

shared_blks_read は「OS から読んだ」数で、OS のページキャッシュに当たった場合も含みます。実際にディスクを待った時間は blk_read_time で見ます。

版による列名の違い

記事や社内の SQL をコピーして動かないときは、列名の違いを疑います。 各版のドキュメントの列を比べると、次の違いがあります。

版 主な違い
12 以前 total_time・mean_time など(_exec_ なし)
13 total_exec_time / total_plan_time に分かれる。wal_* が増える
15(ドキュメントで確認) toplevel・temp_blk_read_time・jit_* がある
16 この記事の環境。blk_read_time / blk_write_time
17 shared_blk_read_time に改名。local_blk_*_time・stats_since・minmax_stats_since が増える
18 wal_buffers_full・parallel_workers_to_launch・parallel_workers_launched が増える

17 以降で読み込みの時間を見るときは、この記事の blk_read_time を shared_blk_read_time に読み替えます。

負荷をかけて集計を取る

pgbench(PostgreSQL に付属するベンチマークツール)の標準のシナリオに、遅い SQL を2つ混ぜて60秒動かしました。

-- search_balance.sql:索引の無い列での検索
\set v random(-5000, 5000)
SELECT count(*) FROM pgbench_accounts WHERE abalance = :v;
-- report.sql:30万行の DISTINCT(並べ替えがメモリに入らない)
SELECT count(*) FROM (SELECT DISTINCT bid, filler, aid FROM pgbench_accounts WHERE aid <= 300000) s;
pgbench -i -s 10 bench                         # 100万行のデータを作る
psql -d bench -c "SELECT pg_stat_statements_reset()"   # 準備中の SQL を集計から消す
pgbench -c 8 -j 2 -T 60 -P 20 \
  -b tpcb-like@20 -b select-only@20 \
  -f search_balance.sql@2 -f report.sql@1 bench
number of transactions actually processed: 8574
latency average = 56.088 ms
tps = 141.990377 (without initial connection time)

ここから下の出力は、この60秒の集計です。SQL の文は left(regexp_replace(query, '\s+', ' ', 'g'), 60) で改行を詰めて60文字に切っています。

分析クエリ集

1. 合計時間の順(まずこれ)

SELECT queryid,
       left(regexp_replace(query, '\s+', ' ', 'g'), 60) AS query,
       calls,
       round(total_exec_time::numeric, 0) AS total_ms,
       round(mean_exec_time::numeric, 2)  AS mean_ms,
       round((100 * total_exec_time / sum(total_exec_time) OVER ())::numeric, 1) AS pct,
       rows
FROM pg_stat_statements
WHERE dbid = (SELECT oid FROM pg_database WHERE datname = current_database())
ORDER BY total_exec_time DESC
LIMIT 10;
       queryid        |                            query                             | calls | total_ms | mean_ms | pct  | rows 
----------------------+--------------------------------------------------------------+-------+----------+---------+------+------
  -156217827571974747 | SELECT count(*) FROM (SELECT DISTINCT bid, filler, aid FROM  |   202 |   142622 |  706.05 | 52.8 |  202
 -3259546628744050512 | SELECT count(*) FROM pgbench_accounts WHERE abalance = $1    |   411 |    61589 |  149.85 | 22.8 |  411
   281648461012500279 | UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE b |  3931 |    55794 |   14.19 | 20.6 | 3931
 -7501989902836862635 | UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE ti |  3931 |     9614 |    2.45 |  3.6 | 3931
 -8659676057048197262 | SELECT abalance FROM pgbench_accounts WHERE aid = $1         |  7961 |      340 |    0.04 |  0.1 | 7961
 -1085962423785209710 | UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE a |  3931 |      300 |    0.08 |  0.1 | 3931
  6233814722611029354 | INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VA |  3931 |       42 |    0.01 |  0.0 | 3931

pct(全体に占める割合)の上位3つで、時間の 96% を占めています。 直す順番はこの表で決まります。WHERE abalance = $1 のように、定数は $1 にまとめられています。

3行目の UPDATE pgbench_branches は、1回 14ms と目立ちます。pgbench のスケール 10 では branches 表が10行しかなく、8クライアントが同じ行を更新し合うので、行ロックの待ち時間が実行時間に入っています。 pg_stat_statements の時間は「待ち」も含むので、遅い原因が SQL の書き方なのか、ロック待ちなのかは、この表だけでは分かりません。ロック待ちの調べ方は関連記事「PostgreSQLロック確認SQL|ブロッキング特定から解除までコピペ集」で扱っています。

2. 平均時間の順とばらつき

SELECT left(regexp_replace(query, '\s+', ' ', 'g'), 60) AS query,
       calls,
       round(mean_exec_time::numeric, 2)   AS mean_ms,
       round(min_exec_time::numeric, 2)    AS min_ms,
       round(max_exec_time::numeric, 2)    AS max_ms,
       round(stddev_exec_time::numeric, 2) AS stddev_ms
FROM pg_stat_statements
WHERE calls >= 10                 -- 1回だけの管理用 SQL を除く
ORDER BY mean_exec_time DESC
LIMIT 10;
                            query                             | calls | mean_ms | min_ms | max_ms  | stddev_ms 
--------------------------------------------------------------+-------+---------+--------+---------+-----------
 SELECT count(*) FROM (SELECT DISTINCT bid, filler, aid FROM  |   202 |  706.05 | 226.98 | 1633.35 |    341.93
 SELECT count(*) FROM pgbench_accounts WHERE abalance = $1    |   411 |  149.85 |  41.18 |  416.83 |     60.71
 UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE b |  3931 |   14.19 |   0.00 |  686.30 |     57.78
 UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE ti |  3931 |    2.45 |   0.01 |  605.37 |     25.81
 UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE a |  3931 |    0.08 |   0.01 |   19.34 |      0.43

min が小さく max と stddev が大きい SQL は、SQL そのものより「そのときの状況」で遅くなっています。 UPDATE pgbench_branches は最小 0.00ms・最大 686ms で、ロック待ちの典型です。逆に DISTINCT の SQL は最小でも 227ms あり、SQL そのものが重いことが分かります。

3. 呼び出し回数の順(N+1 を探す)

SELECT left(regexp_replace(query, '\s+', ' ', 'g'), 60) AS query,
       calls,
       round(total_exec_time::numeric, 0) AS total_ms,
       round(mean_exec_time::numeric, 3)  AS mean_ms,
       round(rows::numeric / calls, 1)    AS rows_per_call
FROM pg_stat_statements
ORDER BY calls DESC
LIMIT 10;
                            query                             | calls | total_ms | mean_ms | rows_per_call 
--------------------------------------------------------------+-------+----------+---------+---------------
 SELECT abalance FROM pgbench_accounts WHERE aid = $1         |  7961 |      340 |   0.043 |           1.0
 UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE ti |  3931 |     9614 |   2.446 |           1.0
 INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VA |  3931 |       42 |   0.011 |           1.0

1回は速い(0.043ms)のに回数が飛び抜けて多い SQL は、アプリのループの中で1件ずつ取っている(N+1)ことがあります。 データベースの時間は小さくても、アプリとの往復の回数が応答時間を延ばします。rows_per_call が 1.0 で calls が大きい SELECT が候補です。N+1 の直し方は関連記事「N+1問題とは?原因と見つけ方・解決方法【フレームワーク別】」で扱っています。

4. 共有バッファのヒット率

SELECT left(regexp_replace(query, '\s+', ' ', 'g'), 60) AS query,
       calls,
       shared_blks_hit,
       shared_blks_read,
       round(100.0 * shared_blks_hit / nullif(shared_blks_hit + shared_blks_read, 0), 1) AS hit_pct,
       round(blk_read_time::numeric, 0) AS read_ms     -- 17 以降は shared_blk_read_time
FROM pg_stat_statements
WHERE shared_blks_hit + shared_blks_read > 0
ORDER BY shared_blks_read DESC
LIMIT 10;
                            query                             | calls | shared_blks_hit | shared_blks_read | hit_pct | read_ms 
--------------------------------------------------------------+-------+-----------------+------------------+---------+---------
 SELECT count(*) FROM pgbench_accounts WHERE abalance = $1    |   411 |         5960038 |           791698 |    88.3 |    5771
 SELECT count(*) FROM (SELECT DISTINCT bid, filler, aid FROM  |   202 |         1356088 |            22281 |    98.4 |     209
 SELECT abalance FROM pgbench_accounts WHERE aid = $1         |  7961 |           32194 |             3150 |    91.1 |      42

WHERE abalance = $1 は、411回で合計 675万ブロック(約 51GB 分)を読んでいます。 1回あたり約1.6万ブロックで、表全体(pgbench_accounts は約1.6万ブロック)を毎回読んでいる、つまり全件走査です。ヒット率が高くても、読む量そのものが多ければ遅くなります。ヒット率より先に「1回あたりのブロック数」を見ると、索引の不足に気づけます。

データベース全体のヒット率は次のように出せます。この負荷では 90.05% でした。

SELECT round(100.0 * sum(shared_blks_hit) / nullif(sum(shared_blks_hit) + sum(shared_blks_read), 0), 2) AS overall_hit_pct
FROM pg_stat_statements;

5. 一時ファイルを使っている SQL

SELECT left(regexp_replace(query, '\s+', ' ', 'g'), 60) AS query,
       calls,
       temp_blks_written,
       pg_size_pretty(temp_blks_written * current_setting('block_size')::bigint) AS temp_written,
       round(mean_exec_time::numeric, 1) AS mean_ms
FROM pg_stat_statements
WHERE temp_blks_written > 0
ORDER BY temp_blks_written DESC
LIMIT 10;
                            query                             | calls | temp_blks_written | temp_written | mean_ms 
--------------------------------------------------------------+-------+-------------------+--------------+---------
 SELECT count(*) FROM (SELECT DISTINCT bid, filler, aid FROM  |   202 |            789012 | 6164 MB      |   706.0

並べ替えやハッシュが work_mem に入りきらないと、一時ファイルに書き出します。 この SQL は202回で合計 6GB を書いていました。

6. WAL(書き込み)が多い SQL

SELECT left(regexp_replace(query, '\s+', ' ', 'g'), 60) AS query,
       calls, wal_records, pg_size_pretty(wal_bytes) AS wal
FROM pg_stat_statements
WHERE wal_bytes > 0
ORDER BY wal_bytes DESC
LIMIT 5;
                            query                             | calls | wal_records |   wal   
--------------------------------------------------------------+-------+-------------+---------
 UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE a |  3931 |       10909 | 1016 kB
 UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE b |  3931 |        4830 | 332 kB

レプリケーションの遅れや WAL の増えすぎを調べるときに使います。

7. ユーザー・データベースごと

SELECT r.rolname, d.datname, count(*) AS statements, sum(s.calls) AS calls,
       round(sum(s.total_exec_time)::numeric, 0) AS total_ms
FROM pg_stat_statements s
JOIN pg_roles r ON r.oid = s.userid
JOIN pg_database d ON d.oid = s.dbid
GROUP BY 1, 2
ORDER BY total_ms DESC;

アプリ・バッチ・人の操作でユーザーを分けておくと、どこからの負荷かがこの1本で分かります。

8. 特定の表を使う SQL

SELECT calls, round(mean_exec_time::numeric, 2) AS mean_ms, left(query, 80) AS query
FROM pg_stat_statements
WHERE query ILIKE '%pgbench_accounts%'
ORDER BY total_exec_time DESC;

直したあとに効果を確かめる

1つの SQL だけ集計を消して、直したあとの数字を取り直せます。 PostgreSQL 16 の pg_stat_statements_reset(userid, dbid, queryid) は、指定しない引数を 0 として扱い、すべて 0 なら全件を消します。

SELECT pg_stat_statements_reset(0, 0, -3259546628744050512);   -- この queryid だけ消す

2つの遅い SQL に対して、索引の追加と work_mem の変更を行い、同じ負荷(2クライアント・15秒)の前後で比べました。

CREATE INDEX ON pgbench_accounts (abalance);
ALTER ROLE postgres SET work_mem = '64MB';     -- 試験用。本番ではロール・処理を絞って設定
SQL 変更 平均(前) 平均(後) ブロック数(前 → 後)
WHERE abalance = $1 索引を追加 107.1 ms 0.041 ms 542982 → 145
DISTINCT bid, filler, aid work_mem 4MB → 64MB 613.0 ms 644.2 ms 一時ファイル 167958 → 0

索引を足した SQL は、読むブロックが 3700分の1 になり、平均が 107ms から 0.041ms になりました。 一方、work_mem を上げた SQL は、一時ファイルは 0 になったものの、平均時間はほぼ変わりませんでした。この SQL は30万行を並べ替えること自体に時間がかかっていて、一時ファイルの読み書き(auto_explain の出力では約 20ms)は一部だったためです。「一時ファイルを使っている = それが遅さの原因」とは限らないので、次の auto_explain で、どこに時間がかかっているかを見ます。 索引が効かない書き方については関連記事「SQLのインデックスが効かない10のパターンと確認方法」で扱っています。索引の種類の選び方は関連記事「PostgreSQLインデックスの種類|B-tree/GIN/GiST/BRIN実測」で扱っています。

リセットと保存

操作 SQL
すべて消す SELECT pg_stat_statements_reset();
1つの SQL だけ消す SELECT pg_stat_statements_reset(0, 0, queryid);
あるユーザーの分だけ消す SELECT pg_stat_statements_reset((SELECT oid FROM pg_roles WHERE rolname = 'app'));
最小・最大だけ消す(17 から) SELECT pg_stat_statements_reset(0, 0, 0, true);
最後に全件を消した時刻 SELECT stats_reset FROM pg_stat_statements_info;
上限で追い出された回数 SELECT dealloc FROM pg_stat_statements_info;

集計は「最後のリセットからの累計」です。 「昨日から遅くなった」を調べるには、定期的に結果を表に保存して差を取るか、調査の前にリセットしてから一定時間待ちます。

-- 1時間ごとなどに保存して、差分で見る
CREATE TABLE pgss_snapshot AS
SELECT now() AS taken_at, queryid, dbid, userid, calls, total_exec_time, shared_blks_read
FROM pg_stat_statements WITH NO DATA;

INSERT INTO pgss_snapshot
SELECT now(), queryid, dbid, userid, calls, total_exec_time, shared_blks_read
FROM pg_stat_statements;

pg_stat_statements.save が既定の on なら、通常の停止・再起動では集計が残ります。再起動の前後で行数を確かめたところ、集計は消えずに残っていました。pg_stat_statements.max(既定 5000)を超える種類の SQL が来ると、実行回数の少ないものから追い出され、pg_stat_statements_info.dealloc が増えます。この値が増え続けるなら、max を上げます。

auto_explain と組み合わせる

pg_stat_statements は「どの SQL が遅いか」、auto_explain は「その SQL のどこが遅いか(実行計画)」を教えてくれます。 auto_explain は、指定した時間より遅い SQL の実行計画をサーバーのログに書き出す拡張機能です。

設定

# postgresql.conf
shared_preload_libraries = 'pg_stat_statements'
session_preload_libraries = 'auto_explain'     # 新しいセッションから有効(再読み込みで反映)
auto_explain.log_min_duration = '500ms'        # これより遅い SQL の計画を出す(既定 -1 = 出さない)
auto_explain.log_analyze = on                  # 実際の時間・行数を出す(オーバーヘッドあり)
auto_explain.log_buffers = on                  # ブロック数を出す(log_analyze が必要)
log_line_prefix = '%m [%p] %q%u@%d qid=%Q '    # %Q で queryid をログに出す(14 から)

ALTER SYSTEM で設定するときは、同じセッションで先に LOAD 'auto_explain'; を実行します。 読み込んでいないセッションで ALTER SYSTEM SET auto_explain.log_min_duration = '500ms'; を実行すると、ERROR: unrecognized configuration parameter "auto_explain.log_min_duration" になりました。

LOAD 'auto_explain';
ALTER SYSTEM SET session_preload_libraries = 'auto_explain';
ALTER SYSTEM SET auto_explain.log_min_duration = '500ms';
ALTER SYSTEM SET auto_explain.log_analyze = on;
ALTER SYSTEM SET auto_explain.log_buffers = on;
SELECT pg_reload_conf();
項目 既定値 意味
auto_explain.log_min_duration -1(無効) この時間(ミリ秒)以上の SQL の計画をログに出す。0 は全部
auto_explain.log_analyze off EXPLAIN ANALYZE の形で出す。全 SQL に計測のオーバーヘッドがかかる
auto_explain.log_buffers off ブロック数を出す(log_analyze が必要)
auto_explain.log_timing on ノードごとの時間を出す。off にするとオーバーヘッドが減る
auto_explain.log_nested_statements off 関数の中の SQL も対象にする
auto_explain.log_format text text・xml・json・yaml
auto_explain.sample_rate 1 対象にする SQL の割合

出力と queryid のつなぎ方

log_min_duration を 100ms にして、2つの遅い SQL を実行したときのログです。

2026-10-13 12:45:55.566 JST [14860] postgres@bench qid=-156217827571974747 LOG:  duration: 329.564 ms  plan:
    Query Text: SELECT count(*) FROM (SELECT DISTINCT bid, filler, aid FROM pgbench_accounts WHERE aid <= 300000) s
    Aggregate  (cost=62779.52..62779.53 rows=1 width=8) (actual time=329.552..329.554 rows=1 loops=1)
      Buffers: shared hit=7781, temp read=3896 written=3906
      I/O Timings: temp read=7.348 write=13.004
      ->  Unique  (cost=56040.08..59035.39 rows=299531 width=93) (actual time=153.122..306.363 rows=300000 loops=1)
            ->  Sort  (cost=56040.08..56788.90 rows=299531 width=93) (actual time=153.120..259.693 rows=300000 loops=1)
                  Sort Key: pgbench_accounts.bid, pgbench_accounts.filler, pgbench_accounts.aid
                  Sort Method: external merge  Disk: 31168kB
                  ->  Index Scan using pgbench_accounts_pkey on pgbench_accounts  (actual time=0.041..48.064 rows=300000 loops=1)
                        Index Cond: (aid <= 300000)
2026-10-13 12:45:55.699 JST [14860] postgres@bench qid=-3259546628744050512 LOG:  duration: 114.887 ms  plan:
    Query Text: SELECT count(*) FROM pgbench_accounts WHERE abalance = 0
    Finalize Aggregate  (actual time=110.772..114.877 rows=1 loops=1)
      ->  Gather  (actual time=107.502..114.865 rows=3 loops=1)
            Workers Planned: 2
            ->  Parallel Seq Scan on pgbench_accounts  (actual time=0.015..71.216 rows=332025 loops=3)
                  Filter: (abalance = 0)
                  Buffers: shared hit=15181 read=1273

(一部の行と cost を省いています)

ログの qid= の値は、pg_stat_statements の queryid と同じでした。 pg_stat_statements で見つけた queryid でログを検索すれば、その SQL の実際の実行計画にたどり着けます。

sudo grep -A30 "qid=-156217827571974747" /var/log/postgresql/postgresql-16-main.log

1つ目の計画からは、Sort のノードまでで約 260ms かかり、並べ替えは external merge Disk: 31168kB(一時ファイルを使う並べ替え)、一時ファイルの読み書き(I/O Timings)は合計約 20ms と読めます。2つ目は Parallel Seq Scan(全件走査)で、索引が無いことが分かります。実行計画の読み方は関連記事「実行計画の見方|EXPLAIN ANALYZEの読み方を実行結果で解説」で扱っています。

track = all で関数の中の SQL も見る

既定の track = top では、関数の中で実行された SQL は数えられず、関数の呼び出しだけが残ります。

CREATE FUNCTION tx_count(b int) RETURNS bigint LANGUAGE plpgsql AS $$
BEGIN
  RETURN (SELECT count(*) FROM pgbench_tellers WHERE bid = b);
END $$;

ALTER SYSTEM SET pg_stat_statements.track = 'all';   -- 'all' は引用符が必要
SELECT pg_reload_conf();
-- track = top
 toplevel | calls |        query        
----------+-------+---------------------
 t        |     2 | SELECT tx_count($1)

-- track = 'all'
 toplevel | calls |                        query                         
----------+-------+------------------------------------------------------
 t        |     2 | SELECT tx_count($1)
 f        |     2 | (SELECT count(*) FROM pgbench_tellers WHERE bid = b)

ストアドプロシージャや関数に処理を寄せているシステムでは、all にしないと遅い SQL が見えません。 all では時間が関数とその中の SQL の両方に入るので、合計時間を足すときは toplevel = true に絞ります。

スロークエリログとの違い

方法 分かること 向いている場面
pg_stat_statements SQL の形ごとの回数・時間・ブロック数の累計 全体で何が重いかの順位付け、回数が多い SQL
log_min_duration_statement 閾値より遅かった1回ごとの SQL と時間 特定の時刻に遅かった SQL の確認
auto_explain 閾値より遅かった1回ごとの実行計画 なぜ遅いかの原因調べ

速いけれど回数が多い SQL は、スロークエリログには出ず、pg_stat_statements でしか見つかりません。 3つは役割が違うので、組み合わせて使います。MySQL での同じ調べ方は関連記事「MySQLスロークエリログの設定と分析|8.0/8.4対応の手順と見方」で扱っています。

よくある質問

Q. 本番で有効にすると、どのくらい重くなりますか。 A. ドキュメントでは、track_planning を on にすると目立つ性能の低下があり得るとされ、既定は off です。auto_explain の log_analyze は、全 SQL に計測のオーバーヘッドがかかり、log_timing = off にすると減らせるとされています。auto_explain は log_min_duration を大きめにする、sample_rate で対象の割合を絞る、という調整ができます。

Q. query に $1 ではなく実際の値が見たいです。 A. pg_stat_statements は値をまとめるので、元の値は残りません。値が必要なときは auto_explain(log_parameter_max_length)や log_min_duration_statement のログを使います。

Q. 同じ SQL なのに行が分かれています。 A. 実行したユーザー・データベースが違うと別の行になります(userid・dbid も集計のキー)。PostgreSQL 16 では、IN ($1, $2) と IN ($1, $2, $3) のように、要素の数が違う IN 句も別の SQL として数えられます。

まとめ

  • 有効化は shared_preload_libraries に追加 → 再起動 → CREATE EXTENSION。外すときは '' ではなく ALTER SYSTEM RESET
  • まず total_exec_time の順で全体への負荷を見る。次に平均・回数・ブロック数
  • min が小さく max が大きいならロック待ちなどの状況要因、1回あたりのブロック数が多いなら全件走査を疑う
  • 回数が多い速い SQL(N+1)は pg_stat_statements でしか見つからない
  • 直したら queryid を指定してリセットし、前後の数字で効果を確かめる
  • auto_explain のログの %Q(queryid) と pg_stat_statements の queryid をつなげると、遅い SQL の実行計画にすぐたどり着ける
  • 17 以降は blk_read_time が shared_blk_read_time に変わる

参考・出典

確認日はいずれも 2026年10月13日です。

  • PostgreSQL 16 Documentation「F.32. pg_stat_statements」:https://www.postgresql.org/docs/16/pgstatstatements.html
  • PostgreSQL 13・15・17・18 Documentation「pg_stat_statements」(列の比較):https://www.postgresql.org/docs/13/pgstatstatements.html ・ https://www.postgresql.org/docs/15/pgstatstatements.html ・ https://www.postgresql.org/docs/17/pgstatstatements.html ・ https://www.postgresql.org/docs/18/pgstatstatements.html
  • PostgreSQL 16 Documentation「F.3. auto_explain」:https://www.postgresql.org/docs/16/auto-explain.html
  • PostgreSQL 16 Documentation「pgbench」:https://www.postgresql.org/docs/16/pgbench.html
  • PostgreSQL 16 Documentation「20.8. Error Reporting and Logging(log_line_prefix)」:https://www.postgresql.org/docs/16/runtime-config-logging.html

本記事の内容は、ご自由にお使いください。
ご利用の際は、出典として本ページへのリンクを記載いただけますようお願いします。

(記載例)出典:株式会社RJC「pg_stat_statementsで遅いSQLを探す|設定と分析クエリ集」

株式会社RJC ― SI事業・SES事業・AI駆動開発。RJCは一緒に成長を楽しめる会社です。

WE ARE HIRING

RJCで一緒に開発しながら、
成長を楽しみませんか?

RJCは、Web・モバイル・AIを活用した開発プロジェクトで、テックリードやPM・PMOも活躍するシステム開発会社です。会社を知る、待遇を確かめる、話を聞いてみる。気になるところ見てみてください!

  • 127日年間休日
  • 12時間平均残業時間
  • 毎日ガチャ遊びココロも大切にする福利厚生。アマギフなどの賞品ラインナップ!

ほかにも、チケットレストラン、書籍読み放題、2年ごとの慰労報奨(休暇 or 金一封)、11期連続の黒字決算。

ABOUT RJC RJCがどんな会社か知る 考え方、研修、働き方、福利厚生、社員の前職まで。RJCのことが丸わかり! RJC丸わかりページへ JOB DESCRIPTION 仕事内容・待遇を見てみる 仕事内容、給与・待遇、選考の流れ。経験者も未経験も!応募前に知りたいこと、まとめました! 募集要項を見る ENTRY エントリーする エントリーは1〜2分・履歴書不要です。まずは話を聞いてみたい、という方でも歓迎です! エントリーフォームへ

RJCで一緒に開発しながら、 成長を楽しみませんか?