InnoDBで行ロック/テーブルロックになる条件を調べた #mysqlcasual Advent Calendar 2013
はじめに
この記事は、MySQL Casual Advent Calendar 2013 7日目の記事です。
〜 Casual に記事を書けばええんやでヽ(´ー｀)ノ 〜
私がMySQLで えっ？！ っと思った下記エントリーの挙動が何故そうなってしまうのかを書きたいと思います。
InnoDBで行ロック/テーブルロックになる条件
MyISAM はテーブルロック、InnoDB は行ロックが掛かるというのは有名な話じゃないかと。 ただ、最近知ったのですが、InnoDB だとしても必ずしも行ロックになるわけではなく、テーブルロックになる場合もあるようですね。 ... InnoDB であってもユニーク制約 or インデックスが張られているカラムで検索した場合以外はテーブルロックになってしまうようです。これは注意しないと思わぬところでテーブルロックになってしまって大変なことになりそう！
検証に使った環境は下記です
> select @@version; +-------------+ | @@version | +-------------+ | 5.5.25a-log | +-------------+ > SELECT @@global.tx_isolation; +-----------------------+ | @@global.tx_isolation | +-----------------------+ | REPEATABLE-READ | +-----------------------+
まずはえっ？！(検証したいこと)を共有しましょう。
検証したいこと
まずはテーブルとデータを作ります。
create table lock_test (
id int primary key auto_increment,
name varchar(32) not null,
age int not null
) engine=innoDB default charset=utf8;
insert into lock_test (name, age) values
('tanaka', 20),
('suzuki', 30),
('sato', 40);
> select * from lock_test; +----+--------+-----+ | id | name | age | +----+--------+-----+ | 1 | tanaka | 20 | | 2 | suzuki | 30 | | 3 | sato | 40 | +----+--------+-----+ 3 rows in set (0.00 sec)
検証はここからです。
### tx1 ### > begin; Query OK, 0 rows affected (0.00 sec) > UPDATE lock_test SET age = 21 WHERE name = 'tanaka'; Query OK, 1 row affected (0.00 sec) Rows matched: 1 Changed: 1 Warnings: 0
tanakaを更新中に..
### tx2 ### > UPDATE lock_test SET age = 31 WHERE name = 'suzuki'; ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
別のセッションからsuzukiを更新しようとするとロック待ちになります。
tanakaを更新した時にRows matched: 1 Changed: 1と出ていたのでid:1のtanakaだけがロック対象かと思ったのですがsuzukiが更新できません。
えっテーブルロックなの？InnoDBは行ロックと聞いていたのに...という気持ちになりました。
MySQLのロックはどうやって実現されているのか？
この挙動を理解するには次の事を知っておく必要があります。
http://dev.mysql.com/doc/refman/5.1/ja/pluggable-storage-overview.html
- データの保存と取得を行うレイヤーがストレージエンジンとして独立している。
- 以下、MySQLを
サーバ(SQLパーサーなどストレージエンジン以外のレイヤー)とストレージエンジンの二つの言葉で分けて書きます。 - ロックはストレージエンジンが行う
- ストレージエンジンがロックを行うため選択した ストレージエンジンによって挙動が変わります 、本記事ではInnoDBのことです。
- ロック機構をストレージエンジンが持っている ためストレージエンジンがアクセスした行がロック対象になります。
サーバとストレージエンジンのやりとりを見てみる
サーバはストレージエンジンにデータを取得するなど要求をした時にHandler API(?)と呼ばれるAPIを経由して処理を行います。このAPIの実行回数はshow session status like 'Handler%';でわかりますので、SQLを実行しながらこの値がどう変わるのかを見てみます。
まずはsession statusをクリアします。
> flush status; Query OK, 0 rows affected (0.01 sec) > show session status like 'Handler%'; +----------------------------+-------+ | Variable_name | Value | +----------------------------+-------+ | Handler_commit | 0 | | Handler_delete | 0 | | Handler_discover | 0 | | Handler_prepare | 0 | | Handler_read_first | 0 | | Handler_read_key | 0 | | Handler_read_last | 0 | | Handler_read_next | 0 | | Handler_read_prev | 0 | | Handler_read_rnd | 0 | | Handler_read_rnd_next | 0 | | Handler_rollback | 0 | | Handler_savepoint | 0 | | Handler_savepoint_rollback | 0 | | Handler_update | 0 | | Handler_write | 0 | +----------------------------+-------+ 16 rows in set (0.00 sec)
各キーの詳細はMySQL :: MySQL 5.1 リファレンスマニュアル :: 4.2.5 ステータス変数に書いてあります。
先ほどと同じSQLを実行しながら値がどうかわるか見てみます。
### tx1 ### > begin; Query OK, 0 rows affected (0.00 sec) > UPDATE lock_test SET age = 21 WHERE name = 'tanaka'; Query OK, 1 row affected (0.00 sec) Rows matched: 1 Changed: 1 Warnings: 0 > show session status like 'Handler%'; +----------------------------+-------+ | Variable_name | Value | +----------------------------+-------+ | Handler_commit | 1 | | Handler_delete | 0 | | Handler_discover | 0 | | Handler_prepare | 0 | | Handler_read_first | 1 | | Handler_read_key | 1 | | Handler_read_last | 0 | | Handler_read_next | 0 | | Handler_read_prev | 0 | | Handler_read_rnd | 0 | | Handler_read_rnd_next | 4 | <--- | Handler_rollback | 0 | | Handler_savepoint | 0 | | Handler_savepoint_rollback | 0 | | Handler_update | 1 | | Handler_write | 0 | +----------------------------+-------+ 16 rows in set (0.00 sec)
Handler_read_rnd_nextが4なので、InnoDBストレージエンジンが読み込んだ行数は4となっています。実際には1行しか更新対象がなくても、インデックスが使われずにフルスキャンを実行したため全行をストレージエンジンが読み込んだとわかります。ストレージエンジンが読み込み後にサーバによってInMemoryで対象行を抽出し実際に更新を行ったのは1件になっています。
実際にフルスキャンされるUPDATE文なのか実行計画を確認します。UPDATE文はEXPLAIN構文に対応していないので、SELECTに変換することで代替えします。(5.6からはUPDATEもEXPLAINできます)
> EXPLAIN SELECT * FROM lock_test WHERE name = 'tanaka'; +----+-------------+-----------+------+---------------+------+---------+------+------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+-----------+------+---------------+------+---------+------+------+-------------+ | 1 | SIMPLE | lock_test | ALL | NULL | NULL | NULL | NULL | 3 | Using where | +----+-------------+-----------+------+---------------+------+---------+------+------+-------------+ 1 row in set (0.00 sec)
- typeがALLなのでフルスキャン
- keyは使用されたINDEXですがありません
- ExtraがUsing whereなのでサーバがストレージエンジンから取得した後にInMemoryで再度抽出しています
ロックを調べる
SHOW ENGINE INNODB STATUSでロックが何行か確認してみましょう。
> SHOW ENGINE INNODB STATUS \G; ---TRANSACTION 2C5F2C, ACTIVE 498 sec 2 lock struct(s), heap size 376, 4 row lock(s), undo log entries 1 MySQL thread id 20, OS thread handle 0x10b174000, query id 15600 localhost root SHOW ENGINE INNODB STATUS
4 row lock(s)と出ていることがわかります。
別のセッションでinformation_schemaを参照してもロック対象行数が把握できます
> use information_schema; > SELECT trx_rows_locked FROM INNODB_TRX; +-----------------+ | trx_rows_locked | +-----------------+ | 4 | +-----------------+ 1 row in set (0.00 sec)
実データは3行しかないのに4行なのは最後の行を示すsupremumなのかな？と思ってますがよくわらないです。(教えて偉いひと！)
ここまででわかったのは次のことです。
- インデックスを使わない場合はフルスキャンする
- SHOW ENGINE INNODB STATUSやinformation_schemaのINNODB_TRXテーブルを使ってロック対象行数を調べる事ができる
- サーバとストレージエンジンのやり取りはHandler APIを使い、Handler APIの実行回数はSHOW SESSION STATUSで確認できる
動きがだんだんわかってきました。漠然とMySQLのロック気持ち悪いなーだったのが少しわかった気持ちになってきました^^
インデックスを作れば行ロックになるの？
ささたつさんの記事でインデックスを作ると行ロックになるという事でしたので、インデックスを作ってみます。
> CREATE INDEX lock_test_name_index ON lock_test(name); Query OK, 0 rows affected (0.04 sec) Records: 0 Duplicates: 0 Warnings: 0 > EXPLAIN SELECT * FROM lock_test WHERE name = 'tanaka'; +----+-------------+-----------+------+----------------------+----------------------+---------+-------+------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+-----------+------+----------------------+----------------------+---------+-------+------+-------------+ | 1 | SIMPLE | lock_test | ref | lock_test_name_index | lock_test_name_index | 98 | const | 1 | Using where | +----+-------------+-----------+------+----------------------+----------------------+---------+-------+------+-------------+ 1 row in set (0.00 sec)
インデックスは使われている事がわかります。ロック競合が行われないかを確認します。
## tx1 ## > flush status; Query OK, 0 rows affected (0.00 sec) > begin; Query OK, 0 rows affected (0.00 sec) > UPDATE lock_test SET age = 21 WHERE name = 'tanaka'; Query OK, 0 rows affected (0.00 sec) Rows matched: 1 Changed: 0 Warnings: 0 > show session status like 'Handler%'; +----------------------------+-------+ | Variable_name | Value | +----------------------------+-------+ | Handler_commit | 1 | | Handler_delete | 0 | | Handler_discover | 0 | | Handler_prepare | 0 | | Handler_read_first | 0 | | Handler_read_key | 1 | | Handler_read_last | 0 | | Handler_read_next | 1 | <--- | Handler_read_prev | 0 | | Handler_read_rnd | 0 | | Handler_read_rnd_next | 0 | <--- | Handler_rollback | 0 | | Handler_savepoint | 0 | | Handler_savepoint_rollback | 0 | | Handler_update | 1 | | Handler_write | 0 | +----------------------------+-------+ 16 rows in set (0.00 sec)
Handler_read_rnd_nextが0になり、Handler_read_nextが1になりました。 ストレージエンジンから読み出したのは1行になったことがわかります。
そして、tanakaを更新中に...
## tx2 ## > begin; Query OK, 0 rows affected (0.00 sec) > UPDATE lock_test SET age = 31 WHERE name = 'suzuki'; Query OK, 0 rows affected (0.00 sec) Rows matched: 1 Changed: 0 Warnings: 0
suzukiを更新できました!!
ロック情報はどう変わったのでしょうか。tx2はrollbackして調べてみます。
> SHOW ENGINE INNODB STATUS \G ---TRANSACTION 2C5F38, ACTIVE 7 sec 3 lock struct(s), heap size 376, 3 row lock(s), undo log entries 1
えっ3 row lock(s)？
> use information_schema; > SELECT trx_rows_locked FROM INNODB_TRX; +-----------------+ | trx_rows_locked | +-----------------+ | 3 | +-----------------+ 1 row in set (0.00 sec)
trx_rows_lockedも3になってる！？
恐らく次のように最小と最大を示すinfimumとsupremumが含まれて3になってるんじゃないかと思ってますが、よく分かりません ＞＜）
- infimum(最小)
- 対象行のid:1, name:tanaka
- supremum(最大)
分からない事も残っていますが、インデックスから読み込んだ行をストレージエンジンが行ロックした事でロック競合しなくなりました。
InnoDBはインデックスの値でロックする
次はname = tanakaが複数存在したらどうなるでしょうか。
> insert into lock_test (name, age) values ('tanaka', 30);
Query OK, 1 row affected (0.00 sec)
> SELECT * FROM lock_test;
+----+--------+-----+
| id | name | age |
+----+--------+-----+
| 1 | tanaka | 21 |
| 2 | suzuki | 31 |
| 3 | sato | 40 |
| 4 | tanaka | 30 |
+----+--------+-----+
4 rows in set (0.00 sec)
tanakaがage違いでid:1と4があります。 インデックスが無いカラムageを条件に付けてid:4のtanakaを更新します。
> flush status; Query OK, 0 rows affected (0.00 sec) > begin; Query OK, 0 rows affected (0.00 sec) > UPDATE lock_test SET age = 31 WHERE name = 'tanaka' AND age = 30; Query OK, 1 row affected (0.00 sec) Rows matched: 1 Changed: 1 Warnings: 0 > show session status like 'Handler%'; +----------------------------+-------+ | Variable_name | Value | +----------------------------+-------+ | Handler_commit | 1 | | Handler_delete | 0 | | Handler_discover | 0 | | Handler_prepare | 0 | | Handler_read_first | 0 | | Handler_read_key | 1 | | Handler_read_last | 0 | | Handler_read_next | 2 | <--- | Handler_read_prev | 0 | | Handler_read_rnd | 0 | | Handler_read_rnd_next | 0 | | Handler_rollback | 0 | | Handler_savepoint | 0 | | Handler_savepoint_rollback | 0 | | Handler_update | 1 | | Handler_write | 0 | +----------------------------+-------+ 16 rows in set (0.00 sec)
対象行は1件ですが、Handler_read_nextが2になりました。
id:4のtanakaを更新中にid:1のtanakaを更新してみると...
## tx2 ## > UPDATE lock_test SET age = 21 WHERE id = 1; ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
ロック競合しているじゃありませんか。
> explain SELECT * from lock_test WHERE name = 'tanaka' and age = 30; +----+-------------+-----------+------+----------------------+----------------------+---------+-------+------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +----+-------------+-----------+------+----------------------+----------------------+---------+-------+------+-------------+ | 1 | SIMPLE | lock_test | ref | lock_test_name_index | lock_test_name_index | 98 | const | 2 | Using where | +----+-------------+-----------+------+----------------------+----------------------+---------+-------+------+-------------+ 1 row in set (0.00 sec)
実行計画を確認するとインデックスは有効ですが、インデックスから読み込んだ行をストレージエンジンが行ロックするので、lock_test_name_indexによって2行のtanaka(idが1と4)を取得しロックを獲得。その後にサーバがage = 30に一致する行を探して1件の更新になっています。
ここまでの動きで InnoDBはUPDATEの場合にストレージエンジンで読み込んだ全ての行をロックし、検索条件にヒットするかは関係無い という事がわかりました。
ストレージエンジンが読み込んだtanakaは全てロックされています。InnoDBはインデックスの値でロックすると書いたのはこの為です。
なんだかMySQLがわかった気持ちになってきました^^
それでは、ロック情報を見てみましょう。
> SHOW ENGINE INNODB STATUS \G ---TRANSACTION 2C5F3F, ACTIVE 7 sec 3 lock struct(s), heap size 376, 5 row lock(s), undo log entries 1 > use information_schema; > SELECT trx_rows_locked FROM INNODB_TRX;+-----------------+ | trx_rows_locked | +-----------------+ | 5 | +-----------------+ 1 row in set (0.00 sec)
えっ？！5行ですね。意味がわかりません。(教えて偉い人)
まとめ
InnoDBで行ロック/テーブルロックになる条件を調べて見ました。この動きを見るとInnoDBでテーブルロックだ！と思っていたのはストレージエンジンが複数行読み込み全部の行を行ロックしていた(している)と言った方が正しそうですね。
なるほど、なるほどと理解した気持ちになったところに5 row lock(s)となって、まだまだMySQLはわからないことが多いです。
まだ調査の旅は続くのでした。
私はOracleをずっと使っていたのでMySQLの事はよく分かっていなかったのですが、下記の２冊が素晴らしい内容で私の知識不足を解消してくれました(感謝)。ココに高速道路がありました。
![エキスパートのためのMySQL[運用+管理]トラブルシューティングガイド](http://ecx.images-amazon.com/images/I/41oqE-9dM2L._SL160_.jpg)
エキスパートのためのMySQL[運用+管理]トラブルシューティングガイド
posted with amazlet at 13.12.06
実践ハイパフォーマンスMySQL 第3版
posted with amazlet at 13.12.06
明日
8日目は@nekogeruge_987さんです。かじゅある！かじゅある！
追記
実データが3件しか無いのに4 row lock(s)となった内訳を調べて見ました。
id:kamipoさんのAdvent Calendar 3日目の記事にinnodb_lock_monitorを有効にすればわかると書いてあるじゃないですかと今頃になって気付き試してみました。
> SHOW INDEX FROM lock_test; +-----------+------------+----------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+ | Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment | +-----------+------------+----------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+ | lock_test | 0 | PRIMARY | 1 | id | A | 3 | NULL | NULL | | BTREE | | | +-----------+------------+----------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+ > select * from lock_test; +----+--------+-----+ | id | name | age | +----+--------+-----+ | 1 | tanaka | 20 | | 2 | suzuki | 30 | | 3 | sato | 40 | +----+--------+-----+ 3 rows in set (0.00 sec)
上記の状態でinnodb_lock_monitorを有効にして
> CREATE TABLE innodb_lock_monitor (a INT) ENGINE=INNODB; Query OK, 0 rows affected (0.02 sec)
同じようにロックさせてみます
> begin Query OK, 0 rows affected (0.00 sec) > UPDATE lock_test SET age = 21 WHERE name = 'tanaka'; Query OK, 1 row affected (0.01 sec) Rows matched: 1 Changed: 1 Warnings: 0
innodb_lock_monitorが有効だとSHOW ENGINE INNODB STATUSでTRANSACTIONSセクションにより詳しい情報が見れるようになっています
> SHOW ENGINE INNODB STATUS \G ------------ TRANSACTIONS ------------ Trx id counter 2C5F65 Purge done for trx's n:o < 2C5F64 undo n:o < 0 History list length 756 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 2C5F57, not started MySQL thread id 26, OS thread handle 0x10b1b7000, query id 16274 localhost root ---TRANSACTION 2C5F64, ACTIVE 6 sec 2 lock struct(s), heap size 376, 4 row lock(s), undo log entries 1 MySQL thread id 22, OS thread handle 0x10b174000, query id 16288 localhost root SHOW ENGINE INNODB STATUS TABLE LOCK table `test`.`lock_test` trx id 2C5F64 lock mode IX RECORD LOCKS space id 0 page no 16944 n bits 72 index `PRIMARY` of table `test`.`lock_test` trx id 2C5F64 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 5; compact format; info bits 0 0: len 4; hex 80000001; asc ;; 1: len 6; hex 0000002c5f64; asc ,_d;; 2: len 7; hex 24000046c4088c; asc $ F ;; 3: len 6; hex 74616e616b61; asc tanaka;; 4: len 4; hex 80000015; asc ;; Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0 0: len 4; hex 80000002; asc ;; 1: len 6; hex 0000002c5f5d; asc ,_];; 2: len 7; hex a0000042c3011e; asc B ;; 3: len 6; hex 73757a756b69; asc suzuki;; 4: len 4; hex 8000001e; asc ;; Record lock, heap no 4 PHYSICAL RECORD: n_fields 5; compact format; info bits 0 0: len 4; hex 80000003; asc ;; 1: len 6; hex 0000002c5f5d; asc ,_];; 2: len 7; hex a0000042c3012c; asc B ,;; 3: len 4; hex 7361746f; asc sato;; 4: len 4; hex 80000028; asc (;;
4 row lock(s)の内訳が次のようになっています。
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 0: len 8; hex 73757072656d756d; asc supremum;;
supremumと下記の3レコード(id: hex 80000001(tanaka), hex 80000002(suzuki), hex 80000003(sato))
やはりsupremumよ君だったのか。
Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0 0: len 4; hex 80000001; asc ;; 1: len 6; hex 0000002c5f64; asc ,_d;; 2: len 7; hex 24000046c4088c; asc $ F ;; 3: len 6; hex 74616e616b61; asc tanaka;; 4: len 4; hex 80000015; asc ;; Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0 0: len 4; hex 80000002; asc ;; 1: len 6; hex 0000002c5f5d; asc ,_];; 2: len 7; hex a0000042c3011e; asc B ;; 3: len 6; hex 73757a756b69; asc suzuki;; 4: len 4; hex 8000001e; asc ;; Record lock, heap no 4 PHYSICAL RECORD: n_fields 5; compact format; info bits 0 0: len 4; hex 80000003; asc ;; 1: len 6; hex 0000002c5f5d; asc ,_];; 2: len 7; hex a0000042c3012c; asc B ,;; 3: len 4; hex 7361746f; asc sato;; 4: len 4; hex 80000028; asc (;;
supremumがロックされているということは...別のセッションでinsertを実行してみます
> insert into lock_test (name, age) values ('bluerabbit', 20);
ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction
むむむ、bluerabbitは二十歳じゃない!と怒られました。 (最大値のidがロックされているようです)
一つの疑問がすっきりしました。 kamipoさん++
使ったらあと片付けしておきましょう。(select @@datadirにあるディレクトリのエラーログに大量にログが出続ける)
> drop table innodb_lock_monitor;
