MySQL
MySQL8.0

「MySQL8.0 で起こる謎のデッドロックの条件を調べてみた」を data_locks・data_lock_waits テーブルで確かめてみた

これは インフラ勉強会 Advent Calendar 2018 17 日目の記事です。

※忘れていたので後から突っ込みました。

昨日は sahya さんだった…はずです(皆さん忙しそうですね…時期が時期だけに)。


インフラ勉強会の Advent Calendar には PostgreSQL の記事を 2 本入れたのですが、本来わたしは MySQL 側の人ですので、ここはひとつ MySQL ネタを突っ込んでおきます。

Qrunch に、

という記事が掲載されており、面白そうだったので、

に書いた、



  • performance_schema.data_locksテーブル


  • performance_schema.data_lock_waitsテーブル

を見ながら、「再現1」の動きを確かめてみます。

※残念ながら(?)sys.innodb_lock_waitsビューはあまり役に立ちませんでした。「他を待たせていないロック」を表示しないと意味がないので…。


12/20 追記:

MySQL のロックの種類について、軽く説明を書きました。



実験

DB とテーブルと初期データを登録しますが、それと同時に、実験の流れが分かりやすいようにデッドロックを検出しない(タイムアウトまで待つ)innodb_deadlock_detect=0の設定にしておきます。


準備

mysql> SET GLOBAL innodb_deadlock_detect=0;

Query OK, 0 rows affected (0.00 sec)

mysql> CREATE DATABASE dl_test;
Query OK, 1 row affected (0.06 sec)

mysql> USE dl_test;
Database changed
mysql> CREATE TABLE users
-> (
-> id INTEGER PRIMARY KEY,
-> score INTEGER
-> );
Query OK, 0 rows affected (0.07 sec)

mysql> INSERT INTO users
-> (id, score) VALUES
-> (10, 95),
-> (15, 67),
-> (20, 82),
-> (25, 93),
-> (30, 87);
Query OK, 5 rows affected (0.07 sec)
Records: 5 Duplicates: 0 Warnings: 0

mysql> CREATE INDEX index_users_on_score ON users(score);
Query OK, 0 rows affected (0.02 sec)
Records: 0 Duplicates: 0 Warnings: 0


次に、トランザクション1でSELECT ~ FOR UPDATEします。


トランザクション1・SELECT_FOR_UPDATE

mysql> USE dl_test;

Database changed
mysql> SET autocommit=0;
Query OK, 0 rows affected (0.00 sec)

mysql> BEGIN;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * FROM users WHERE id BETWEEN 18 AND 23 FOR UPDATE;
+----+-------+
| id | score |
+----+-------+
| 20 | 82 |
+----+-------+
1 row in set (0.00 sec)


ここで、前述の 2 つのテーブルでロックの状況を見てみましょう。


ロック確認・その1

mysql> SELECT * FROM performance_schema.data_locks\G

*************************** 1. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:1090
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140541731842104
LOCK_TYPE: TABLE
LOCK_MODE: IX
LOCK_STATUS: GRANTED
LOCK_DATA: NULL
*************************** 2. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:4
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839064
LOCK_TYPE: RECORD
LOCK_MODE: X
LOCK_STATUS: GRANTED
LOCK_DATA: 20
*************************** 3. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:5
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839064
LOCK_TYPE: RECORD
LOCK_MODE: X
LOCK_STATUS: GRANTED
LOCK_DATA: 25
3 rows in set (0.00 sec)

mysql> SELECT * FROM performance_schema.data_lock_waits\G
Empty set (0.00 sec)


performance_schema.data_locksに、


  • 1 行目:トランザクション1のusersテーブルに対するインテンション排他ロック(テーブル排他ロック)※全体の流れの説明が難しくならないよう、このインテンション排他ロックについては特に触れません

  • 2 行目:同・id=20の行に対する排他ロック

  • 3 行目:同・id=25の行に対する排他ロック

