FANCOMI Ad-Tech Blog

株式会社ファンコミュニケーションズ nend・新規事業のエンジニア・技術ブログ

innodb_print_all_deadlocksを試してみました

h_nagayamaです。 MySQLのバージョン 5.5.30 以上ならば ロック競合情報をログファイルに出力できるようになったので、今回試してみました。

関連するオプションは、innodb_print_all_deadlocks です。 詳細は、下記の公式マニュアルもご参照ください。 公式マニュアル InnoDB Startup Options and System Variables

●事前準備 検証に使用するMySQLの設定を確認します [sql]

バージョンを確認します

今回の検証に使用したのは、ver 5.5.34 になります。

mysql> show variables like 'version'; +---------------+------------+ | Variable_name | Value | +---------------+------------+ | version | 5.5.34-log | +---------------+------------+

innodb_print_all_deadlocks の設定を確認します

このオプションは Variable Scope | Global のため、set globalで設定を変更できます

mysql> show variables like 'innodb_print_all_deadlocks'; +----------------------------+-------+ | Variable_name | Value | +----------------------------+-------+ | innodb_print_all_deadlocks | ON | +----------------------------+-------+

ログに記録するようにする(有効にする)

set global innodb_print_all_deadlocks = ON ;

ログに記録させない(無効)

set global innodb_print_all_deadlocks = OFF ;

ログは log_error で設定しているファイルに出力されます

log_errorの設定先を確認します

mysql> show variables like 'log_error'; +---------------+---------------------------+ | Variable_name | Value | +---------------+---------------------------+ | log_error | /var/log/mysql/mysqld.log | +---------------+---------------------------+

[/sql]

検証用のテーブルを作成します [sql] CREATE TABLE deadlock_test ( id int(11) NOT NULL AUTO_INCREMENT, data varchar(64), PRIMARY KEY (id) ) Engine=InnoDB;

データもいくつか入れておきます

insert into deadlock_test (data) values ('data1'),('data2');

データを確認します

mysql> select * from deadlock_test ; +----+-------+ | id | data | +----+-------+ | 1 | data1 | | 2 | data2 | +----+-------+ [/sql]

●検証 ターミナルを3つ用意します [sql]

ターミナル1で

トランザクションを開始します

mysql> begin;

lock in share mode を付けて、ロックを取得します

mysql> select * from deadlock_test where id = 1 lock in share mode;

ターミナル2で

トランザクションを開始します

mysql> begin;

lock in share mode を付けて、ロックを取得します

mysql> select * from deadlock_test where id = 2 lock in share mode;

別のターミナルでロックてしているレコードを操作します

ターミナル1で

mysql> delete from deadlock_test where id = 2 ;

ターミナル2で

mysql> delete from deadlock_test where id = 1 ;

ロック競合が発生しました

ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

[/sql]

ターミナル3で、ロック競合情報がファイルに出力されたことを確認しました [html]

tail -f /var/log/mysql/mysqld.log

InnoDB: transactions deadlock detected, dumping detailed information. 150226 12:18:03 (1) TRANSACTION: TRANSACTION 9DBB20, ACTIVE 58 sec starting index read mysql tables in use 1, locked 1 LOCK WAIT 4 lock struct(s), heap size 1248, 2 row lock(s) MySQL thread id 594, OS thread handle 0x2ab70c0c2940, query id 7843 localhost root updating delete from deadlock_test where id = 2 (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 27085 page no 3 n bits 72 index PRIMARY of table db_name.deadlock_test trx id 9DBB20 lock_mode X locks rec but not gap waiting Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0 0: len 4; hex 80000002; asc ;; 1: len 6; hex 0000009dbb08; asc ;; 2: len 7; hex b500084004011e; asc @ ;; 3: len 5; hex 6461746132; asc data2;;

(2) TRANSACTION: TRANSACTION 9DBB22, ACTIVE 29 sec starting index read mysql tables in use 1, locked 1 4 lock struct(s), heap size 1248, 2 row lock(s) MySQL thread id 595, OS thread handle 0x2ab702dfe940, query id 7844 localhost root updating delete from deadlock_test where id = 1 (2) HOLDS THE LOCK(S): RECORD LOCKS space id 27085 page no 3 n bits 72 index PRIMARY of table db_name.deadlock_test trx id 9DBB22 lock mode S locks rec but not gap Record lock, heap no 3 PHYSICAL RECORD: n_fields 4; compact format; info bits 0 0: len 4; hex 80000002; asc ;; 1: len 6; hex 0000009dbb08; asc ;; 2: len 7; hex b500084004011e; asc @ ;; 3: len 5; hex 6461746132; asc data2;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 27085 page no 3 n bits 72 index PRIMARY of table db_name.deadlock_test trx id 9DBB22 lock_mode X locks rec but not gap waiting Record lock, heap no 2 PHYSICAL RECORD: n_fields 4; compact format; info bits 0 0: len 4; hex 80000001; asc ;; 1: len 6; hex 0000009dbb08; asc ;; 2: len 7; hex b5000840040110; asc @ ;; 3: len 5; hex 6461746131; asc data1;;

*** WE ROLL BACK TRANSACTION (2) [/html]

実際に導入するまでには、負荷にどの程度の影響があるのかなど、 まだ引き続き検証が必要になりますが、 この機能を上手く利用して、問題発生時の調査が少しでも捗ると嬉しいです。