これは インフラ勉強会 Advent Calendar 2018 17 日目の記事です。
※忘れていたので後から突っ込みました。
昨日は sahya さんだった…はずです(皆さん忙しそうですね…時期が時期だけに)。
インフラ勉強会の Advent Calendar には PostgreSQL の記事を 2 本入れたのですが、本来わたしは MySQL 側の人ですので、ここはひとつ MySQL ネタを突っ込んでおきます。
Qrunch に、
- MySQL8.0 で起こる謎のデッドロックの条件を調べてみた(bluexxsun さん)
という記事が掲載されており、面白そうだったので、
に書いた、
- **
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
します。
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 つのテーブルでロックの状況を見てみましょう。
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 UPDATE
のSELECT
処理自体はREAD COMMITTED
相当になります。
次に、トランザクション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;
ロック待ち状態になりました。
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
してみます。
mysql> INSERT INTO users VALUES (18, 75);
デッドロックで待ち状態になりました(最初の設定により、タイムアウトするまでエラーは出ないようになっています)。
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に待たされている」**ことを示す情報が増えました。
デッドロックの完成です!
ここで、タイムアウトまで待ってから、ロックの状況を見てみます。
ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
Query OK, 1 row affected (9 min 5.26 sec)
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=14
:INSERT
でロックを取るのがid=15
の行になるのでデッドロックしない -
id=16・17・19
:id=18
と同様ロックを取るのがid=20
の行になるのでデッドロックする -
id=21
:ロックを取るのがid=25
の行になるのでデッドロックしない(トランザクション2はid=25
のロックを取ろうとする前で止まっているため)
となります。
※インデックスが降順の場合は~~もしかすると上下関係が逆かもしれません(未確認)~~上下関係が逆になります。
というわけで、
UPDATE
・DELETE
でどうなるのかについては、皆さんで試してみてください。
bluexxsun さん、良いネタの提供ありがとうございました。