0
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

@matsutomu

PostgreSQL16の待機イベントを観察する ─ pg_stat_activityとpg_locksでボトルネックを特定する

0
Last updated at Posted at 2026-05-05

1. はじめに

本記事では、待機イベントやロックについて理解しつつ、その他のボトルネックになる事象について取り扱います。原因の調査には pg_stat_activity の wait_event が手がかりになりますが、実際に観察してみると ロック待ち（Lock）だけでなく、共有バッファ競合（BufferIO）やWAL書き込み（WALWrite） など、複数の待機イベントがボトルネックになりえることがわかります。

SQLの実行条件やpgbench の並列数（-c）を段階的に変えながら、pg_stat_activity と pg_locks で待機イベントをリアルタイムに観察し、ボトルネック（bottleneck）の種類と特定方法を整理します。

1.1 検証環境

項目 内容
OS AmazonLinux2023
PostgreSQL 16
インスタンスタイプ t3.micro (2 vCPU、1GiB)
データ pgbench scale factor 100（約1,500万行）

パラメータは以下のように設定しています。

パラメータ 値 理由・狙い
shared_buffers 256MB 搭載メモリの25%程度。これ以上増やすとOS側のメモリが枯渇し、挙動が不安定になります。
work_mem 4MB pgbenchの並列度（-c）を上げた際、接続数 × work_mem のメモリが消費されます。t3.microで並列度50〜100を試すなら、小さく保たないと即座に落ちます。
min_wal_size 512MB WALファイルの削除・再作成のオーバーヘッド（LWLockの原因の一つ）を減らすため、少し多めに確保しておきます。
max_wal_size 2GB ロック観察中にチェックポイントが走ると、I/O負荷で待機イベントが書き換わってしまいます。大きくしてチェックポイントを遠ざけます。
checkpoint_timeout 15min チェックポイント間隔を長くしておきます。
checkpoint_completion_target 0.9 書き込みを穏やかにしておきます。

pgbenchの初期化をスケール100で実行します。

$ pgbench -i -s 100 -U postgres pgbench_test

1.2 ロック（Lock）の基本

PostgreSQLのロックは大きく2種類あります。

種類 説明 例
テーブルロック テーブル単位のロック SELECT（AccessShare）、ALTER TABLE（AccessExclusive）
行ロック 行単位のロック UPDATE、SELECT FOR UPDATE

通常のSELECT/UPDATEで問題になるのはほぼ行ロックですが、DDL（ALTER TABLE など）は強いテーブルロックを取るため、本番環境での実行には注意が必要です。

ロックの競合マトリクスの主要なものは以下の通りです。

保持中のロック 待たされるロック
RowExclusiveLock（UPDATE/DELETE） ShareLock、ExclusiveLock
ShareUpdateExclusiveLock（VACUUM） ShareUpdateExclusiveLock、ShareLock、ExclusiveLock
AccessExclusiveLock（ALTER TABLE） すべてのロック

1.3 使用するSQL

負荷テスト用SQL（./pgsql/lock_test_sleep.sql）

aid を狭い範囲（10000〜10100）に絞ることで、同じ行への競合を意図的に発生させます。

\set aid random(10000, 10100)

BEGIN;
-- インデックスアクセスを無効化用
-- ステップ1で実行する際のみコメントアウトをはずします。
-- SET enable_indexscan = off;
-- SET enable_bitmapscan = off;

-- 更新用にデータをロック
SELECT abalance FROM pgbench_accounts WHERE aid = :aid FOR UPDATE;
-- 0.5秒保持して他のクライアントを待たせる
SELECT pg_sleep(0.5);
-- 更新
UPDATE pgbench_accounts SET abalance = abalance + 1 WHERE aid = :aid;
COMMIT;

状況確認用SQL（./pgsql/pg_stat_act.sql）

SELECT pid, state, wait_event_type, wait_event,
       ROUND(EXTRACT(EPOCH FROM (NOW() - query_start))::numeric, 1) AS elapsed_sec
