コンテンツへスキップ

MySQLのInnoDBでLock待ちのSQLを調べる

ロンドンオリンピックもいよいよ閉会式が近づいて来てて、寝不足だった日々が終わると思うと、なんだか寂しい気持ちで。

男子サッカーはトゥーロン国際大会の頃はどうなることかと思いましたが、オリンピックではすばらしい試合の連続で、良かったです。特にエジプト戦の清武のチェイスからの永井のゴールは最高でした。

まあ、最後の試合は勝ってほしかったですが・・・。

さて、MySQLのチューニングの話ですが、よくあるチューニングといえば、innodb_buffer_poolなどのメモリ周りのチューニング、スロークエリを利用したクエリチューニングなどがあります。

基本的にはどちらかが万全であればほぼ問題は無いかと思いますが、そんなに難しいクエリでもなく、explainでも単発でも実行時間に問題はないクエリで性能問題が発生することがあります。

ロック待ちを誘発するようなクエリです。

InnoDBのテーブルの場合は更新系のクエリでも基本は行ロックなので粒度は低いものの、複数行のUPDATEなどでは待たされる可能性があります。

なので、information_schemaを使った待ちが発生しているクエリの調査方法を簡単に試しました。

使うテーブルはこちらになります。
information_schema.innodb_lock_waits　：　ロック待ち情報
information_schema.innodb_trx　：　トランザクション情報

テーブルはCityテーブルをInnoDBで作ってます。

トランザクション1からスタート
mysql> set autocommit = 0;
Query OK, 0 rows affected (0.00 sec)

mysql> select * from City where id = 1;
+—-+——-+————-+———-+————+
| ID | Name | CountryCode | District | Population |
+—-+——-+————-+———-+————+
| 1 | Kabul | AFG | Kabol | 1780000 |
+—-+——-+————-+———-+————+
1 row in set (0.00 sec)

mysql> update City set Population = Population + 1 where id = 1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1 Changed: 1 Warnings: 0

mysql> select * from City where id = 1;
+—-+——-+————-+———-+————+
| ID | Name | CountryCode | District | Population |
+—-+——-+————-+———-+————+
| 1 | Kabul | AFG | Kabol | 1780001 |
+—-+——-+————-+———-+————+
1 row in set (0.00 sec)

commitはしないで、

次にトランザクション2でロックを発生させます。

トランザクション2をスタートmysql> set autocommit = 0;
Query OK, 0 rows affected (0.00 sec)mysql> select * from City where id = 1;
+—-+——-+————-+———-+————+
| ID | Name | CountryCode | District | Population |
+—-+——-+————-+———-+————+
| 1 | Kabul | AFG | Kabol | 1780000 |
+—-+——-+————-+———-+————+
1 row in set (0.00 sec)

mysql> update City set Population = Population + 10 where id = 1;

ここでロック待ちになります。

ロック待ちの間にinformation_schemaを確認。

まずは、innodb_trxからmysql> select * from innodb_trx\G
*************************** 1. row ***************************
trx_id: 24B1EC
trx_state: LOCK WAIT
trx_started: 2012-08-13 00:13:40
trx_requested_lock_id: 24B1EC:96:4:2
trx_wait_started: 2012-08-13 00:16:04
trx_weight: 2
trx_mysql_thread_id: 20247
trx_query: update City set Population = Population + 10 where id = 1
trx_operation_state: starting index read
trx_tables_in_use: 1
trx_tables_locked: 1
trx_lock_structs: 2
trx_lock_memory_bytes: 1248
trx_rows_locked: 1
trx_rows_modified: 0
trx_concurrency_tickets: 0
trx_isolation_level: READ COMMITTED
trx_unique_checks: 1
trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
trx_adaptive_hash_latched: 0
trx_adaptive_hash_timeout: 10000
*************************** 2. row ***************************
trx_id: 24B10F
trx_state: RUNNING
trx_started: 2012-08-13 00:10:44
trx_requested_lock_id: NULL
trx_wait_started: NULL
trx_weight: 3
trx_mysql_thread_id: 20353
trx_query: NULL
trx_operation_state: NULL
trx_tables_in_use: 0
trx_tables_locked: 0
trx_lock_structs: 2
trx_lock_memory_bytes: 376
trx_rows_locked: 1
trx_rows_modified: 1
trx_concurrency_tickets: 0
trx_isolation_level: READ COMMITTED
trx_unique_checks: 1
trx_foreign_key_checks: 1
trx_last_foreign_key_error: NULL
trx_adaptive_hash_latched: 0
trx_adaptive_hash_timeout: 10000
2 rows in set (0.00 sec)2つのトランザクションが実行中ということがわかります。

