MySQLのデッドロックを再現して、原因をログで確かめる(ERROR 1213と1205の違い)

MySQL
スポンサーリンク

MySQL(InnoDB)のデッドロックを、2つのセッションで更新の順番を逆にしてわざと起こし、原因をログで確かめる手順です。ERROR 1213 のメッセージ、SHOW ENGINE INNODB STATUS の LATEST DETECTED DEADLOCK、エラーログ(innodb_print_all_deadlocks)、performance_schema.data_locks の読み方と、ロック待ちのタイムアウト(ERROR 1205)との違いを、実際の出力で載せています。

結論

デッドロックとロック待ちのタイムアウトは、エラーの番号も、取り消される範囲も、記録される場所も違いました。今回の確認での違いです。MySQL 9.7.4 で、デッドロックの検出と取り消しの設定は既定のままにし、エラーログに出すための2つの設定(innodb_print_all_deadlocks と log_error_verbosity)を変え、タイムアウトを比べるときだけ片方の接続のロック待ちの上限を5秒にしました。

デッドロックロック待ちのタイムアウト
エラーERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transactionERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
起きる条件2つのトランザクションが、お互いの持つロックを待つ形になったとき。InnoDB がすぐに見つけて、片方を取り消すほかのトランザクションが持つロックを、innodb_lock_wait_timeout(既定50秒)より長く待ったとき
取り消される範囲トランザクション全体(START TRANSACTION からの変更がすべて消える)待っていた文だけ(既定の innodb_rollback_on_timeout=OFF のとき)。トランザクションは続き、それまでのロックも持ったまま
原因の記録SHOW ENGINE INNODB STATUS の LATEST DETECTED DEADLOCK(最後の1件だけ)。innodb_print_all_deadlocks=ON にすると、毎回エラーログに出るエラーログには何も出なかった(log_error_verbosity を3にした状態で確認)
アプリでの扱いトランザクションを最初からやり直す文をやり直すか、ROLLBACK してトランザクションをやり直す
  • デッドロックの原因は、LATEST DETECTED DEADLOCK の「HOLDS THE LOCK(S)(持っているロック)」と「WAITING FOR THIS LOCK TO BE GRANTED(待っているロック)」を、2つのトランザクションで見比べて読みます。最後の WE ROLL BACK TRANSACTION (2) が、取り消された側です。
  • そこに出る文は、デッドロックの時点で実行中だった文だけです。先にロックを取った文(今回は最初の UPDATE)は出ません。
  • ロック待ちが起きている最中なら、performance_schema.data_locks と sys.innodb_lock_waits で、誰がどの行のロックを持ち、誰が待っているかを見られます。
  • エラーログに出すときは、innodb_print_all_deadlocks だけでなく log_error_verbosity を3にします。既定の2のままだと、詳細の行は出ても、見出しの行と「どちらを取り消したか」の行が出ませんでした。
  • 更新する行の順番を2つのセッションでそろえると、片方が待つだけで、デッドロックにはなりませんでした。

動作確認した環境

  • MySQL 9.7.4(長期サポートのLTS版。Dockerの公式イメージ mysql:9.7.4 を digest で固定)。クライアントも同じイメージの中の mysql 9.7.4
  • ストレージエンジン InnoDB、分離レベルは既定の REPEATABLE READ のまま
  • Docker 29.7.2(Windows 11 の Docker Desktop、Linuxコンテナ、x86_64)、PowerShell 7.6.5
  • 確認日: 2026年11月9日

この記事は、MacとWindowsの両方の読者を対象にしています。MySQLはDockerのコンテナで動かし、SQLはコンテナの中の mysql クライアントで打つので、MacでもWindowsでも同じ手順です。ホストのシェルで書き方が変わるところ(ログの絞り込み)は、Mac(ターミナル)とWindows(PowerShell)の両方を載せています。

この記事のコマンドは、Claude(AI)が実行して確認しました。本文の出力は、新しいコンテナで上から順に実行した結果です。3つのターミナルの mysql は、人が端末で打つのと同じ対話モードで動かしましたが、Claudeの実行環境には端末がないため、ホストからの docker exec -it ではなく、コンテナの中の擬似端末で開いて、1行ずつSQLを送りました。PowerShellのコマンド(PS> で始まるもの)は、Windows 11 の PowerShell 7 で実行しました。Macでは確認していません。

準備