が表示されました。

これは、


  • 実在するレコードのうち、id=18のすぐ下の行はロック対象外

  • 実在するレコードのうち、id=18のすぐ上の行はロック対象

  • 実在するレコードのうち、id=23のすぐ上の行はロック対象

という動作を示しています(ので、id=15の行はロック対象外です)。

ロックで待たせているものはないのでperformance_schema.data_lock_waitsは空です。

※余談ですが、MySQL ではトランザクション分離レベルがREPEATABLE READであっても、このSELECT ~ FOR UPDATESELECT処理自体はREAD COMMITTED相当になります。

次に、トランザクション2でSELECT ~ FOR UPDATEします。


トランザクション2・SELECT_FOR_UPDATE

mysql> USE dl_test;

Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
mysql> SET autocommit=0;
Query OK, 0 rows affected (0.00 sec)

mysql> BEGIN;
Query OK, 0 rows affected (0.00 sec)

mysql> SELECT * FROM users WHERE id BETWEEN 18 AND 23 FOR UPDATE;


ロック待ち状態になりました。


ロック確認・その2

mysql> SELECT * FROM performance_schema.data_locks\G

*************************** 1. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16938:1090
ENGINE_TRANSACTION_ID: 16938
THREAD_ID: 49
EVENT_ID: 23
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140541731848056
LOCK_TYPE: TABLE
LOCK_MODE: IX
LOCK_STATUS: GRANTED
LOCK_DATA: NULL
*************************** 2. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16938:21:4:4
ENGINE_TRANSACTION_ID: 16938
THREAD_ID: 49
EVENT_ID: 23
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731845128
LOCK_TYPE: RECORD
LOCK_MODE: X
LOCK_STATUS: WAITING
LOCK_DATA: 20
*************************** 3. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:1090
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140541731842104
LOCK_TYPE: TABLE
LOCK_MODE: IX
LOCK_STATUS: GRANTED
LOCK_DATA: NULL
*************************** 4. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:4
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839064
LOCK_TYPE: RECORD
LOCK_MODE: X
LOCK_STATUS: GRANTED
LOCK_DATA: 20
*************************** 5. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:5
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839064
LOCK_TYPE: RECORD
LOCK_MODE: X
LOCK_STATUS: GRANTED
LOCK_DATA: 25
5 rows in set (0.00 sec)

mysql> SELECT * FROM performance_schema.data_lock_waits\G
*************************** 1. row ***************************
ENGINE: INNODB
REQUESTING_ENGINE_LOCK_ID: 16938:21:4:4
REQUESTING_ENGINE_TRANSACTION_ID: 16938
REQUESTING_THREAD_ID: 49
REQUESTING_EVENT_ID: 23
REQUESTING_OBJECT_INSTANCE_BEGIN: 140541731845128
BLOCKING_ENGINE_LOCK_ID: 16937:21:4:4
BLOCKING_ENGINE_TRANSACTION_ID: 16937
BLOCKING_THREAD_ID: 48
BLOCKING_EVENT_ID: 37
BLOCKING_OBJECT_INSTANCE_BEGIN: 140541731839064
1 row in set (0.00 sec)


performance_schema.data_locksに(usersテーブルに対するインテンション排他ロックは省略します)、


  • 2 行目:トランザクション2のid=20の行に対する排他ロック(待ち)

  • 4 行目:トランザクション1のid=20の行に対する排他ロック

  • 5 行目:同・id=25の行に対する排他ロック

が表示されました。

また、performance_schema.data_lock_waitsには、


  • トランザクション2のid=20の行に対する排他ロックがトランザクション1の同じ行に対する排他ロックに待たされている

ことを示す行が表示されました。

id=20の行のロックで待たされているので、トランザクション2はまだid=25の行ロックを取りに行く前の状態です。

ここで、トランザクション1でid=18の行をINSERTしてみます。