FROM pg_stat_activity
WHERE state != 'idle' AND pid != pg_backend_pid()
ORDER BY elapsed_sec DESC;

ロック待ち連鎖確認用SQL（./pgsql/pg_locks_info.sql）

SELECT
  blocked.pid                              AS blocked_pid,
  LEFT(blocked.query, 60)                  AS blocked_query,
  blocking.pid                             AS blocking_pid,
  LEFT(blocking.query, 60)                 AS blocking_query,
  blocked_locks.locktype,
  blocked_locks.mode                       AS waiting_mode,
  blocking_locks.mode                      AS holding_mode,
  NOW() - blocked.query_start              AS waiting_duration
FROM pg_locks AS blocked_locks
JOIN pg_stat_activity AS blocked
  ON blocked.pid = blocked_locks.pid
JOIN pg_locks AS blocking_locks
  ON blocking_locks.transactionid = blocked_locks.transactionid
  AND blocking_locks.granted = true
  AND blocking_locks.pid != blocked_locks.pid
JOIN pg_stat_activity AS blocking
  ON blocking.pid = blocking_locks.pid
WHERE blocked_locks.granted = false
ORDER BY waiting_duration DESC;

以上のSQLを使用しながら、ロックについて理解を深めていきます。

2. 待機イベントをリアルタイムで観察する

2.1 pg_stat_activityで待機イベントの種類を把握する

まず、どのような待機イベントが発生するかを段階的に確認します。別々のターミナルを2つ用意します。

ターミナル1（監視）

$ watch -n 3 "psql -U postgres -d pgbench_test -f ./pgsql/pg_stat_act.sql"

ターミナル2（負荷）

$ pgbench -c 10 -j 2 -T 60 -P 5 -U postgres pgbench_test -f ./pgsql/lock_test_sleep.sql

ステップ1：インデックスを無効化した場合（SeqScan強制）

負荷テスト用SQLに SET enable_indexscan = off と SET enable_bitmapscan = off を実行してSeqScanを強制すると、wait_event_type に IPC、wait_event に BufferIO が現れます。

  pid  | state  | wait_event_type | wait_event | elapsed_sec
-------+--------+-----------------+------------+-------------
 18397 | active | IPC             | BufferIO   |         4.9
 （他9件も同様）

実行結果も記載します。

pgbench (16.12)
starting vacuum...end.
progress: 5.0 s, 0.0 tps, lat 0.000 ms stddev 0.000, 0 failed
（省略）
latency average = 19177.987 ms
latency stddev = 2963.592 ms
initial connection time = 78.460 ms
tps = 0.521133 (without initial connection time)

BufferIO は、shared_buffers 上の同一ページに読み取り・書き込みが集中しているときの待機イベントです。インデックスを使わないSeqScanにより、バッファ競合が激しくなっています。

ステップ2：インデックスを有効に戻した場合

SeqScan強制の設定をコメントアウトし、インデックスが使われる状態で再実行します。wait_event_type が Lock に変わり、transactionid（コミット待ち）や tuple（行ロック待ち）が現れます。

  pid  | state  | wait_event_type |  wait_event   | elapsed_sec
-------+--------+-----------------+---------------+-------------
 19554 | active | Timeout         | PgSleep       |         0.0
 19556 | active | Lock            | transactionid |         0.0
 19560 | active | Lock            | tuple         |         0.0
 （省略）

pgbench (16.12)
starting vacuum...end.
progress: 5.0 s, 17.2 tps, lat 522.399 ms stddev 91.998, 0 failed
（省略）
latency average = 524.473 ms
latency stddev = 108.218 ms
initial connection time = 77.902 ms
tps = 19.064700 (without initial connection time)

BufferIO 競合は解消されてTPSは大きく改善しましたが、pg_sleep(0.5) による意図的な待機がロック保持時間を引き延ばしているため、Lock 待ちが発生しています。

ステップ3：pg_sleepも除去した場合

pg_sleep をコメントアウトすると、今度は LWLock の WALWrite が大半を占めます。

  pid  |        state        | wait_event_type | wait_event | elapsed_sec
