はじめに
システム事業部堤田です。
今回、業務でdeadlockの発生原因を追うことになり、その際にdeadlockについて色々と学ぶことが出来ましたので、その内容について筆を執ることにしました。 これを読む方のdeadlockの理解に少しでも役立つことが出来れば幸いです。
検証で用いた環境・テーブル構成
確認を行ったdbとバージョン：mysql 5.7
テーブル構成は下記の通りです。
mysql> CREATE TABLE book (id int, title varchar(255), author varchar(255)); mysql> CREATE TABLE publisher (id int, name varchar(255), tel varchar(255)); mysql> select * from book; +------+---------------------+----------------+ | id | title | author | +------+---------------------+----------------+ | 1 | winnie the pooh | A.A.Milne | | 2 | Comet in Moominland | Tove Jansson | | 3 | PETER RABBIT | Beatrix Potter | +------+---------------------+----------------+ 3 rows in set (0.01 sec) mysql> select * from publisher; +------+-----------------------+--------------+ | id | name | tel | +------+-----------------------+--------------+ | 1 | Drawn & Quarterly | 514-279-2221 | | 2 | Methuen Publishing2 | 01653 628152 | | 3 | Frederick Warne & Co. | | +------+-----------------------+--------------+ 3 rows in set (0.00 sec)
検証用データですので、主キーや、index等のオプションは一切つけていません。後述していますが、そのため後でちょっと苦労しました。
※テストデータとして、くまのプーさんや、ムーミンの本をデータとして使っています。wikiからpublisherを確認してテーブルに登録しましたが、今回登録した内容以外のpublisherも存在していますが、全部は登録していません。関係者の方がいましたら生暖かい目で見ていただければと。
検証概要
2つのトランザクションを用いて、SELECT文にFOR UPDATEを付けて実行する事でテーブルロックをかけます。その後の処理で、お互いのトランザクションがロックされたテーブルの行を参照させ、どちらも待機状態にすることでdeadlockを発生させています。deadlock発生後は、show engine innodb status;で発生状況を確認しています。
SELECT ... FROM FOR UPDATEについては、MySQL 5.7のリファレンスマニュアル 14.7.3 Locks Set by Different SQL Statements in InnoDBから、下記のようにあります。原文と日本語両方掲載していますが、日本語の内容はMySQL5.6のリファレンスの内容になります。5.7のリファレンスは日本語対応していませんでしたが、5.6と5.7で英文の違いはありませんでしたので、そのまま利用しています。これ以降の内容も同様です。一応参照先にはすぐ飛べるようにしておきます。
For index records the search encounters, SELECT ... FOR UPDATE blocks other sessions from doing SELECT ... LOCK IN SHARE MODE or from reading in certain transaction isolation levels. Consistent reads ignore any locks set on the records that exist in the read view.
SELECT ... FROM ... FOR UPDATE は、検索で見つかったインデックスレコードに対して、ほかのセッションが SELECT ... FROM ... LOCK IN SHARE MODE を実行したり、特定のトランザクション分離レベルで読み取ったりすることをブロックします。一貫性読み取りでは、読み取られたビュー内に存在するレコードに設定されたロックはすべて無視されます。
先に今回検証する際に、ひっかかった内容を述べますと、SELECT FROM FOR UPDATEではWHERE文で指定した内容にだけロックがかかると思っていたのですが、それは誤った認識でした。
調べて見ると、WHERE文で指定した対象のカラムがINDEXまたは、UNIQUE設定がされている場合は行ロックがかかるのですが、その二つが設定されていない場合は、テーブルロックとなり、検索対象外の行についてもロックになりました。
- MySQL 5.7 14.6.2.1 Clustered and Secondary Indexes
- MySQL 5.6 14.6.2.1 Clustered and Secondary Indexes
- MySQL 5.6 日本語 14.2.13.2 クラスタインデックスとセカンダリインデックス
すべての InnoDB テーブルは、行のデータが格納されているクラスタ化されたインデックスと呼ばれる特別なインデックスを持っています。一般に、クラスタ化されたインデックスは主キーのシノニムです。クエリー、挿入、およびその他のデータベース操作で最適なパフォーマンスを実現するには、InnoDB がクラスタ化されたインデックスを使用して、テーブルごとにもっとも一般的な検索と DML 操作を最適化する方法について理解する必要があります
とありまして、後述しているDEADLOCKのログからも、RECORD LOCKS space id 1655 page no 3 n bits 80 index GEN_CLUST_INDEX of table `fuga`.`publisher` trx id 140072 lock_mode X waitingのようにGEN_CLUST_INDEXと記載されているようにクラスタインデックスとしてレコードを検索しているという事が分かります。
検証の為primary keyもindexもuniqueも設定していなかった事で、検証時は少し混乱しましたがそれによって理解が深まりました。怪我の功名ですね。
検証内容
2つのトランザクション処理の概要は下記の通りです。
T1
SELECT * FROM book WHERE id = 1 FOR UPDATE;。SELECT FOR UPDATE でbookにロックをかける。図の(b)。DELETE FROM publisher WHERE id = 1;。DELETE文でpublisherの1行目を削除しようとする。図の(d)。この時、deadlockが発生し、T1の処理がrollbackされる。
T2
SELECT * FROM publisher WHERE id = 1 FOR UPDATE;。SELECT FOR UPDATE で、publisherにロックをかける。図の(a)DELETE FROM book WHERE id = 1;。DELETE文で、bookの1行目を削除しようとする。図の(c)。ただし、T1の1の処理でbookに対してロックが発生しているので待機状態になる。- T1の1でロックされたbookの1行目のロックが解放されて、T2の2のDELETE文が成功する。
実際の実行順は、下記シーケンス図の通りです。
この時発生したdeadlockをshow engine innodb status;で確認します。以下内容ですが、LATEST DETECTED DEADOCK以外の内容は割愛しています。
------------------------ LATEST DETECTED DEADLOCK ------------------------ 2023-02-05 19:35:20 0x7f62c0125700 *** (1) TRANSACTION: TRANSACTION 16131, ACTIVE 41 sec starting index read mysql tables in use 1, locked 1 LOCK WAIT 4 lock struct(s), heap size 1136, 5 row lock(s) MySQL thread id 10, OS thread handle 140062105679616, query id 10971 localhost root updating DELETE FROM book WHERE id = 1 *** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 754 page no 3 n bits 72 index GEN_CLUST_INDEX of table `fuga`.`book` trx id 16131 lock_mode X waiting Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 0 0: len 6; hex 000000000200; asc ;; 1: len 6; hex 000000003eed; asc > ;; 2: len 7; hex f5000001aa0110; asc ;; 3: len 4; hex 80000001; asc ;; 4: len 15; hex 77696e6e69652074686520706f6f68; asc winnie the pooh;; 5: len 9; hex 412e412e4d696c6e65; asc A.A.Milne;; *** (2) TRANSACTION: TRANSACTION 16132, ACTIVE 34 sec starting index read mysql tables in use 1, locked 1 4 lock struct(s), heap size 1136, 5 row lock(s) MySQL thread id 9, OS thread handle 140062105949952, query id 10972 localhost root updating DELETE FROM publisher WHERE id = 1 *** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 754 page no 3 n bits 72 index GEN_CLUST_INDEX of table `fuga`.`book` trx id 16132 lock_mode X Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 0: len 8; hex 73757072656d756d; asc supremum;; Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 0 0: len 6; hex 000000000200; asc ;; 1: len 6; hex 000000003eed; asc > ;; 2: len 7; hex f5000001aa0110; asc ;; 3: len 4; hex 80000001; asc ;; 4: len 15; hex 77696e6e69652074686520706f6f68; asc winnie the pooh;; 5: len 9; hex 412e412e4d696c6e65; asc A.A.Milne;; Record lock, heap no 3 PHYSICAL RECORD: n_fields 6; compact format; info bits 0 0: len 6; hex 000000000201; asc ;; 1: len 6; hex 000000003eee; asc > ;; 2: len 7; hex f6000001d40110; asc ;; 3: len 4; hex 80000002; asc ;; 4: len 19; hex 436f6d657420696e204d6f6f6d696e6c616e64; asc Comet in Moominland;; 5: len 12; hex 546f7665204a616e73736f6e; asc Tove Jansson;; Record lock, heap no 4 PHYSICAL RECORD: n_fields 6; compact format; info bits 0 0: len 6; hex 000000000202; asc ;; 1: len 6; hex 000000003ef3; asc > ;; 2: len 7; hex f9000001ad0110; asc ;; 3: len 4; hex 80000003; asc ;; 4: len 12; hex 504554455220524142424954; asc PETER RABBIT;; 5: len 14; hex 4265617472697820506f74746572; asc Beatrix Potter;; *** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 755 page no 3 n bits 72 index GEN_CLUST_INDEX of table `fuga`.`publisher` trx id 16132 lock_mode X waiting Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 0 0: len 6; hex 000000000203; asc ;; 1: len 6; hex 000000003ef5; asc > ;; 2: len 7; hex fb000001d70110; asc ;; 3: len 4; hex 80000001; asc ;; 4: len 16; hex 447261776e2026205175617274656c79; asc Drawn & Quartely;; 5: len 12; hex 3531342d3237392d32323231; asc 514-279-2221;;
検証結果の分析
最初に確認するのは、下記の部分で(1) TRANSACTIONとある通り、一つ目のトランザクション処理についての記述になります。
*** (1) TRANSACTION: TRANSACTION 16131, ACTIVE 41 sec starting index read mysql tables in use 1, locked 1 LOCK WAIT 4 lock struct(s), heap size 1136, 5 row lock(s) MySQL thread id 10, OS thread handle 140062105679616, query id 10971 localhost root updating DELETE FROM book WHERE id = 1
全部を把握しているわけではありませんが、TRANSACTIONの番号のようなものが書いてあったり、DELETE FROM book where id = 1とSQLが出力されています。
T2（トランザクションの2）で行った処理が出力されている事が分かります。
何故、(2) TRANSACTIONでの処理が(1) TRANSACTION側で出力されているのだろうかと思いましたが、(1) TRANSACTION中の処理のによりロックされている部分にアクセスしようとしている処理を出力しているのだと思います。
*** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 754 page no 3 n bits 72 index GEN_CLUST_INDEX of table `fuga`.`book` trx id 16131 lock_mode X waiting Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
ここは(1)のトランザクションにて、ロックの許可を得るまで待機しているという内容になっています。 T2の2の処理はDELETE文ですが、MySQL5.6のリファレンスマニュアルの14.2.8にもある通り、DELETE文では行ロックをかけようとする為、対象の行ロックをかけようとしています。ただし、T1の1の処理で先に対象の行にロックがかけられている為、ロックが解放されるまで待機しようとしている状態となります。
- MySQL 5.7 14.7.3 Locks Set by Different SQL Statements in InnoDB
- MySQL 5.6 14.7.3 Locks Set by Different SQL Statements in InnoDB
- MySQL 5.6 日本語 14.2.8 InnoDB のさまざまな SQL ステートメントで設定されたロック
一般に、ロック読み取り、UPDATE、または DELETE では、SQL ステートメントの処理時にスキャンされるすべてのインデックスレコード上に、レコードロックが設定されます。
次に、(2) TRANSACTIONの内容を確認します。
*** (2) TRANSACTION: TRANSACTION 16132, ACTIVE 34 sec starting index read mysql tables in use 1, locked 1 4 lock struct(s), heap size 1136, 5 row lock(s) MySQL thread id 9, OS thread handle 140062105949952, query id 10972 localhost root updating DELETE FROM publisher WHERE id = 1
(1) TRANSACTIONと同様にDELETE FROM publisher where id = 1のSQLについて、T1の2の処理が書かれていることが分かります。
*** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 754 page no 3 n bits 72 index GEN_CLUST_INDEX of table `fuga`.`book` trx id 16132 lock_mode X Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 0: len 8; hex 73757072656d756d; asc supremum;;
このHOLDS THE LOCK(S)という内容が、実際にロックがかかっている箇所（範囲）を示しています。fugaデータベースのbookテーブルにて、ロックモードX（排他ロック）にてロックがかかっていることが分かります。
ロックモードについての詳細は、MySQL 5.7 14.7.1 InnoDB Lockingを確認下さい。とりあえずは、ロックモードXがかかっていると、他のトランザクション処理で、同じ行に対してロックをかけようとす場合は、ロックが解放されるまで待機しないといけないというような理解をして下さい。
トランザクション T1 が行 r 上で排他 (X) ロックを保持している場合は、r 上のいずれかのタイプのロックに対する一部の個別のトランザクション T2 からのリクエストは、すぐに付与できません
※ MySQL 5.6 日本語 14.2.3 InnoDB のロックモードでは、上記のようにありますので、例外はあるという事だとは思いますが、具体的にどういう処理がという所までは調べきれていません。
*** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 755 page no 3 n bits 72 index GEN_CLUST_INDEX of table `fuga`.`publisher` trx id 16132 lock_mode X waiting Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 0 0: len 6; hex 000000000203; asc ;; 1: len 6; hex 000000003ef5; asc > ;; 2: len 7; hex fb000001d70110; asc ;; 3: len 4; hex 80000001; asc ;; 4: len 16; hex 447261776e2026205175617274656c79; asc Drawn & Quartely;; 5: len 12; hex 3531342d3237392d32323231; asc 514-279-2221;;
(2) HOLDS THE LOCK(S)により、実際のロックがかかっている領域が示されています。3: の記載がbook.idにあたり、 4: がbook.title、5: がbook.authorになっていることが分かります。
また、supremumという記述は以降全てという意図となっていまして、INSERT処理にdeadlockが発生する際のインデックスロックと関わってきます。こちらが、業務で出会ったdeadlockの原因だったのですが、こちらについては別途記事を書こうと思っています。
ざっくりとしたイメージですが、あるテーブルに差し込まれたindexより以降の行にINSERTでindexを挿入しようとするとその範囲でロックがかかっている為、ロック解放まで待機が必要というようなロックとなります。
*** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 754 page no 3 n bits 72 index GEN_CLUST_INDEX of table `fuga`.`book` trx id 16132 lock_mode X Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 0: len 8; hex 73757072656d756d; asc supremum;; Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 0 0: len 6; hex 000000000200; asc ;; 1: len 6; hex 000000003eed; asc > ;; 2: len 7; hex f5000001aa0110; asc ;; 3: len 4; hex 80000001; asc ;; 4: len 15; hex 77696e6e69652074686520706f6f68; asc winnie the pooh;; 5: len 9; hex 412e412e4d696c6e65; asc A.A.Milne;; Record lock, heap no 3 PHYSICAL RECORD: n_fields 6; compact format; info bits 0 0: len 6; hex 000000000201; asc ;; 1: len 6; hex 000000003eee; asc > ;; 2: len 7; hex f6000001d40110; asc ;; 3: len 4; hex 80000002; asc ;; 4: len 19; hex 436f6d657420696e204d6f6f6d696e6c616e64; asc Comet in Moominland;; 5: len 12; hex 546f7665204a616e73736f6e; asc Tove Jansson;; Record lock, heap no 4 PHYSICAL RECORD: n_fields 6; compact format; info bits 0 0: len 6; hex 000000000202; asc ;; 1: len 6; hex 000000003ef3; asc > ;; 2: len 7; hex f9000001ad0110; asc ;; 3: len 4; hex 80000003; asc ;; 4: len 12; hex 504554455220524142424954; asc PETER RABBIT;; 5: len 14; hex 4265617472697820506f74746572; asc Beatrix Potter;;
この(2) HOLDS THE LOCK(S)の内容ですが、T2の1の処理で行ったpublisherテーブルへのSELECT FROM FOR UPDATEの処理によってロックがかかった事を示しています。
先にひっかかった部分でも少し述べていますが、ロックの種類は行ロックでは無く、テーブルロックとなってまして、全データ分である3行分のロック内容が出力されています。
ここで、T1の1の処理で行っているbookテーブルへのロックはどこに出力されているんだと思いましたが、これは実際に起こったdeadlockの部分だけをログとして出力している為、LAST DETECTED DEADLOCKには出力されていないのだと考えています。
実際にbookテーブルのロックがあった為、deadlockが発生しているのですが、T2の3の処理はT1がrollbackされた為、ロックが解放されてdaedlockは発生せずに処理されています。この事もあり、片方のロックの情報だけが出力されているという事です。
まとめ
今回は、MySQlにてdeadlockが発生した際にログとしてどのようなものが出力されるのかというのを検証し、その読み解き方について記載しました。
ただ、実際に業務で発生したdeadlockは、DELETE文ではなくINSERT文によるロックで発生していました。それには、インテンションロックという仕組みが関係しているのですが、その内容については別の記事を準備中です。もしよろしければ、そちらの記事も読んで頂ければと思います。
MySQLのリファレンスの内容を確認してもはっきりと記載の部分もありますので、いくつか推測の含んだ内容となってしまいましたが、今後そちらについてはっきりさせることが出来れば、追記や訂正等を行いたいと思います。もし、詳細な仕様をご存知の方がいて指摘頂ける親切な方がいましたら、コメント下さると幸いです。