MySQLのコンテナを起動します。pass は検証用のパスワードです。イメージはタグ(9.7.4)で版が決まり、digest(@sha256:...)は同じイメージを取るためにつけています。MacのターミナルでもWindowsのPowerShellでも、同じ1行です。

docker run -d --name tb-deadlock-mysql -e MYSQL_ROOT_PASSWORD=pass -e MYSQL_DATABASE=app mysql:9.7.4@sha256:df90258da46f6e7ff8574ff84f17618aba0765cac749928299c69fd4e7cb8ad8

初回の起動では、データベースの初期化に10秒ほどかかります(今回の確認で)。次の行が出たら準備ができています。

# Mac
$ docker logs tb-deadlock-mysql 2>&1 | grep 'ready for connections' | tail -n 1
# Windows(PowerShell)
PS> docker logs tb-deadlock-mysql 2>&1 | Select-String 'ready for connections' | Select-Object -Last 1

2026-11-09T00:56:45.691515Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '9.7.4'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server - GPL.

端末(Mac はターミナル、Windows は PowerShell)を3つ開き、それぞれで次のコマンドを実行して、mysql に接続します。パスワードを聞かれたら pass と打ちます。この記事では、3つをターミナルA、B、Cと呼びます。AとBでデッドロックを起こし、Cで様子を見ます。

docker exec -it tb-deadlock-mysql mysql -uroot -p app

ターミナルAの表示です(著作権の表示などは省略)。接続のIDは、Aが9、Bが10、Cが11でした。このIDは後でロックの持ち主を見分けるのに使います。

Enter password: 
Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 9
Server version: 9.7.4 MySQL Community Server - GPL

ターミナルAで、口座の残高のテーブルを作ります。

mysql> CREATE TABLE accounts (id INT PRIMARY KEY, name VARCHAR(20) NOT NULL, balance INT NOT NULL);
Query OK, 0 rows affected (0.015 sec)

mysql> INSERT INTO accounts VALUES (1, 'alice', 1000), (2, 'bob', 1000);
Query OK, 2 rows affected (0.007 sec)
Records: 2  Duplicates: 0  Warnings: 0

mysql> SELECT * FROM accounts;
+----+-------+---------+
| id | name  | balance |
+----+-------+---------+
|  1 | alice |    1000 |
|  2 | bob   |    1000 |
+----+-------+---------+
2 rows in set (0.000 sec)

ターミナルCで、関係する設定の値を見ておきます。デッドロックの検出は有効(innodb_deadlock_detect が1)、ロック待ちの上限は50秒、タイムアウトでトランザクション全体を取り消す設定は無効(0)、すべてのデッドロックをエラーログに出す設定は無効(0)、エラーログの詳しさは2でした。どれも既定の値です。

mysql> SELECT @@innodb_deadlock_detect, @@innodb_lock_wait_timeout, @@innodb_rollback_on_timeout, @@innodb_print_all_deadlocks, @@log_error_verbosity;
+--------------------------+----------------------------+------------------------------+------------------------------+-----------------------+
| @@innodb_deadlock_detect | @@innodb_lock_wait_timeout | @@innodb_rollback_on_timeout | @@innodb_print_all_deadlocks | @@log_error_verbosity |
+--------------------------+----------------------------+------------------------------+------------------------------+-----------------------+
|                        1 |                         50 |                            0 |                            0 |                     2 |
+--------------------------+----------------------------+------------------------------+------------------------------+-----------------------+
1 row in set (0.000 sec)

デッドロックを毎回エラーログに出すため、ターミナルCで2つの設定を変えます。log_error_verbosity を3にする理由は、後の「ハマりどころ」に書きました。SET GLOBAL の変更は、サーバーを再起動すると元に戻ります。

mysql> SET GLOBAL innodb_print_all_deadlocks = ON;
Query OK, 0 rows affected (0.000 sec)

mysql> SET GLOBAL log_error_verbosity = 3;
Query OK, 0 rows affected (0.000 sec)

デッドロックを起こす

AはID 1からID 2へ、BはID 2からID 1へ、100ずつ移す処理をします。更新する行の順番が、AとBで逆です。次の順番で打ちます。

順ターミナルAターミナルB
1START TRANSACTION; と ID 1 の UPDATE(ID 1 のロックを取る)
2START TRANSACTION; と ID 2 の UPDATE(ID 2 のロックを取る)
3ID 2 の UPDATE(Bが持つロックを待つ)
4ID 1 の UPDATE(Aが持つロックを待つ → デッドロック)