-------+---------------------+-----------------+------------+-------------
 20308 | active              | LWLock          | WALWrite   |         0.0
 20311 | active              | IO              | WALSync    |         0.0
 （他8件も同様）

pgbench (16.12)
starting vacuum...end.
progress: 5.0 s, 4066.9 tps, lat 2.418 ms stddev 0.572, 0 failed
（省略）
latency average = 2.465 ms
latency stddev = 0.668 ms
initial connection time = 78.360 ms
tps = 4054.989843 (without initial connection time)

行ロック競合は解消されてTPSは大幅に改善しましたが、今度はWAL（Write Ahead Log）の書き出しがボトルネックになっています。

ステップ4：synchronous_commitをoffにした場合

注意
synchronous_commit = off にすると、クラッシュ時に最大で wal_writer_delay の3倍（デフォルト約0.6秒）分のコミット済みデータが消失するリスクがあります。実運用での使用は要件を慎重に確認してください。

WAL同期の待機を回避するために synchronous_commit = off を設定して再実行します。

  pid  |        state        | wait_event_type | wait_event | elapsed_sec
-------+---------------------+-----------------+------------+-------------
 20597 | idle in transaction |                 |            |         0.0
 20596 | idle in transaction |                 |            |         0.0
 20598 | active              |                 |            |         0.0
 20600 | idle in transaction |                 |            |         0.0
 20601 | idle in transaction |                 |            |         0.0
 20602 | idle in transaction |                 |            |         0.0
 20603 | idle in transaction | Client          | ClientRead |         0.0
 20604 | idle in transaction |                 |            |         0.0
 20605 | idle in transaction | Client          | ClientRead |         0.0
(9 rows)

pgbench (16.12)
starting vacuum...end.
progress: 5.0 s, 6180.7 tps, lat 1.591 ms stddev 0.726, 0 failed
（省略）
latency average = 1.549 ms
latency stddev = 0.476 ms
initial connection time = 80.454 ms
tps = 6452.170139 (without initial connection time)

待機イベントがほぼ消え、TPSが大きく向上しました。

実行結果のまとめ（ステップ1から4の結果）

条件 主な wait_event TPS
SeqScan強制 IPC / BufferIO 約0.5
インデックス有効（pg_sleep有り） Lock / transactionid, tuple 約19
pg_sleep除去 LWLock / WALWrite 約4,055
synchronous_commit off （ほぼなし） 約6,452

待機イベントごとに原因と対処が異なります。Lock だけがボトルネックではなく、共有バッファやWALも絡んでくることが確認できました。

wait_event_type wait_event 意味
IPC BufferIO shared_buffers上の同一ページへの読み書き集中
Lock transactionid トランザクションのコミット待ち
Lock tuple 他トランザクションが同じ行を更新中
Lock relation テーブルロック待ち（DDLなど）
LWLock WALWrite WALバッファへの書き込み待ち
IO WALSync WALのディスク同期（fsync）待ち
Client ClientRead クライアントからの入力待ち（正常）

ステップ5（おまけ）：更に並列度を50にした場合

並列度を50に変更して実行した場合も確認します。

$ pgbench -c 50 -j 2 -T 60 -P 5 -U postgres pgbench_test -f ./pgsql/lock_test_sleep.sql
pgbench (16.12)
starting vacuum...end.
progress: 5.0 s, 4183.5 tps, lat 11.006 ms stddev 4.179, 0 failed
（省略）
latency average = 10.937 ms
latency stddev = 3.277 ms
initial connection time = 384.431 ms
tps = 4569.233679 (without initial connection time)

並列度を上げると接続確立のオーバーヘッド（initial connection time）が増え、レイテンシも上昇します。並列数とTPSのトレードオフを確認する際の参考値として記録しておきます。

2.2 pg_locksでロック待ちの連鎖（lock chain）を可視化する

pg_stat_activity で wait_event_type = 'Lock' が確認できたら、次は pg_locks を使って「どのプロセスが何をブロックしているか」を特定します。