トランザクション1・INSERT

mysql> INSERT INTO users VALUES (18, 75);


デッドロックで待ち状態になりました(最初の設定により、タイムアウトするまでエラーは出ないようになっています)。


ロック確認・その3

mysql> SELECT * FROM performance_schema.data_locks\G

*************************** 1. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16938:1090
ENGINE_TRANSACTION_ID: 16938
THREAD_ID: 49
EVENT_ID: 23
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140541731848056
LOCK_TYPE: TABLE
LOCK_MODE: IX
LOCK_STATUS: GRANTED
LOCK_DATA: NULL
*************************** 2. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16938:21:4:4
ENGINE_TRANSACTION_ID: 16938
THREAD_ID: 49
EVENT_ID: 23
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731845128
LOCK_TYPE: RECORD
LOCK_MODE: X
LOCK_STATUS: WAITING
LOCK_DATA: 20
*************************** 3. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:1090
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140541731842104
LOCK_TYPE: TABLE
LOCK_MODE: IX
LOCK_STATUS: GRANTED
LOCK_DATA: NULL
*************************** 4. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:4
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839064
LOCK_TYPE: RECORD
LOCK_MODE: X
LOCK_STATUS: GRANTED
LOCK_DATA: 20
*************************** 5. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:5
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839064
LOCK_TYPE: RECORD
LOCK_MODE: X
LOCK_STATUS: GRANTED
LOCK_DATA: 25
*************************** 6. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:4
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 38
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839408
LOCK_TYPE: RECORD
LOCK_MODE: X,GAP,INSERT_INTENTION
LOCK_STATUS: WAITING
LOCK_DATA: 20
6 rows in set (0.00 sec)

mysql> SELECT * FROM performance_schema.data_lock_waits\G
*************************** 1. row ***************************
ENGINE: INNODB
REQUESTING_ENGINE_LOCK_ID: 16938:21:4:4
REQUESTING_ENGINE_TRANSACTION_ID: 16938
REQUESTING_THREAD_ID: 49
REQUESTING_EVENT_ID: 23
REQUESTING_OBJECT_INSTANCE_BEGIN: 140541731845128
BLOCKING_ENGINE_LOCK_ID: 16937:21:4:4
BLOCKING_ENGINE_TRANSACTION_ID: 16937
BLOCKING_THREAD_ID: 48
BLOCKING_EVENT_ID: 37
BLOCKING_OBJECT_INSTANCE_BEGIN: 140541731839064
*************************** 2. row ***************************
ENGINE: INNODB
REQUESTING_ENGINE_LOCK_ID: 16937:21:4:4
REQUESTING_ENGINE_TRANSACTION_ID: 16937
REQUESTING_THREAD_ID: 48
REQUESTING_EVENT_ID: 38
REQUESTING_OBJECT_INSTANCE_BEGIN: 140541731839408
BLOCKING_ENGINE_LOCK_ID: 16938:21:4:4
BLOCKING_ENGINE_TRANSACTION_ID: 16938
BLOCKING_THREAD_ID: 49
BLOCKING_EVENT_ID: 23
BLOCKING_OBJECT_INSTANCE_BEGIN: 140541731845128
2 rows in set (0.00 sec)


performance_schema.data_locksの 6 行目にINSERTによるid=20に対する排他・ギャップ・挿入インテンションロックが増えました(id=18のすぐ上に実在する行に対するロック)。

performance_schema.data_lock_waitsの 2 行目に、id=20の行に対して、トランザクション1がトランザクション2に待たされている」ことを示す情報が増えました。

デッドロックの完成です!

ここで、タイムアウトまで待ってから、ロックの状況を見てみます。


トランザクション2・タイムアウト

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction



トランザクション1・タイムアウト直後

Query OK, 1 row affected (9 min 5.26 sec)



ロック確認・その4

mysql> SELECT * FROM performance_schema.data_locks\G