手順3のあと、Aが本当に待っていることをターミナルCで確かめてから(次の章)手順4に進みます。手順3と手順4の順番が入れ替わると、待つ側が逆になり、この記事と同じ出力になりません(その場合の出力は確かめていません)。

Aの待ちは、innodb_lock_wait_timeout(既定50秒)を過ぎると ERROR 1205 で終わってしまいます。手順3から手順4までは50秒以内に進めます。過ぎてしまったら、AとBの両方で ROLLBACK; を打ち、手順1からやり直します。

手順1(ターミナルA):

mysql> START TRANSACTION;
Query OK, 0 rows affected (0.000 sec)

mysql> UPDATE accounts SET balance = balance - 100 WHERE id = 1;
Query OK, 1 row affected (0.000 sec)
Rows matched: 1  Changed: 1  Warnings: 0

手順2(ターミナルB):

mysql> START TRANSACTION;
Query OK, 0 rows affected (0.000 sec)

mysql> UPDATE accounts SET balance = balance - 100 WHERE id = 2;
Query OK, 1 row affected (0.000 sec)
Rows matched: 1  Changed: 1  Warnings: 0

手順3(ターミナルA)。ID 2 はBがロックしているので、結果が返らず、待ったままになります。

mysql> UPDATE accounts SET balance = balance + 100 WHERE id = 2;

待っている間に、ロックを見る(data_locks)

Aが待っている間に、ターミナルCで performance_schema.data_locks を見ます。接続のIDで見分けられるよう、performance_schema.threads と結合して PROCESSLIST_ID(接続のID)を出しています。

mysql> SELECT t.PROCESSLIST_ID AS conn_id, l.ENGINE_TRANSACTION_ID AS trx_id, l.INDEX_NAME, l.LOCK_TYPE, l.LOCK_MODE, l.LOCK_STATUS, l.LOCK_DATA FROM performance_schema.data_locks l JOIN performance_schema.threads t USING (THREAD_ID) ORDER BY conn_id, l.LOCK_TYPE DESC, l.LOCK_DATA;
+---------+--------+------------+-----------+---------------+-------------+-----------+
| conn_id | trx_id | INDEX_NAME | LOCK_TYPE | LOCK_MODE     | LOCK_STATUS | LOCK_DATA |
+---------+--------+------------+-----------+---------------+-------------+-----------+
|       9 |   2074 | NULL       | TABLE     | IX            | GRANTED     | NULL      |
|       9 |   2074 | PRIMARY    | RECORD    | X,REC_NOT_GAP | GRANTED     | 1         |
|       9 |   2074 | PRIMARY    | RECORD    | X,REC_NOT_GAP | WAITING     | 2         |
|      10 |   2075 | NULL       | TABLE     | IX            | GRANTED     | NULL      |
|      10 |   2075 | PRIMARY    | RECORD    | X,REC_NOT_GAP | GRANTED     | 2         |
+---------+--------+------------+-----------+---------------+-------------+-----------+
5 rows in set (0.007 sec)
  • LOCK_TYPE が TABLE の行は、テーブルへの意図ロック(IX)です。行を排他でロックする前に、InnoDB がテーブルに取ります。
  • RECORD の行が、行のロックです。LOCK_DATA は主キー(INDEX_NAME が PRIMARY)の値で、どの行かが分かります。X,REC_NOT_GAP は、行の間(ギャップ)を含まない、その行だけの排他ロックです。
  • LOCK_STATUS が GRANTED は持っているロック、WAITING は待っているロックです。接続9(A)は ID 1 を持ち、ID 2 を待っています。ID 2 は接続10(B)が持っています。

誰が誰を待っているかは、sys.innodb_lock_waits で1行にまとまります(data_locks と data_lock_waits をもとにしたビューです)。対話モードなので、\G で縦に表示できます。

mysql> SELECT waiting_pid, waiting_query, waiting_lock_mode, blocking_pid, blocking_query, blocking_lock_mode, locked_index FROM sys.innodb_lock_waits\G
*************************** 1. row ***************************
       waiting_pid: 9
     waiting_query: UPDATE accounts SET balance = balance + 100 WHERE id = 2
 waiting_lock_mode: X,REC_NOT_GAP
      blocking_pid: 10
    blocking_query: NULL
blocking_lock_mode: X,REC_NOT_GAP
      locked_index: PRIMARY
1 row in set (0.008 sec)