ターミナル1で監視クエリを起動しておきます。

watch -n 3 "psql -U postgres -d pgbench_test -f ./pgsql/pg_locks_info.sql"

競合をより顕著に再現するため、負荷テスト用SQLのパラメータを変更します。aid の範囲を6行（10000〜10005）に絞り、pg_sleep を2秒に伸ばします。

\set aid random(10000, 10005)

BEGIN;
SELECT abalance FROM pgbench_accounts WHERE aid = :aid FOR UPDATE;
SELECT pg_sleep(2);   -- 2秒保持して他のクライアントを待たせる
UPDATE pgbench_accounts SET abalance = abalance + 1 WHERE aid = :aid;
COMMIT;

並列数50で実行します。

$ pgbench -c 50 -j 4 -T 60 -P 5 -U postgres pgbench_test -f ./pgsql/lock_test_sleep.sql

ロック待ち連鎖クエリの結果を確認すると、各プロセスが pg_sleep(2) を実行中のプロセスに最大26秒以上待たされていることが可視化されます。

 blocked_pid |                   blocked_query                    | blocking_pid |     blocking_query     |   locktype    | waiting_mode | holding_mode  | waiting_duration
-------------+----------------------------------------------------+--------------+------------------------+---------------+--------------+---------------+------------------
        9389 | SELECT abalance FROM pgbench_accounts WHERE aid = 10003 ... |  9420 | SELECT pg_sleep(2); | transactionid | ShareLock    | ExclusiveLock | 00:00:26.782884
        9382 | SELECT abalance FROM pgbench_accounts WHERE aid = 10001 ... |  9426 | SELECT pg_sleep(2); | transactionid | ShareLock    | ExclusiveLock | 00:00:24.778733
        9380 | SELECT abalance FROM pgbench_accounts WHERE aid = 10000 ... |  9406 | SELECT pg_sleep(2); | transactionid | ShareLock    | ExclusiveLock | 00:00:18.766352
        9385 | SELECT abalance FROM pgbench_accounts WHERE aid = 10004 ... |  9379 | SELECT pg_sleep(2); | transactionid | ShareLock    | ExclusiveLock | 00:00:10.741205
        9422 | SELECT abalance FROM pgbench_accounts WHERE aid = 10005 ... |  9408 | SELECT pg_sleep(2); | transactionid | ShareLock    | ExclusiveLock | 00:00:06.742328
        9403 | SELECT abalance FROM pgbench_accounts WHERE aid = 10002 ... |  9425 | SELECT pg_sleep(2); | transactionid | ShareLock    | ExclusiveLock | 00:00:04.740438
(6 rows)

waiting_mode = ShareLock、holding_mode = ExclusiveLock の組み合わせから、FOR UPDATE で排他ロックを保持したまま長時間待機しているトランザクションが後続を詰まらせていることがわかります。

3. デッドロック（Deadlock）を観察・対処する

デッドロックは、2つのトランザクションが互いに相手のロック解放を待っている状態です。PostgreSQLは自動でデッドロックを検出し、一方をロールバック（rollback）します。

3.1 デッドロックのログを有効にする

# postgresql.conf
log_lock_waits = on      # ロック待ちをログに記録
deadlock_timeout = 1s    # デッドロック検出までの待機時間（デフォルト: 1s）

設定の反映はリロードで可能です。

$ sudo systemctl reload postgresql

3.2 デッドロックを意図的に再現する

2つのターミナルで、互いに相手が保持している行を更新する操作を交差した順序で実行します。

ターミナル1

BEGIN;
UPDATE pgbench_accounts SET abalance = abalance + 100 WHERE aid = 1;
-- ここで待機。ターミナル2の操作を待つ

ターミナル2

BEGIN;
UPDATE pgbench_accounts SET abalance = abalance + 100 WHERE aid = 2;
UPDATE pgbench_accounts SET abalance = abalance + 100 WHERE aid = 1;  -- ターミナル1が保持中のためブロック

