この記事は、MySQL Casual Advent Calendar 2017の20日目の記事です。
煽り気味のタイトルですがみなさん SHOW ENGINE INNODB STATUS
読んでますか?
SHOW ENGINE INNODB STATUS \G
— そーだい@初代ALF (@soudai1025) 2016年12月20日
見づらいのなんとかならんのか。
わかる。でもMySQLの振る舞いを知る中でSHOW ENGINE INNODB STATUSを読まざる得ない場面はそこそこあります。 どんな時に必要になるのでしょうか? そこでSHOW ENGINE INNODB STATUSにまつわる話を書きます。
SHOW ENGINE INNODB STATUS
をまず読みやすくする
まず末尾に \G
を付けましょう。
これで3倍読みやすくなります。
次に pager less -S
を使いましょう。
これでlessで開いた状態で読めます。
mysql> pager less -S PAGER set to 'less -S' mysql> SHOW ENGINE INNODB STATUS\G
さて読む準備は整いました。
SHOW ENGINE INNODB STATUSを読み解く
読み慣れて無い方はまず、 id:myfinder さんのスライドを読みましょう。
SHOW ENGINE INNODB STATUSの勘所が書いてあります。
www.slideshare.net
ほら読める気がしてきた。 けどこのへんの値は実はPMP(Percona Monitoring Plugins)とか使うと可視化してくれます。 みんな大好き @yoku0825 さんもオススメしてます。
勿論同等以上の事は Mackerel でも出来る(InnoDBの監視は今日の予定なので待っててくれ!!)
しかしそれでも SHOW ENGINE INNODB STATUS
を見ないといけない日はあります。
それは細かいロックの挙動を調べるときでしょう。
デッドロックを調べる
ロックの挙動を調べるにはまずInnoDB ロックモニターを有効化する必要があります。
mysql> pager less -S PAGER set to 'less -S' mysql> set GLOBAL innodb_status_output_locks=ON; Query OK, 0 rows affected (0.00 sec) mysql> SHOW ENGINE INNODB STATUS\G
ロックを調べるときはみんな大好き id:kamipo さんも
SHOW ENGINE INNODB STATUS
を使っています!
ロックの見方についてはkamipoさんの記事でカバーされているので今回は割愛します。 我々がSHOW ENGINE INNODB STATUSを求める時、それはデッドロックが発生しているときでしょう(だいたい僕はそうです)
手っ取り早くデッドロックを起こします。
-- トランザクション A mysql> begin; mysql> INSERT INTO child VALUES (1, 1); Query OK, 1 row affected (0.00 sec) --トランザクションB mysql> begin; mysql> INSERT INTO child values (1, 2); Query OK, 1 row affected (0.00 sec) -- トランザクション A mysql> UPDATE parent SET count = count + 1 WHERE id = 1; -- 待たされます! -- トランザクション B mysql> UPDATE parent SET count = count + 2 WHERE id = 1; ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction
いえーい!外部キー制約によるデッドロック!!(よく見る)
この場合、SHOW ENGINE INNODB STATUSに LATEST DETECTED DEADLOCK
が現れます。
公式ドキュメントからの引用
MySQL :: MySQL 5.6 リファレンスマニュアル :: 14.15.3 InnoDB 標準モニターおよびロックモニターの出力
LATEST DETECTED DEADLOCK このセクションは、最新のデッドロックに関する情報を提供します。デッドロックが発生していない場合は存在しません。その内容には、関連しているトランザクション、各トランザクションが実行しようとしていたステートメント、それぞれが保持しているロックと必要なロック、およびデッドロックを解消するために InnoDB がロールバックすることを決定したトランザクションが示されます。このセクションでレポートされるロックモードについては、セクション14.2.3「InnoDB のロックモード」で説明されています。
実際はこんな感じです。
------------------------ LATEST DETECTED DEADLOCK ------------------------ 2017-12-19 17:18:44 7f05bcc0d700 *** (1) TRANSACTION: TRANSACTION 5999052, ACTIVE 19 sec starting index read mysql tables in use 1, locked 1 LOCK WAIT 5 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 1 MySQL thread id 3919, OS thread handle 0x7f05bcbcc700, query id 19851 localhost root updating UPDATE parent SET count = count + 1 WHERE id = 1 *** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 20 page no 3 n bits 72 index `PRIMARY` of table `hoge`.`parent` trx id 5999052 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 0000005b89b2; asc [ ;; 2: len 7; hex a1000001550110; asc U ;; 3: len 4; hex 80000000; asc ;; *** (2) TRANSACTION: TRANSACTION 5999053, ACTIVE 10 sec starting index read mysql tables in use 1, locked 1 5 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 1 MySQL thread id 3886, OS thread handle 0x7f05bcc0d700, query id 19852 localhost root updating UPDATE parent SET count = count + 2 WHERE id = 1 *** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 20 page no 3 n bits 72 index `PRIMARY` of table `hoge`.`parent` trx id 5999053 lock mode S locks rec but not gap 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 0000005b89b2; asc [ ;; 2: len 7; hex a1000001550110; asc U ;; 3: len 4; hex 80000000; asc ;; *** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 20 page no 3 n bits 72 index `PRIMARY` of table `hoge`.`parent` trx id 5999053 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 0000005b89b2; asc [ ;; 2: len 7; hex a1000001550110; asc U ;; 3: len 4; hex 80000000; asc ;; *** WE ROLL BACK TRANSACTION (2)
TRANSACTION (2)がデッドロックによってロールバックしていることがわかります。
このようにデッドロックを紐解くためには SHOW ENGINE INNODB STATUS
が役にたちます。
その他には?
最新の外部キー制約エラーがわかる LATEST FOREIGN KEY ERROR
やロックの状態自体やクエリの振る舞いを知るためには TRANSACTION
を覗くのが良いでしょう。
しかしSHOW ENGINE INNODB STATUSはその時の状態なので本番で常にSQLが複数回実行されるような場合では1度実行しただけでは全てを知ることが出来ません。
実際には set GLOBAL innodb_status_output=ON;
を実行してSHOW ENGINE INNODB STATUSの情報をエラーログに20秒置きに吐いておき、それを見比べながらロックを取り合えっているSQLを調べることになります。
クエリを見比べるときは id:sh2 さんのもう1億回くらい見たであろう下記の記事からロック競合を表示するSQLのViewを作っておきましょう。
僕はさらにこれを5秒に1回ログに保存したりしてました。
MySQL InnoDBにおけるロック競合の解析手順 - SH2の日記
おっと、ロックについてちょっと熱くなってしまいました。
ロックは主題ではないので話がずれましたがあとは 詳しい人に聞いてください!id:ichirin2501
より深く知るためには?
ちなみに PMP for Cacti については下の本にめっちゃ詳しく書いてあります。 モニタリング本の基礎としてオススメです。
あとSHOW ENGINE INNODB STATUSについて詳しく知るには 実践ハイパフォーマンスMySQL を読むのがもっとも近道です。
また実践ハイパフォーマンスMySQLはMySQLの振る舞いを深く知ることができますのでMySQL使いは必読です。
ちなみに僕はMySQLのソースコード詳しいわけではないので実践ハイパフォーマンスMySQLを読んだ程度の SHOW ENGINE INNODB STATUS
力です。
というわけで SHOW ENGINE INNODB STATUS
は怖くないのでぜひこの機会に使いこなしてみましょう。