待っているのは接続9(A)の UPDATE で、止めているのは接続10(B)です。blocking_query が NULL なのは、Bが今は何も実行していない(UPDATE を終えて、次の入力を待っている)からです。ロックを持ったまま何もしていない接続は、こうなります。

Bが逆の順番で更新する(ERROR 1213)

手順4(ターミナルB)。BがAの持つ ID 1 を待つと、AとBがお互いを待つ形になります。InnoDB がすぐにデッドロックを見つけ、Bのトランザクションを取り消して、Bに ERROR 1213 を返しました。

mysql> UPDATE accounts SET balance = balance + 100 WHERE id = 1;
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

Bのロックがなくなったので、待っていたAの UPDATE が終わりました。2.403 sec は、手順3からロックを取れるまで待った時間です(ロックを見ていた時間を含みます)。

mysql> UPDATE accounts SET balance = balance + 100 WHERE id = 2;
Query OK, 1 row affected (2.403 sec)
Rows matched: 1  Changed: 1  Warnings: 0

エラーのあと: Bのトランザクションはすべて取り消された

ターミナルBで残高を見ると、手順2で減らした ID 2 も1000に戻っていました。エラーになった文だけでなく、START TRANSACTION からのBの変更がすべて取り消されています。ID 1 が1000のままに見えるのは、Aの変更がまだコミットされていないからです。

mysql> SELECT * FROM accounts;
+----+-------+---------+
| id | name  | balance |
+----+-------+---------+
|  1 | alice |    1000 |
|  2 | bob   |    1000 |
+----+-------+---------+
2 rows in set (0.000 sec)

ターミナルAでは自分の2つの変更が見え、コミットできます。

mysql> SELECT * FROM accounts;
+----+-------+---------+
| id | name  | balance |
+----+-------+---------+
|  1 | alice |     900 |
|  2 | bob   |    1100 |
+----+-------+---------+
2 rows in set (0.000 sec)

mysql> COMMIT;
Query OK, 0 rows affected (0.011 sec)

ターミナルCで見ると、Aの移動だけが反映されています。Bの移動は、アプリならトランザクションを最初からやり直す必要があります。

mysql> SELECT * FROM accounts;
+----+-------+---------+
| id | name  | balance |
+----+-------+---------+
|  1 | alice |     900 |
|  2 | bob   |    1100 |
+----+-------+---------+
2 rows in set (0.000 sec)

LATEST DETECTED DEADLOCK を読む

終わったデッドロックの原因は、SHOW ENGINE INNODB STATUS で見ます。ターミナルCで実行し、LATEST DETECTED DEADLOCK の部分だけを抜き出しました(出力の全体は長いので、前後は省略)。

mysql> SHOW ENGINE INNODB STATUS\G
(略)
------------------------
LATEST DETECTED DEADLOCK
------------------------
2026-11-09 00:58:11 128101744891456
*** (1) TRANSACTION:
TRANSACTION 2074, ACTIVE 5 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1128, 2 row lock(s), undo log entries 1
MySQL thread id 9, OS thread handle 128101831984704, query id 24 localhost root updating
UPDATE accounts SET balance = balance + 100 WHERE id = 2

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 2 page no 4 n bits 72 index PRIMARY of table `app`.`accounts` trx id 2074 lock_mode X locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 00000000081a; asc       ;;
 2: len 7; hex 02000001220151; asc     " Q;;
 3: len 5; hex 616c696365; asc alice;;
 4: len 4; hex 80000384; asc     ;;


*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2 page no 4 n bits 72 index PRIMARY of table `app`.`accounts` trx id 2074 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000002; asc     ;;
 1: len 6; hex 00000000081b; asc       ;;
 2: len 7; hex 01000001260151; asc     & Q;;
 3: len 3; hex 626f62; asc bob;;
 4: len 4; hex 80000384; asc     ;;


*** (2) TRANSACTION:
TRANSACTION 2075, ACTIVE 3 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1128, 2 row lock(s), undo log entries 1
MySQL thread id 10, OS thread handle 128101830927936, query id 44 localhost root updating
UPDATE accounts SET balance = balance + 100 WHERE id = 1

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 2 page no 4 n bits 72 index PRIMARY of table `app`.`accounts` trx id 2075 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000002; asc     ;;
 1: len 6; hex 00000000081b; asc       ;;
 2: len 7; hex 01000001260151; asc     & Q;;
 3: len 3; hex 626f62; asc bob;;
 4: len 4; hex 80000384; asc     ;;