ターミナル1（続き）

UPDATE pgbench_accounts SET abalance = abalance + 100 WHERE aid = 2;  -- ターミナル2が保持中のためブロック
-- → デッドロック検出、どちらかがロールバック

デッドロック発生時にはpsqlのエラーとログの両方に記録されます。

psqlのエラー出力

ERROR:  deadlock detected
DETAIL:  Process 10343 waits for ShareLock on transaction 17007855; blocked by process 10425.
         Process 10425 waits for ShareLock on transaction 17007854; blocked by process 10343.
HINT:  See server log for query details.
CONTEXT:  while updating tuple (0,63) in relation "pgbench_accounts"

PostgreSQLログ（log_lock_waits = on の場合）

$ sudo tail -f /var/lib/pgsql/data/log/postgresql-Mon.log

2026-05-04 12:36:18.439 UTC [10343] DETAIL:  Process 10343 waits for ShareLock on transaction 17007855; blocked by process 10425.
    Process 10425 waits for ShareLock on transaction 17007854; blocked by process 10343.
    Process 10343: UPDATE pgbench_accounts SET abalance = abalance + 100 WHERE aid = 2;
    Process 10425: UPDATE pgbench_accounts SET abalance = abalance + 100 WHERE aid = 1;
2026-05-04 12:36:18.439 UTC [10343] HINT:  See server log for query details.
2026-05-04 12:36:18.439 UTC [10343] CONTEXT:  while updating tuple (0,63) in relation "pgbench_accounts"
2026-05-04 12:36:18.439 UTC [10343] STATEMENT:  UPDATE pgbench_accounts SET abalance = abalance + 100 WHERE aid = 2;
2026-05-04 12:36:18.439 UTC [10425] LOG:  process 10425 acquired ShareLock on transaction 17007854 after 16681.326 ms
2026-05-04 12:36:18.439 UTC [10425] CONTEXT:  while updating tuple (0,1) in relation "pgbench_accounts"
2026-05-04 12:36:18.439 UTC [10425] STATEMENT:  UPDATE pgbench_accounts SET abalance = abalance + 100 WHERE aid = 1;

ログには「どのプロセスが何を待っていたか」「どのSQLが原因か」が記録されます。デッドロックの根本対処は 複数行を更新する際の順序を統一すること です（例：常に aid の昇順で更新する）。

4. まとめ

4.1 観察から原因特定までの流れ

pg_stat_activityとpg_locksを利用して、統計情報から原因を特定してきました。

TPS が想定より低い
  │
  ├─ pg_stat_activity で wait_event_type を確認
  │    ├─ Lock       → ロック待ちが発生（2.1, 2.2節へ）
  │    ├─ LWLock     → WAL書き込み待ち（WAL設定を見直す）
  │    └─ IPC        → バッファ競合（shared_buffers・インデックス設計を見直す）
  │
  ├─ wait_event = Lock の場合、pg_locks_info.sql で blocking_pid を特定
  │    └─ blocking_query を確認 → どのSQLが原因か
  │
  └─ log_lock_waits のログで待ち時間・頻度を確認
       └─ deadlock なら更新順序の統一を検討

4.2 wait_eventごとの対処方針

今回、事象が確認できた事に対する対処方法です。

wait_event 原因 対処
BufferIO 共有バッファ関連のディスクIO待ち SQLチューニング（SeqScan見直し）、共有バッファサイズ見直し
transactionid トランザクションのコミット待ち SQLチューニング（本記事ではsleepをコメントアウト）
tuple 同じ行へのUPDATE競合 ホットスポット行の分散（bid分散など）
WALWrite WALバッファへの書き込み集中 synchronous_commit の緩和（要件次第）、WALサイズの調整

「すべてSQLチューニング」出来れば良いのですが、各イベント種類ごとに対処方法が変わってきます。postgresql.confの設定値の見直しや、AWSであればディスクIOの改善設定と適切な対処方法への決定につながります。

0
1
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
Sign upLogin
0
1

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?