Help us understand the problem. What is going on with this article?

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

More than 1 year has passed since last update.

これは インフラ勉強会 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 さん、良いネタの提供ありがとうございました。


hmatsu47
名古屋で士業向けWebサービスのインフラ構築管理、たまにアプリケーション開発をやっています。 業務利用しているもの、個人研究など、気長にのんびり投稿していきます。ニッチ狙いが多めです。 IPA RISS(001158)・NW・DB/日商・大商2級コレクター?(簿記・ビジネス法務・ビジネス会計)。 https://hmatsu47.qrunch.io/
https://hmatsu47.hatenablog.com/
infra-workshop
インフラ技術を勉強したい人たちのためのオンライン勉強会です
https://wp.infra-workshop.tech/
Why not register and get more from Qiita?
  1. We will deliver articles that match you
    By following users and tags, you can catch up information on technical fields that you are interested in as a whole
  2. you can read useful information later efficiently
    By "stocking" the articles you like, you can search right away