しかも、trx_id: 24B1ECの方はtrx_state: LOCK WAITということでロック待ちのようです。

そして、innodb_lock_waitsの方を見ると、

mysql> select * from innodb_lock_waits;
+——————-+——————-+—————–+——————+
| requesting_trx_id | requested_lock_id | blocking_trx_id | blocking_lock_id |
+——————-+——————-+—————–+——————+
| 24B1EC | 24B1EC:96:4:2 | 24B10F | 24B10F:96:4:2 |
+——————-+——————-+—————–+——————+
1 row in set (0.00 sec)

24B1ECは24B10Fにブロックされていることがわかります。

そうこうしていると、トランザクション2の方がロック待ちタイムアウトしてしまいました。

トランザクション2
mysql> update City set Population = Population + 10 where id = 1;
ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transactionここでinnodb_lock_waitsを見ると・・・mysql> select * from innodb_lock_waits;
Empty set (0.01 sec)

なくなりました。

trxは？

mysql> select trx_id from innodb_trx;
+——–+
| trx_id |
+——–+
| 24B1EC |
| 24B10F |
+——–+
2 rows in set (0.00 sec)

まだ2つあります。
ロックがタイムアウトしただけで、トランザクションが終わったわけではないです。

ここで、トランザクション1をコミットしてみると？

トランザクション1
mysql> commit;
Query OK, 0 rows affected (0.00 sec)

ステータスは？

mysql> select trx_id from innodb_trx;
+——–+
| trx_id |
+——–+
| 24B1EC |
+——–+

トランザクション2だけになりました。

トランザクション2もコミットで

トランザクション2
mysql> select * from City where id = 1;
+—-+——-+————-+———-+————+
| ID | Name | CountryCode | District | Population |
+—-+——-+————-+———-+————+
| 1 | Kabul | AFG | Kabol | 1780001 |★トランザクション1がコミットされてます。
+—-+——-+————-+———-+————+
1 row in set (0.00 sec)mysql> commit;
Query OK, 0 rows affected (0.00 sec)
mysql> select trx_id from innodb_trx;
Empty set (0.01 sec)そして誰もいなくなった・・・

残念ながら、どのトランザクションで待たされているかだけしかわかりませんが、どのクエリで待ちが発生しているかどうかは、innodb_lock_waitsを検索していればわかりそうです。

また、この方法では全てのロックを網羅することはできませんが、global statusを確認することで、行ロックの回数を調べることはできます。

mysql> select * from global_status where variable_name like “innodb%lock%”;
+——————————-+—————-+
| VARIABLE_NAME | VARIABLE_VALUE |
+——————————-+—————-+
| INNODB_ROW_LOCK_CURRENT_WAITS | 1 |★現在の行ロック待ちのクエリ数
| INNODB_ROW_LOCK_TIME | 2525715 |★ロック待ち時間の合計（ミリ秒）
| INNODB_ROW_LOCK_TIME_AVG | 1151 |★ロック待ち時間の平均（ミリ秒）
| INNODB_ROW_LOCK_TIME_MAX | 121268 |★ロック待ち時間の最大（ミリ秒）
| INNODB_ROW_LOCK_WAITS | 2193 |★ロック待ちのクエリ総数
+——————————-+—————-+
5 rows in set (0.03 sec)
タグ:

「MySQLのInnoDBでLock待ちのSQLを調べる」への1件のフィードバック

  1. ピンバック: MySQLのロックに関して+サブクエリ内のupdate – skillup

コメントを残す

メールアドレスが公開されることはありません。 ※ が付いている欄は必須項目です

CAPTCHA