- データベース
pg_stat_statementsで遅いSQLを探す|設定と分析クエリ集
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期連続の黒字決算。