*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 2 page no 4 n bits 72 index PRIMARY of table `app`.`accounts` trx id 2075 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 00000000081a; asc       ;;
 2: len 7; hex 02000001220151; asc     " Q;;
 3: len 5; hex 616c696365; asc alice;;
 4: len 4; hex 80000384; asc     ;;

*** WE ROLL BACK TRANSACTION (2)
(略)

読み方です。

  • *** (1) TRANSACTION: と *** (2) TRANSACTION: が、デッドロックになった2つのトランザクションです。MySQL thread id 9 は接続のIDで、(1)がA、(2)がBです。その下の行は、そのとき実行していた文です。
  • HOLDS THE LOCK(S) が持っているロック、WAITING FOR THIS LOCK TO BE GRANTED が待っているロックです。index PRIMARY of table `app`.`accounts` で、どのテーブルのどのインデックスか分かります。lock_mode X locks rec but not gap は、data_locks の X,REC_NOT_GAP と同じ、その行だけの排他ロックです。
  • どの行かは、その下の 0: 〜 4: の列の値で分かります。今回の出力では、0: が主キーの id(hex 80000001 が id 1、hex 80000002 が id 2)、3: が name(asc alice など)でした。
  • (1)は id 1 を持って id 2 を待ち、(2)は id 2 を持って id 1 を待っています。お互いを待っているので、どちらも先に進めません。これがデッドロックの原因です。
  • 最後の *** WE ROLL BACK TRANSACTION (2) が、取り消したトランザクションです。公式ドキュメントでは、InnoDB は挿入・更新・削除した行の数が少ない、小さいトランザクションを選んで取り消そうとします。今回は両方とも1行ずつの変更で、(2)のBが取り消されました。

注意点が2つあります。1つは、表示される文がデッドロックの時点で実行中だった文だけであることです。Aが ID 1 のロックを取った最初の UPDATE は、どこにも出ていません。実際のアプリでは、出てきた文と同じトランザクションで、その前に何を実行していたかを、アプリのコードやログで探すことになります。もう1つは、ここに残るのが最後の1件だけであることです。次のデッドロックが起きると上書きされます。毎回残すには、次のエラーログを使います。

エラーログに毎回残す(innodb_print_all_deadlocks)

innodb_print_all_deadlocks を有効にすると、デッドロックのたびに、同じ内容がエラーログに出ます。Dockerの公式イメージのMySQLでは、エラーログは docker logs で見られます。デッドロックの見出しから WE ROLL BACK の行までを抜き出しました。

$ docker logs tb-deadlock-mysql 2>&1 | sed -n '/deadlock detected/,/WE ROLL BACK/p'
2026-11-09T00:58:11.067406Z 0 [Note] [MY-012468] [InnoDB] Transactions deadlock detected, dumping detailed information.
2026-11-09T00:58:11.067516Z 0 [Note] [MY-012469] [InnoDB]  *** (1) TRANSACTION: 
TRANSACTION 2074, ACTIVE 5 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1128, 2 row lock(s), undo log entries 1
MySQL thread id 9, OS thread handle 128101831984704, query id 24 localhost root updating
UPDATE accounts SET balance = balance + 100 WHERE id = 2
2026-11-09T00:58:11.067633Z 0 [Note] [MY-012469] [InnoDB]  *** (1) HOLDS THE LOCK(S): 
RECORD LOCKS space id 2 page no 4 n bits 72 index PRIMARY of table `app`.`accounts` trx id 2074 lock_mode X locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 00000000081a; asc       ;;
 2: len 7; hex 02000001220151; asc     " Q;;
 3: len 5; hex 616c696365; asc alice;;
 4: len 4; hex 80000384; asc     ;;

2026-11-09T00:58:11.067684Z 0 [Note] [MY-012469] [InnoDB]  *** (1) WAITING FOR THIS LOCK TO BE GRANTED: 
RECORD LOCKS space id 2 page no 4 n bits 72 index PRIMARY of table `app`.`accounts` trx id 2074 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000002; asc     ;;
 1: len 6; hex 00000000081b; asc       ;;
 2: len 7; hex 01000001260151; asc     & Q;;
 3: len 3; hex 626f62; asc bob;;
 4: len 4; hex 80000384; asc     ;;

