はじめに
システム事業部堤田です。
前々回の記事で、deadlockが発生した際、mysql上でコマンドshow engine innodb status;実行後に出力されるログの読み取り方を、前回の記事でmysqlのテーブルや行に対してどのような時にロックが発生するのかというので、ロックモードの一部について解説を行いました。今回の記事はそれらの集大成という事で、実際にインサートインテンションロックが原因で発生したdeadlockについて解説を行いました。
前回の記事：deadlock発生時の読み解き方（mysql5.7） 前々回の記事: deadlock発生時の読み解き方（mysql5.7） その２ Innodbのロックモードについて
事象が発生したのは本番環境ですが、流石にその内容は持ってこれませんでしたので検証環境を用意して（ほぼ）同様のDeadlockを発生させました。用意したテーブルの情報、実際に行った操作、結果をそれぞれ記載します。何故ほぼなのかは、最後に説明します。 日本語でも英語でも、詳細な解説や事例が載っている記事がなかなか見つからず、調査、検証に苦労しました。まだまだ疑問に残っている部分はありますが、事象のエッセンスは全て盛り込みました。deadlockについて理解が深まるような内容になっていれば幸いです。
deadlockの解説
Databaseの構成
CREATE TABLE books (id int NOT NULL PRIMARY KEY, title varchar(255), x_id int);
x_idは結局必要なカラムではありませんので、内容としては無視してください。後述していますが、事象の再現として断念したprimary key以外のindexにて、インサートインテンションロックをかけようと検証した際の名残です。
実際に行った操作
事前のテーブルの状態は下記の通りです。
select * from books; +----+--------+------+ | id | title | x_id | +----+--------+------+ | 10 | apatch | NULL | | 20 | beach | NULL | | 30 | chair | NULL | +----+--------+------+
T(1)は後述しているLATEST DETECTED DEADLOCK中の(1) TRANSACTIONを, T(2)は(2) TRANSACTIONになります。
- T(1):
update books set title="xxx" WHERE id BETWEEN 11 AND 19; - T(2):
update books set title="yyy" WHERE id BETWEEN 21 AND 29; - T(1):
insert into books (id, title) values (25, "docker") - T(2):
insert into books (id, title) values (15, "javascript")このタイミングでDeadlockが発生します。
deadlockのログ
------------------------ LATEST DETECTED DEADLOCK ------------------------ 2023-07-03 22:06:37 0x7f22581c1700 *** (1) TRANSACTION: TRANSACTION 31596, ACTIVE 21 sec inserting mysql tables in use 1, locked 1 LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s) MySQL thread id 22, OS thread handle 139785483310848, query id 74112 localhost root update insert into books (id, title) values (25, "docker") *** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 898 page no 3 n bits 72 index PRIMARY of table `biz3_dev`.`books` trx id 31596 lock_mode X locks gap before rec insert intention waiting Record lock, heap no 4 PHYSICAL RECORD: n_fields 5; compact format; info bits 0 0: len 4; hex 8000001e; asc ;; 1: len 6; hex 000000007b6b; asc {k;; 2: len 7; hex e6000001e90110; asc ;; 3: len 5; hex 6368616972; asc chair;; 4: SQL NULL; *** (2) TRANSACTION: TRANSACTION 31597, ACTIVE 16 sec inserting mysql tables in use 1, locked 1 3 lock struct(s), heap size 1136, 2 row lock(s) MySQL thread id 26, OS thread handle 139785483851520, query id 74113 localhost root update insert into books (id, title) values (15, "javascript") *** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 898 page no 3 n bits 72 index PRIMARY of table `biz3_dev`.`books` trx id 31597 lock_mode X Record lock, heap no 4 PHYSICAL RECORD: n_fields 5; compact format; info bits 0 0: len 4; hex 8000001e; asc ;; 1: len 6; hex 000000007b6b; asc {k;; 2: len 7; hex e6000001e90110; asc ;; 3: len 5; hex 6368616972; asc chair;; 4: SQL NULL; *** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 898 page no 3 n bits 72 index PRIMARY of table `biz3_dev`.`books` trx id 31597 lock_mode X locks gap before rec insert intention waiting Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0 0: len 4; hex 80000014; asc ;; 1: len 6; hex 000000007b66; asc {f;; 2: len 7; hex e30000019d0110; asc ;; 3: len 5; hex 6265616368; asc beach;; 4: SQL NULL; *** WE ROLL BACK TRANSACTION (2)
注目すべきはTRANSACTION (1)と(2)、HOLDS THE LOCK(S)のロックの原因です。
- TRANSACTION (1)
insert into books (id, title) values (25, "docker")- (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 898 page no 3 n bits 72 index PRIMARY of tablebiz3_dev.bookstrx id 31596 lock_mode X locks gap before rec insert intention waiting
- TRANSACTION (2)
insert into books (id, title) values (15, "javascript")- (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 898 page no 3 n bits 72 index PRIMARY of tablebiz3_dev.bookstrx id 31597 lock_mode X locks gap before rec insert intention waiting
- (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 898 page no 3 n bits 72 index PRIMARY of tablebiz3_dev.bookstrx id 31597 lock_mode X
TRANSACTION (1)と(2)両方供インサートインテンションロックであることがlock_mode X locks gap before rec insert intention waitingから分かります。
また、HOLDS THE LOCKS(S)にて、booksテーブルのprimary key(id)に対して、X（排他）ロックがかかっている事も分かります。index PRIMARY of tablebiz3_dev.bookstrx id 31597 lock_mode X 。
TRANSACTION (1)と(2)でギャップロックを用意して、同じくTRANSACTION (1)と(2)でお互いのギャップロックに対してINSERTを行っている為、インサートインテンションロックが原因でデッドロックとなっているというのが、今回の事象となります。
解説を終えて
さて、検証環境を用意して（ほぼ）同様のデッドロックを用意したと記載をしましたが、これは本番ではもう少し複雑な状況でデッドロックが発生していた為です。その状況を検証環境で用意する事が厳しかった事と、解説の記事である事から簡易的な内容で紹介する事になりました。
本番では、インデックスレコードの対象となっているのがprimary keyではなく、foreign keyでかつNOT NULLとなっておりまして、HOLDS THE LOCKSでのロック内容にも、インサートインデックスロックが発生しているとありました。この難しい点は3つあります。
- INSERT句で行を挿入しているというのにforeign key側でギャップロックを発生させて、foreign key側の行に対してインサートインテンションロックを発生させないといけない点。
- HOLDS THE LOCK(S)を発生させる処理もインサートインテンションロックとなるようにする必要がある点。
- HOLDS THE LOCK(S)でインサートインテンションロックをかけた際にギャップロックとなるようにし、そのギャップロックの部分にINSERT処理を行ってインテンションロックをかけないといけない点。
書いててややこしいですね。何とか1と2を発生させる事は出来たのですが、3を満たす方法や状況がついに分からなく、その点は妥協した事になります。本番でも稀にしか発生しないdeadlockとなっておりまして、新たにログを取る事も難しいですし、記録してあるログも手順等は無いという状況で色々と試しましたが、見つかりませんでした。最終手的にコピペミスなのではと疑って終わる事にしました。
今回の執筆中に、いくつかブログネタを見つけましたので、そのネタをまとめる内にもし再現方法が分かれば載せようとは思いますが少し悔いが残る形となってしまったのは残念です。
おわりに
幸いこのdeadlockは発生しても片方はロールバックによってトランザクション中の処理が全て無かったことにされ、もう片方は正常に成功するようになっていた事と、失敗した処理も成功するまで再実行できるようになっていましたので、データに不整合が発生したり、実行されなければいけない処理が実行されなくなるというようなことはありませんでした。この事象を発生させないようにするには、トランザクション分離レベルを変更する事もありますが、そうするとケースによってはデータの不整合が発生してしまうのを許容してしまう事になるため、処理の整理が必要になりました。この処理の整理もかなり骨が折れそうな作業でして、リレーショナルデータベースはACID特性を活かしてデータを保存する仕組みですが、厳密に実装するとなると相当に奥が深い問題なのだと改めて感じることが出来ました。
ひとえにdeadlockの発生といっても、対処方法は様々で根本から解消したり、回避したり、発生することを許容するなどある事を知れたのは今後の考え方としても役立つかなと思いました。「解説を終えて」でも記載しましたが、まだまだ理解しきれていない部分もあります。その部分については、頭の片隅に置いて何か思いついた時に改めて取り組んでいこうかと思います。
