PostgreSQL 12 min read

PostgreSQLの「deadlock detected」 ― どちらが止まるかとサーバーログでの追い方

2つのトランザクションが互いの行ロックを待つと、PostgreSQL は片方を止めて次のエラーを返します。

ERROR:  deadlock detected
DETAIL:  Process 604 waits for ShareLock on transaction 821; blocked by process 603.
Process 603 waits for ShareLock on transaction 820; blocked by process 604.
HINT:  See server log for query details.
CONTEXT:  while updating tuple (0,2) in relation "accounts"

SQLSTATE は 40P01 です。この記事のログは PostgreSQL 17.6 で採りました（\set VERBOSITY verbose で SQLSTATE を出し、LOCATION: 行は省いています）。

まず見る（結論）

  • エラーを受けた側は ROLLBACK してから、トランザクションを最初からやり直す
  • 相手の SQL はクライアントのエラーには出ない。サーバーログの DETAIL に両方の SQL が出る
  • 再発を防ぐには、複数の行を更新する処理で行をロックする順番をそろえる

再現した手順

表 accounts に id=1 と id=2 の2行を入れ、2つのセッションで逆の順番に更新しました。

順 セッション A セッション B
1 BEGIN;
UPDATE accounts SET balance=balance-10 WHERE id=1;
2 BEGIN;
UPDATE accounts SET balance=balance-10 WHERE id=2;
3 UPDATE ... WHERE id=2;（B を待つ）
4 UPDATE ... WHERE id=1;（A を待つ）

4 の時点で、A は B を、B は A を待っています。このときは A が冒頭のエラーで止まり、B の UPDATE は UPDATE 1 で通りました。B は COMMIT でき、表は2行とも 90 になりました。

UPDATE を SELECT ... FOR UPDATE に置き換えても同じ結果です。CONTEXT が while locking tuple (0,38) in relation "accounts" に変わるだけでした。

どちらが止まるか

PostgreSQL はロックを待ち始めてすぐにはデッドロックを調べません。deadlock_timeout（既定 1s）だけ待ってから、待ちの輪ができているかを調べます。輪を見つけたセッションが自分のトランザクションを止めます。

上の手順では、A が先に待ち始め、B は約 0.5 秒後に待ち始めました。A が 1 秒たって調べたときには輪ができていたので、A が止まりました。\timing on で測った時間です。

-- セッション A（3 の UPDATE）
Time: 1001.047 ms (00:01.001)
ERROR:  40P01: deadlock detected

-- セッション B（4 の UPDATE）
UPDATE 1
Time: 500.860 ms

B が待ち始めるのを 1.5 秒遅らせた回では、止まったのは後から待ち始めた側でした。A が 1 秒たって調べた時点では輪ができておらず、A はそのまま待ち続けました。その後、B が待ち始めてから 1 秒後に輪を見つけ、B が止まりました。止まるのは、先に待ったか後に待ったかに関係なく、輪ができた後で最初に調べたセッションです。

両方のセッションで SET deadlock_timeout = '5s'; にすると、A のエラーが返るまでの時間は 5001.447 ms に延びました。値を大きくするとデッドロックの検出が遅れ、その間は両方とも止まったままです。

エラーを受けた後のトランザクション

止められたトランザクションの中では、何を実行してもエラーになります。

SELECT 1;
ERROR:  25P02: current transaction is aborted, commands ignored until end of transaction block
ROLLBACK;
ROLLBACK
SELECT 1;
 ?column?
----------
        1
(1 row)

アプリでは、40P01 を受けたら ROLLBACK し、トランザクションの最初からやり直します。止められた SQL だけを再実行しても、それより前の更新は取り消されています。

サーバーログで相手の SQL を見る

クライアントに返る DETAIL にはプロセス ID しか出ません。HINT のとおり、サーバーログには両方の SQL が残ります。

ERROR:  deadlock detected
DETAIL:  Process 627 waits for ShareLock on transaction 830; blocked by process 625.
	Process 625 waits for ShareLock on transaction 829; blocked by process 627.
	Process 627: UPDATE accounts SET balance=balance-10 WHERE id=2;
	Process 625: UPDATE accounts SET balance=balance-10 WHERE id=1;
HINT:  See server log for query details.
CONTEXT:  while updating tuple (0,16) in relation "accounts"
STATEMENT:  UPDATE accounts SET balance=balance-10 WHERE id=2;

出るのは、輪ができた時点で待っていた SQL です。その前に同じトランザクションで実行した UPDATE は出ません。上の例でも、A が先に id=1 を、B が先に id=2 を更新したことはログからは分かりません。どの行をどの順で触る処理なのかは、SQL からアプリのコードを辿って確かめます。

ロック待ちをログに出す（log_lock_waits）

log_lock_waits（既定 off）を on にすると、deadlock_timeout を超えたロック待ちがログに出ます。再起動は要りません。

ALTER SYSTEM SET log_lock_waits = on;
SELECT pg_reload_conf();

B を 1.5 秒遅らせた回のログです（ERROR 以降の行は省きました）。

07:03:25.453 UTC [643] LOG:  process 643 still waiting for ShareLock on transaction 833 after 1000.641 ms
07:03:26.953 UTC [641] LOG:  process 641 detected deadlock while waiting for ShareLock on transaction 832 after 1000.306 ms
07:03:26.953 UTC [641] ERROR:  deadlock detected
07:03:26.953 UTC [643] LOG:  process 643 acquired ShareLock on transaction 833 after 2501.344 ms

デッドロックにならない長いロック待ちも still waiting で残るので、デッドロックの手前で起きている待ちを追えます。

待っている最中に調べる

A が B を待っている間（4 の前）に、3本目のセッションから見た結果です。

SELECT pid, wait_event_type, wait_event, state, query
  FROM pg_stat_activity WHERE datname = 'dldb';
 pid | wait_event_type |  wait_event   |        state        |                       query
-----+-----------------+---------------+---------------------+----------------------------------------------------
 654 | Client          | ClientRead    | idle in transaction | UPDATE accounts SET balance=balance-10 WHERE id=2;
 655 | Lock            | transactionid | active              | UPDATE accounts SET balance=balance-10 WHERE id=2;

SELECT pid, pg_blocking_pids(pid) FROM pg_stat_activity WHERE datname = 'dldb';
 pid | pg_blocking_pids
-----+------------------
 654 | {}
 655 | {654}

654（B）は idle in transaction で、更新した後にコミットしないまま次の SQL を待っています。query 列は最後に実行した SQL です。行ロックの待ちは pg_locks では locktype = transactionid の ShareLock として出ます。待っているのは行ではなく、その行を更新したトランザクションの終了です。

更新の順番をそろえる

A と B の両方が id=1 → id=2 の順に更新すると、デッドロックは起きませんでした。B は id=1 で A の COMMIT を待ち、その後に両方が COMMIT できました。

複数の行を1つのトランザクションで更新する処理は、主キーの昇順など決まった順番でロックを取るようにします。順番をそろえられない場合は、40P01 を受けたらトランザクションごとやり直す処理をアプリに入れておきます。

RELATED PostgreSQL