2026-11-09T00:58:11.067712Z 0 [Note] [MY-012469] [InnoDB]  *** (2) TRANSACTION: 
TRANSACTION 2075, ACTIVE 3 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1128, 2 row lock(s), undo log entries 1
MySQL thread id 10, OS thread handle 128101830927936, query id 44 localhost root updating
UPDATE accounts SET balance = balance + 100 WHERE id = 1
2026-11-09T00:58:11.067721Z 0 [Note] [MY-012469] [InnoDB]  *** (2) HOLDS THE LOCK(S): 
RECORD LOCKS space id 2 page no 4 n bits 72 index PRIMARY of table `app`.`accounts` trx id 2075 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000002; asc     ;;
 1: len 6; hex 00000000081b; asc       ;;
 2: len 7; hex 01000001260151; asc     & Q;;
 3: len 3; hex 626f62; asc bob;;
 4: len 4; hex 80000384; asc     ;;

2026-11-09T00:58:11.067755Z 0 [Note] [MY-012469] [InnoDB]  *** (2) WAITING FOR THIS LOCK TO BE GRANTED: 
RECORD LOCKS space id 2 page no 4 n bits 72 index PRIMARY of table `app`.`accounts` trx id 2075 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 00000000081a; asc       ;;
 2: len 7; hex 02000001220151; asc     " Q;;
 3: len 5; hex 616c696365; asc alice;;
 4: len 4; hex 80000384; asc     ;;

2026-11-09T00:58:11.067795Z 0 [Note] [MY-012469] [InnoDB] *** WE ROLL BACK TRANSACTION (2) 

Windows の PowerShell には sed がないので、Select-String で見出しの行と、その後ろの行を出します。-Context 0,49 は「後ろの49行も出す」という意味で、49は今回のデッドロック(2つのトランザクションが1行ずつロックしたもの)の行数に合わせた数です。ロックする行が多いと、この数では足りません。出力の中身は上と同じで、行の頭に >(見つかった行)や空白がつきます。

PS> docker logs tb-deadlock-mysql 2>&1 | Select-String 'deadlock detected' -Context 0,49

エラーログの行には時刻がつくので、いつ起きたかが分かります。SHOW ENGINE INNODB STATUS と違って上書きされないので、たまにしか起きないデッドロックを調べるときに向いています。公式ドキュメントは、調べ終わったら無効に戻すよう書いています。再起動しても有効のままにしたいときは、設定ファイル(my.cnf)に書くか、SET PERSIST を使います(この2つは今回は試していません)。

ロック待ちのタイムアウト(ERROR 1205)との違い

比べるため、今度はお互いを待つ形にせず、BがAのロックを待つだけにします。既定の50秒は長いので、ターミナルBの接続だけ、ロック待ちの上限を5秒にします。

mysql> SET SESSION innodb_lock_wait_timeout = 5;
Query OK, 0 rows affected (0.000 sec)

ターミナルAで ID 1 をロックします。

mysql> START TRANSACTION;
Query OK, 0 rows affected (0.000 sec)

mysql> UPDATE accounts SET balance = balance - 100 WHERE id = 1;
Query OK, 1 row affected (0.000 sec)
Rows matched: 1  Changed: 1  Warnings: 0

ターミナルBで ID 2 を更新してから、Aが持つ ID 1 を更新します。Aは何も待っていないので、デッドロックにはなりません。Bは5秒ほど待って、ERROR 1205 になりました。

mysql> START TRANSACTION;
Query OK, 0 rows affected (0.000 sec)

