1. はじめに
本記事では、pg_stat_statements を使ってスロークエリ(slow query)を特定する方法を実測で確認します。
EXPLAIN ANALYZE は「特定のクエリを手動で調べる」ツールですが、本番でどのクエリが問題を起こしているか はわかりません。pg_stat_statements はすべてのクエリの実行統計を累積記録するため、「実行回数が多い」「合計時間が長い」「I/Oが多い」クエリを一覧で特定できます。
1.1 検証環境
| 項目 | 内容 |
|---|---|
| OS | AmazonLinux2023 |
| PostgreSQL | 16 |
| インスタンスタイプ | t3.micro (2 vCPU、1GiB) |
| データ | pgbench scale factor 75(約750万行) |
pgbenchの初期化を実行しておきます。
# pgbench_accounts: 7,500,000 件のデータを投入
$ pgbench -i -s 75 -U postgres pgbench_test
# データサイズを確認(1テーブルで約 1.1GB)
$ psql -U postgres -d pgbench_test -c "SELECT relname, round(pg_relation_size(relid) / 1024.0^3, 3) AS table_gb, round(pg_indexes_size(relid) / 1024.0^3, 3) AS index_gb, round(pg_total_relation_size(relid) / 1024.0^3, 3) AS total_gb FROM pg_stat_user_tables WHERE relname = 'pgbench_accounts';"
relname | table_gb | index_gb | total_gb
------------------+----------+----------+----------
pgbench_accounts | 0.945 | 0.157 | 1.102
(1 row)
1.2 pg_stat_statementsについて
pg_stat_statementでは、主に下記項目を確認します。
| カラム名 | 説明 |
|---|---|
calls |
実行回数 |
total_exec_time |
累積実行時間(ms) |
mean_exec_time |
平均実行時間(ms) |
stddev_exec_time |
実行時間の標準偏差(ms)(ばらつきの指標) |
rows |
累積返却行数 |
shared_blks_hit |
共有バッファ(shared buffer)ヒット数 |
shared_blks_read |
ディスクから読み込んだブロック数 |
temp_blks_written |
一時ファイル(temporary file)書き込みブロック数 |
queryid |
対象のクエリーに対する一意のID |
query |
対象のクエリー |
2. pg_stat_statementsを有効にする
2.1 設定と有効化
標準のインストールでは、pg_stat_statementsは有効になっていません。下記のようにpostgresql.confに設定を実施します。
# postgresql.conf
shared_preload_libraries = 'pg_stat_statements' # 再起動が必要
pg_stat_statements.track = all # トップレベル+ネストされたSQL全体を追跡
pg_stat_statements.max = 10000 # 記録するクエリの最大数
# 設定反映(再起動が必要)
$ sudo systemctl restart postgresql
下記のSQLを実行して、拡張機能をインストールして、試験的に実行してみます。
-- 拡張のインストール
CREATE EXTENSION IF NOT EXISTS pg_stat_statements;
-- 動作確認
SELECT count(*) FROM pg_stat_statements;
下記のように結果が表示されれば拡張機能のインストールは成功です。
count
-------
2
(1 row)
2.2 統計情報の初期化
既存の統計情報をリセットしてから計測を開始します。過去に実行したクエリーの統計情報はすべて消去されます。
$ psql -U postgres -d pgbench_test -c "SELECT pg_stat_statements_reset();"
pg_stat_statements_reset
--------------------------
(1 row)
これで、統計情報の取得のための設定は完了です。
3. 負荷をかけてスロークエリを特定する
3.1 pgbenchで負荷をかける
まずpgbenchでデフォルトの実行方法で負荷を60秒かけ、統計情報を蓄積させます。
postgresql.confの設定は以前のこちらで試した設定内容にて実施しています(work_memだけ 64MBで実施)。
$ sudo pgbench -c 30 -j 2 -T 60 -U postgres pgbench_test
(省略)
latency average = 23.964 ms
initial connection time = 230.523 ms
tps = 1251.894647 (without initial connection time)
3.2 累積実行時間が長いクエリを特定
最も基本的な確認です。「合計でどのクエリが時間を食っているか」を特定します。./pgsql/pg_stat_statements.sqlとして、下記のSQLを保存します。
SELECT
LEFT(query, 80) AS query,
calls,
ROUND(total_exec_time::numeric, 1) AS total_ms,
ROUND(mean_exec_time::numeric, 2) AS mean_ms,
ROUND(stddev_exec_time::numeric, 2) AS stddev_ms,
rows
FROM pg_stat_statements
ORDER BY total_exec_time DESC
LIMIT 10;
統計情報を取得するSQLの実行結果です。
$ psql -U postgres -d pgbench_test -f ./pgsql/pg_stat_statements.sql
query | calls | total_ms | mean_ms | stddev_ms | rows
--------------------------------------------------------------------------------------------------------------------------------------
UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2 | 93705 | 4156875.1 | 44.36 | 32.09 | 93705
UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2 | 74903 | 1249641.0 | 16.68 | 16.74 | 74903
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 93705 | 62160.8 | 0.66 | 3.23 | 93705
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 93705 | 38086.3 | 0.41 | 4.11 | 93705
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 74903 | 37047.1 | 0.49 | 2.91 | 74903
copy pgbench_accounts from stdin with (freeze on) | 1 | 13033.0 | 13032.97 | 0.00 | 7500000
INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES ($1, $2, $3, $4 | 93705 | 12396.8 | 0.13 | 2.57 | 93705
alter table pgbench_accounts add primary key (aid) | 1 | 11568.0 | 11568.04 | 0.00 | 0
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 74903 | 7739.3 | 0.10 | 1.20 | 74903
vacuum analyze pgbench_accounts | 1 | 5108.0 | 5107.98 | 0.00 | 0
(10 rows)
システムに最も負荷をかけているのは、total_ms が大きいクエリです。mean_msが平均実行時間で、stddev_ms が大きいクエリは実行時間にばらつきがあり、ロック待ち(lock wait)や I/O スパイクの影響を受けている可能性があります。
3.3 ディスクI/Oが多いクエリを特定
shared_blks_read が多いクエリはキャッシュ(cache)に乗っていない、もしくはSeq Scanしているクエリです。./pgsql/pg_stat_statements_blks.sqlとして、下記のSQLを保存します。
SELECT
LEFT(query, 80) AS query,
calls,
shared_blks_hit,
shared_blks_read,
ROUND(shared_blks_read * 100.0
/ NULLIF(shared_blks_hit + shared_blks_read, 0), 1) AS cache_miss_pct,
temp_blks_written
FROM pg_stat_statements
WHERE shared_blks_read > 0
ORDER BY shared_blks_read DESC
LIMIT 10;
統計情報(ディスクI/O関係)を取得します。
$ psql -U postgres -d pgbench_test -f ./pgsql/pg_stat_statements_blks.sql
query | calls | shared_blks_hit | shared_blks_read | cache_miss_pct | temp_blks_written
-------------------------------------------------------------------------------------------------------------------------------------------------------------------
UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2 | 93705 | 380815 | 186179 | 32.8 | 0
UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2 | 74903 | 641870 | 148274 | 18.8 | 0
alter table pgbench_accounts add primary key (aid) | 1 | 284 | 122791 | 99.8 | 36710
vacuum analyze pgbench_accounts | 1 | 175 | 29969 | 99.4 | 0
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 93705 | 474976 | 1282 | 0.3 | 0
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 74903 | 381500 | 106 | 0.0 | 0
INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES ($1, $2, $3, $4 | 93705 | 95952 | 76 | 0.1 | 0
drop table if exists pgbench_accounts, pgbench_branches, pgbench_history, pgbenc | 1 | 732 | 37 | 4.8 | 0
INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES ($1, $2, $3, $4 | 74903 | 76235 | 32 | 0.0 | 0
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 93705 | 436360 | 29 | 0.0 | 0
(10 rows)
| カラム | 意味 | 判断基準 |
|---|---|---|
cache_miss_pct |
キャッシュミス率(cache miss rate) | 高いほどディスクI/Oが発生している |
temp_blks_written |
一時ファイル書き込み | 0以外 → 一時ファイルへの書き込みが発生 |
3.4 実行頻度が多いクエリを特定
実行回数(calls)が多いクエリは、1回あたりが軽くても累積で大きな負荷になります。./pgsql/pg_stat_statements_calls.sqlとして、下記のSQLを保存します。
SELECT
LEFT(query, 80) AS query,
calls,
ROUND(mean_exec_time::numeric, 3) AS mean_ms,
ROUND(total_exec_time::numeric, 1) AS total_ms,
ROUND((calls * mean_exec_time / 1000.0)::numeric, 1) AS total_sec
FROM pg_stat_statements
ORDER BY calls DESC
LIMIT 10;
mean_ms が小さくても calls が多いクエリは、インデックス追加等の対策検討対象SQLになります。
$ psql -U postgres -d pgbench_test -f ./pgsql/pg_stat_statements_calls.sql
query | calls | mean_ms | total_ms | total_sec
----------------------------------------------------------------------------------------------------------------------------
END | 168609 | 0.001 | 121.3 | 0.1
BEGIN | 168609 | 0.001 | 101.4 | 0.1
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 93705 | 0.406 | 38086.3 | 38.1
INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES ($1, $2, $3, $4 | 93705 | 0.132 | 12396.8 | 12.4
UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2 | 93705 | 44.361 | 4156875.1 | 4156.9
SELECT abalance FROM pgbench_accounts WHERE aid = $1 | 93705 | 0.022 | 2022.1 | 2.0
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 93705 | 0.663 | 62160.8 | 62.2
UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2 | 74903 | 16.683 | 1249641.0 | 1249.6
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 74903 | 0.495 | 37047.1 | 37.0
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 74903 | 0.103 | 7739.3 | 7.7
(10 rows)
3.5 実行時間のばらつきが大きいクエリを特定
stddev_exec_time が mean_exec_time より大きいクエリは実行時間が不安定で、ロック待ちやI/Oスパイクの影響を受けている可能性があります。./pgsql/pg_stat_statements_stddev.sqlとして、下記のSQLを保存します。
SELECT
LEFT(query, 80) AS query,
calls,
ROUND(mean_exec_time::numeric, 2) AS mean_ms,
ROUND(stddev_exec_time::numeric, 2) AS stddev_ms,
ROUND((stddev_exec_time / NULLIF(mean_exec_time, 0))::numeric, 2) AS cv -- 変動係数(coefficient of variation)
FROM pg_stat_statements
WHERE calls > 100
ORDER BY cv DESC
LIMIT 10;
変動係数(CV:coefficient of variation)が1.0を超えるクエリは特に不安定です。pg_locks / pg_stat_activity との組み合わせでロック競合(lock contention)の有無を確認します。
$ psql -U postgres -d pgbench_test -f ./pgsql/pg_stat_statements_stddev.sql
query | calls | mean_ms | stddev_ms | cv
-----------------------------------------------------------------------------------------------------------------------
END | 168609 | 0.00 | 0.03 | 39.04
INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES ($1, $2, $3, $4 | 93705 | 0.13 | 2.57 | 19.45
BEGIN | 168609 | 0.00 | 0.01 | 16.92
INSERT INTO pgbench_history (tid, bid, aid, delta, mtime) VALUES ($1, $2, $3, $4 | 74903 | 0.07 | 1.11 | 16.62
SELECT abalance FROM pgbench_accounts WHERE aid = $1 | 93705 | 0.02 | 0.32 | 14.82
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 74903 | 0.10 | 1.20 | 11.57
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 93705 | 0.41 | 4.11 | 10.12
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 74903 | 0.49 | 2.91 | 5.89
SELECT abalance FROM pgbench_accounts WHERE aid = $1 | 74903 | 0.02 | 0.09 | 5.69
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 93705 | 0.66 | 3.23 | 4.87
(10 rows)
3.6 統計情報を活用して
それぞれの内容を確認していると、pgbench_accountsに対する更新処理に時間がかかっていそうです。pgbench_accountsは約1.1GBあり、変更前のshared_buffers = 8MBであり、OSの総メモリも超えている状態のため、全てのアクセスがディスクに落ちる状態が想像されます。最大のデータサイズのテーブルのデータが共有メモリに保持出来ていないといった事象が想像できます。
なお、postgresql.confは、こちらのように実施しています。
| 項目 | 変更前 | 変更後 |
|---|---|---|
| shared_buffers | 8MB | 256MB |
| work_mem | 64MB | 64MB |
| checkpoint_timeout | 30s | 15min |
| checkpoint_completion_target | 0.001 | 0.9 |
| bgwriter_delay | 10s | 100ms |
| bgwriter_lru_maxpages | 0 | 300 |
| bgwriter_lru_multiplier | 2 | (今回は影響なし) |
| max_wal_size | 126MB | 4GB |
また、本来はoffにしませんが、synchronous_commitもoffにしています。 |
# キャッシュクリア
$ sudo systemctl stop postgresql
$ sync && echo 3 | sudo tee /proc/sys/vm/drop_caches
$ sudo systemctl start postgresql
$ psql -U postgres -d pgbench_test -c "SELECT pg_stat_statements_reset();"
# 負荷をかけてみる
$ sudo pgbench -c 30 -j 2 -T 60 -U postgres pgbench_test
(省略)
latency average = 19.730 ms
initial connection time = 229.832 ms
tps = 1520.510065 (without initial connection time)
共有バッファ等を変更したので、ディスク読み込みが発生ているかを確認してみます。結果としては、shared_blks_readが大幅に改善していたり、temp_blks_writtenがすべて0になっていたりと改善を確認する事ができました。
$ psql -U postgres -d pgbench_test -f ./pgsql/pg_stat_statements_blks.sql
query | calls | shared_blks_hit | shared_blks_read | cache_miss_pct | temp_blks_written
------------------------------------------------------------------------------------------------------------------------------------------------------------------
UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2 | 90981 | 649972 | 114035 | 14.9 | 0
UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2 | 90981 | 456503 | 38 | 0.0 | 0
vacuum pgbench_branches | 1 | 25 | 8 | 24.2 | 0
vacuum pgbench_tellers | 1 | 48 | 6 | 11.1 | 0
UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2 | 90981 | 466148 | 5 | 0.0 | 0
select count(*) from pgbench_branches | 1 | 0 | 3 | 100.0 | 0
truncate pgbench_history | 1 | 27 | 3 | 10.0 | 0
select o.n, p.partstrat, pg_catalog.count(i.inhparent) from pg_catalog.pg_class | 1 | 52 | 2 | 3.7 | 0
(8 rows)
4. まとめ
4.1 スロークエリ特定までの流れ
パフォーマンスが出ない
│
├─ pg_stat_statements で total_exec_time 上位を確認
│ └─ 累積で時間を食っているクエリを特定
│
├─ shared_blks_read が多いクエリを確認
│ └─ cache_miss_pct が高い → インデックス追加・shared_buffers見直し
│ └─ temp_blks_written が多い → work_mem を増やす
│
├─ calls が多いクエリを確認
│ └─ mean_ms が小さくても total_ms が大きい → 高頻度クエリの最適化
│
└─ stddev_exec_time が大きいクエリを確認
└─ ロック待ちやI/Oスパイクの影響 → pg_locks と組み合わせて調査
4.2 pg_stat_statementsの活用場面
| 目的 | 使うカラム | 組み合わせるツール |
|---|---|---|
| 重いクエリの特定 |
total_exec_time / mean_exec_time
|
EXPLAIN ANALYZE で実行計画を確認 |
| I/Oボトルネックの特定 |
shared_blks_read / temp_blks_written
|
pg_statio_user_tables |
| ロック競合の疑い |
stddev_exec_time / cv
|
pg_locks / pg_stat_activity
|
| 高頻度クエリの最適化 | calls |
インデックス追加・クエリキャッシュ検討 |
⚠️ 注意点
pg_stat_statementsはPostgreSQLの再起動またはデータベースの再接続後も統計を保持します。定期的にpg_stat_statements_reset()を実行して古い統計をクリアしないと、過去のスパイクが現在の判断に影響することがあります。本番環境では「計測期間を決めてリセット→計測→確認」のサイクルで運用するのが効果的です。
pg_stat_statementsの統計は、本番環境でどのクエリが問題を起こしているかを「証拠として」示してくれます。勘や経験に頼らず、total_exec_time・shared_blks_read・stddev_exec_timeといった数値を起点にボトルネックを絞り込む習慣をつけることが、PostgreSQLチューニングの第一歩です。
特定したクエリに対しては、次のステップとしてEXPLAIN ANALYZEによる実行計画の読み解きが待っています。「どのクエリが遅いか」をpg_stat_statementsで見つけ、「なぜ遅いか」をEXPLAIN ANALYZEで掘り下げる——この2段構えが本番チューニングの基本サイクルです。