*************************** 1. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16938:1090
ENGINE_TRANSACTION_ID: 16938
THREAD_ID: 49
EVENT_ID: 23
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140541731848056
LOCK_TYPE: TABLE
LOCK_MODE: IX
LOCK_STATUS: GRANTED
LOCK_DATA: NULL
*************************** 2. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:1090
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: NULL
OBJECT_INSTANCE_BEGIN: 140541731842104
LOCK_TYPE: TABLE
LOCK_MODE: IX
LOCK_STATUS: GRANTED
LOCK_DATA: NULL
*************************** 3. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:4
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839064
LOCK_TYPE: RECORD
LOCK_MODE: X
LOCK_STATUS: GRANTED
LOCK_DATA: 20
*************************** 4. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:5
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 37
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839064
LOCK_TYPE: RECORD
LOCK_MODE: X
LOCK_STATUS: GRANTED
LOCK_DATA: 25
*************************** 5. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:4
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 38
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839408
LOCK_TYPE: RECORD
LOCK_MODE: X,GAP,INSERT_INTENTION
LOCK_STATUS: GRANTED
LOCK_DATA: 20
*************************** 6. row ***************************
ENGINE: INNODB
ENGINE_LOCK_ID: 16937:21:4:7
ENGINE_TRANSACTION_ID: 16937
THREAD_ID: 48
EVENT_ID: 38
OBJECT_SCHEMA: dl_test
OBJECT_NAME: users
PARTITION_NAME: NULL
SUBPARTITION_NAME: NULL
INDEX_NAME: PRIMARY
OBJECT_INSTANCE_BEGIN: 140541731839752
LOCK_TYPE: RECORD
LOCK_MODE: X,GAP
LOCK_STATUS: GRANTED
LOCK_DATA: 18
6 rows in set (0.00 sec)

mysql> SELECT * FROM performance_schema.data_lock_waits\G
Empty set (0.00 sec)


トランザクション1のINSERTが完了したため、performance_schema.data_locksの 6 行目は実際に挿入したid=18の行への排他・ギャップロックになっています。

※まだCOMMITしていない状態です。

まとめると、



  • SELECT ~ FOR UPDATEでは、実在する行に対して排他ロックを取る


    • キーの範囲は「指定範囲の下限(この例ではid=18)のすぐ上に実在する行以上、上限(同・id=23)のすぐ上に実在する行以下」

    • 但し、一番下の行(この例ではid=20)がロック待ちになった場合はそれより上の行(同・id=25)のロック待ちにはならない(「ロック待ち」の待ち状態?)




  • INSERTでは、同一トランザクションで先に実行したSELECT ~ FOR UPDATEとは別に、排他ロック(ギャップロック・挿入インテンションロック)を取ろうとする


    • キーの範囲は「挿入しようとする行(この例ではid=18)のすぐ下に実在する行より大きく、すぐ上に実在する行以下」でギャップロックを取る



  • トランザクション1→トランザクション2→トランザクション1の順に同じ行に対して排他ロックを取ろうとすると、対象が 1 行であってもデッドロックする


    • 別々の 2 行に対してお互いに逆順でロックを取ろうとしなくてもデッドロックは成立する



ということになります。

そう考えると、最後にトランザクション1でINSERTする行が、



  • id=14INSERTでロックを取るのがid=15の行になるのでデッドロックしない


  • id=16・17・19id=18と同様ロックを取るのがid=20の行になるのでデッドロックする


  • id=21:ロックを取るのがid=25の行になるのでデッドロックしない(トランザクション2はid=25のロックを取ろうとする前で止まっているため)

となります。

※インデックスが降順の場合はもしかすると上下関係が逆かもしれません(未確認)上下関係が逆になります。


というわけで、

UPDATEDELETEでどうなるのかについては、皆さんで試してみてください。

bluexxsun さん、良いネタの提供ありがとうございました。