mysql> UPDATE accounts SET balance = balance - 100 WHERE id = 2;
Query OK, 1 row affected (0.000 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> UPDATE accounts SET balance = balance + 100 WHERE id = 1;
ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

ここからがデッドロックとの違いです。ターミナルBで残高を見ると、ID 2 は1000のままでした(前の章の終わりで1100だったものを、Bが100減らした値)。取り消されたのはタイムアウトした文だけで、Bのトランザクションは続いています。

mysql> SELECT * FROM accounts;
+----+-------+---------+
| id | name  | balance |
+----+-------+---------+
|  1 | alice |     900 |
|  2 | bob   |    1000 |
+----+-------+---------+
2 rows in set (0.000 sec)

ターミナルCで見ると、Bは ID 2 のロックも持ったままです。タイムアウトのあとに何もしないと、このロックでほかの接続を待たせ続けます。

mysql> SELECT t.PROCESSLIST_ID AS conn_id, l.LOCK_TYPE, l.LOCK_MODE, l.LOCK_STATUS, l.LOCK_DATA FROM performance_schema.data_locks l JOIN performance_schema.threads t USING (THREAD_ID) ORDER BY conn_id, l.LOCK_TYPE DESC, l.LOCK_DATA;
+---------+-----------+---------------+-------------+-----------+
| conn_id | LOCK_TYPE | LOCK_MODE     | LOCK_STATUS | LOCK_DATA |
+---------+-----------+---------------+-------------+-----------+
|       9 | TABLE     | IX            | GRANTED     | NULL      |
|       9 | RECORD    | X,REC_NOT_GAP | GRANTED     | 1         |
|      10 | TABLE     | IX            | GRANTED     | NULL      |
|      10 | RECORD    | X,REC_NOT_GAP | GRANTED     | 2         |
+---------+-----------+---------------+-------------+-----------+
4 rows in set (0.004 sec)

ターミナルBとターミナルAで、それぞれ ROLLBACK して終えます。ターミナルBの表示です(Aも同じ表示でした)。

mysql> ROLLBACK;
Query OK, 0 rows affected (0.001 sec)

このあと docker logs tb-deadlock-mysql でエラーログを見ても、デッドロックの記録は前の章の1件だけでした。Claudeの確認では、この章を始める前と終わったあとのエラーログを比べ、増えた行がないことも確かめました(log_error_verbosity は3のまま)。ロック待ちのタイムアウトは、エラーログに出ませんでした。

タイムアウトでトランザクション全体を取り消したいときは、innodb_rollback_on_timeout を有効にします。この設定はサーバーの起動時にしか変えられません(今回は試していません)。

更新の順番をそろえると、待つだけで済む

AとBの両方が、ID 1 → ID 2 の順番で更新するようにします。その前に、前の章で5秒にしたターミナルBのロック待ちの上限を、既定(サーバー全体の値の50秒)に戻します。SET SESSION で変えた値は、別の値にするか接続が終わるまで残ります(ROLLBACK では戻りません)。戻さないと、この章でBが待つ間に、5秒で ERROR 1205 になることがあります。DEFAULT を代入すると、接続の値がサーバー全体(GLOBAL)の値になります。

mysql> SET SESSION innodb_lock_wait_timeout = DEFAULT;
Query OK, 0 rows affected (0.000 sec)

mysql> SELECT @@SESSION.innodb_lock_wait_timeout;
+------------------------------------+
| @@SESSION.innodb_lock_wait_timeout |
+------------------------------------+
|                                 50 |
+------------------------------------+
1 row in set (0.000 sec)

ターミナルAで ID 1 を更新します。

mysql> START TRANSACTION;
Query OK, 0 rows affected (0.000 sec)

mysql> UPDATE accounts SET balance = balance - 100 WHERE id = 1;
Query OK, 1 row affected (0.000 sec)
Rows matched: 1  Changed: 1  Warnings: 0

ターミナルBも ID 1 から更新します。Aが持っているので、待ちます。

mysql> START TRANSACTION;
Query OK, 0 rows affected (0.000 sec)

mysql> UPDATE accounts SET balance = balance - 100 WHERE id = 1;

Bが待っている間に(50秒以内に)、ターミナルAで ID 2 を更新してコミットします。Aは誰のロックも待たないので、そのまま進みます。

mysql> UPDATE accounts SET balance = balance + 100 WHERE id = 2;
Query OK, 1 row affected (0.000 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> COMMIT;
Query OK, 0 rows affected (0.004 sec)

Aがコミットしてロックを外すと、Bの UPDATE が終わりました(待った時間が 1.961 sec)。Bも ID 2 を更新して、コミットします。

mysql> UPDATE accounts SET balance = balance - 100 WHERE id = 1;
Query OK, 1 row affected (1.961 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> UPDATE accounts SET balance = balance + 100 WHERE id = 2;
Query OK, 1 row affected (0.000 sec)
Rows matched: 1  Changed: 1  Warnings: 0

mysql> COMMIT;
Query OK, 0 rows affected (0.002 sec)

ターミナルCで見ると、両方の移動が反映されていました。エラーログのデッドロックも1件のまま増えていません。

mysql> SELECT * FROM accounts;
+----+-------+---------+
| id | name  | balance |
+----+-------+---------+
|  1 | alice |     700 |
|  2 | bob   |    1300 |
+----+-------+---------+
2 rows in set (0.000 sec)

公式ドキュメントでも、複数のテーブルや複数の行を変更するときは毎回同じ順番で行うこと、トランザクションを小さく短くすること、デッドロックで失敗したらトランザクションをやり直せるようにしておくことが、勧められています。

ハマりどころ

log_error_verbosity が既定の2だと、どちらを取り消したかがエラーログに出ない

innodb_print_all_deadlocks だけを有効にして、log_error_verbosity を既定の2のままにすると、どうなるかを確かめました。ターミナルCで2に戻し、「デッドロックを起こす」の手順1〜4をもう一度実行してから(Bは同じく ERROR 1213 になりました)、Aを ROLLBACK しました。

mysql> SET GLOBAL log_error_verbosity = 2;
Query OK, 0 rows affected (0.000 sec)

エラーログから、トランザクションと取り消しの行を探しました。TRANSACTION 2074 と 2075 が1回目(log_error_verbosity が3)、2094 と 2095 が2回目(2)のデッドロックです。

# Mac
$ docker logs tb-deadlock-mysql 2>&1 | grep -E 'TRANSACTION|ROLL BACK'
# Windows(PowerShell。-CaseSensitive は grep と同じく大文字・小文字を区別するため)
PS> docker logs tb-deadlock-mysql 2>&1 | Select-String -CaseSensitive 'TRANSACTION|ROLL BACK'

2026-11-09T00:58:11.067516Z 0 [Note] [MY-012469] [InnoDB]  *** (1) TRANSACTION: 
TRANSACTION 2074, ACTIVE 5 sec starting index read
2026-11-09T00:58:11.067712Z 0 [Note] [MY-012469] [InnoDB]  *** (2) TRANSACTION: 
TRANSACTION 2075, ACTIVE 3 sec starting index read
2026-11-09T00:58:11.067795Z 0 [Note] [MY-012469] [InnoDB] *** WE ROLL BACK TRANSACTION (2) 
TRANSACTION 2094, ACTIVE 3 sec starting index read
TRANSACTION 2095, ACTIVE 2 sec starting index read

2回目は、ロックの詳細の行(TRANSACTION 2094, ... など)は出ていますが、時刻のついた見出しの行(*** (1) TRANSACTION: など)と、*** WE ROLL BACK TRANSACTION の行がありません。これでは、いつ起きたのか、どちらが取り消されたのかが分かりません。見出しの行には [Note] がついています。公式ドキュメントでは、log_error_verbosity が2のときに出るのはエラーと警告で、3にすると情報(Note)も出ます。3にすると、ほかの情報のメッセージ(接続の中断など)もエラーログに出るようになります。

mysql -e に \G を書くとエラーになる(MySQL 9.7.4 のクライアント、既定の設定)

SHOW ENGINE INNODB STATUS は、ホストのシェルから1回だけ実行したくなります。しかし、今回の mysql クライアント(9.7.4)では、-e に \G を書くとエラーになりました。MySQL 9.4.0 で追加された --commands(mysql クライアントのコマンドを使えるようにする設定)が、既定で無効なためとみられます。--commands をつけると使えました(下)。対話モードでは、--commands をつけなくても、上のとおり \G を使えました。

docker exec -it tb-deadlock-mysql mysql -uroot -p -e "SHOW ENGINE INNODB STATUS\G"

Enter password: 
ERROR at line 1: Unknown command '\G'.

縦に表示する -E(--vertical)をつけて \G を外すか、--commands をつけると、表示されました。

docker exec -it tb-deadlock-mysql mysql -uroot -p -E -e "SHOW ENGINE INNODB STATUS"

Enter password: 
*************************** 1. row ***************************
  Type: InnoDB
  Name: 
Status: 
=====================================
2026-11-09 00:58:51 128101702927936 INNODB MONITOR OUTPUT
=====================================
(以下略)

docker exec -it tb-deadlock-mysql mysql -uroot -p --commands -e "SHOW ENGINE INNODB STATUS\G"

Enter password: 
*************************** 1. row ***************************
  Type: InnoDB
  Name: 
Status: 
=====================================
2026-11-09 00:58:52 128101702927936 INNODB MONITOR OUTPUT
=====================================
(以下略)

後片付け

3つのターミナルで exit を打って mysql を終わり、コンテナを消します。

mysql> exit
Bye

docker rm -f tb-deadlock-mysql

参考URL

スポンサーリンク
MySQLデータベース
スポンサーリンク
シェアする
hayoをフォローする

コメント

タイトルとURLをコピーしました