クソクエリを燻り出す
非効率なクエリが投げられてMySQLサーバが悲鳴をあげることがあります。
DBAは、そんなときに「こんなクソクエリ投げてんじゃねーよ(ノ｀Д´)ノ彡┻━┻」と言えるようにダメクエリを探し出せるようにしておく必要があります。
スロークエリログ
スロークエリログを出力するようにする
my.cnfにこのように書いておくと、実行に指定時間以上を要したクエリが指定ファイルに出力されるようになります。
※MySQL5.0以前のバージョンは書き方が異なるので注意
この例では、「実行に0.5秒以上かかったクエリを/var/log/mysql/slow.logに吐く」ようになります。
[mysqld] slow_query_log=1 slow_query_log_file=/var/log/mysql/slow.log long_query_time=0.5
スロークエリログを参照する
スロークエリログはこんな感じで出力されます。
実行に要した時間、ロックを取得した時間などとともに、クエリが記録されていきます。
# cat /var/log/mysql/slow.log /usr/sbin/mysqld, Version: 5.5.22-log (MySQL Community Server (GPL)). started with: Tcp port: 3306 Unix socket: /var/lib/mysql/mysql.sock Time Id Command Argument # Time: 120427 11:39:30 # User@Host: user[user] @ webxx [192.168.xx.xx] # Query_time: 0.693937 Lock_time: 0.000049 Rows_sent: 2826 Rows_examined: 170699 SET timestamp=1335510385; SELECT family_name FROM user_data WHERE ( country_id = '19' );
スロークエリのスローたる所以を探る
スロークエリログに吐かれたクエリをEXPLAINして、どんな問題があるのかを探ります。
「type: ALL」なので、ただちに駆逐すべきクソクエリだということがわかります。
mysql> EXPLAIN SELECT family_name FROM user_data WHERE ( country_id = '19' )\G *************************** 1. row *************************** id: 1 select_type: SIMPLE table: user_data type: ALL possible_keys: NULL key: NULL key_len: NULL ref: NULL rows: 188592 Extra: Using where 1 row in set (0.00 sec)
スロークエリの統計情報を得る
実際の運用では、スロークエリログにはたくさんのクエリが記録されることもあるので、どんなクエリがどれだけ実行されていて、平均でどれだけの時間を要しているのだろうかという統計情報が必要になってくるでしょう。
mysqldumpslowを使えば、スロークエリログを解析して統計情報を出力してくれます。
前述したEXPLAINを、スロークエリログに吐かれたクエリ全てに対して行うのは大変なので、回数が多いものや、平均実行時間が長いものからEXPLAINしていくのがいいでしょう。
個人的には、mysqldumpslowの結果に、EXPLAINの結果を含めてくれるようになればイイナと思ってます。
# mysqldumpslow /var/log/mysql/slow.log Reading mysql slow query log from /var/log/mysql/slow.log Count: 50 Time=0.67s (0s) Lock=0.00s (0s) Rows=2826.0 (2826), user[user]@20host SELECT family_name FROM user_data WHERE ( country_id = 'S' )
スロークエリログをローテート
mysqldさんは、ログをローテートしてくれないので運用側で工夫しなくてはなりません。
スロークエリログをローテートしないと、mysqldunpslowで取得した統計情報に古い情報が含まれてしまうので、「そのクエリはもう潰したよ(´・ω・｀)」とか言われてしまうかも知れません。
ログの切り替えは、以下のいずれかの方法で行えます。
ちなみに自分の場合は、「mysqldump --flush-logs」の方法をよく用いています。
日次のバックアップスクリプトの中で、mysqldumpとmysqldupslowを一緒に処理しています。
- mysqladmin flush-logs
バイナリログなどのログまで一括で切り替わります。
# cd /var/log/mysql # mv slow.log slow.log.old # mysqladmin flush-logs
- FLUSH SLOW LOGS
MySQL5.5以降のバージョンであれば、個別に切り替えることが出来る。
mysql> FLUSH SLOW LOGS;
- mysqldump --flush-logs
MySQL5.5でやる場合はマイーナーバージョンに注意！
mysqldump --single-transaction に --flush-logs をつけてはいけない - @tmtms のメモ
インデックスを使っていないクエリをログに吐く
スロークエリログから得られる情報だけでは不十分だったり、設定によっては不都合が生じることがあります。
「long_query_time」をあまり低い値に設定してしまうと、健全なクエリが紛れ込んでしまうかも知れないし、スロークエリログファイルが肥大してしまうかも知れません。
例えば、「long_query_time」を1で設定している場合は、実行時間が0.8秒で、フルスキャンやフルインデックススキャンをしている効率の悪いクエリをキャッチできなくなります。
そんなゴミクエリが頻繁に使われると、「スロークエリは出てないのになんか重いねぇ(´・ω・｀)」とかってことになってしまいます。
以下のようにすると、実行時間が「long_query_time」の設定値未満で、フルスキャンやフルインデックススキャンをしている効率の悪いクエリをスロークエリログに出力するようになります。
- my.cnfに記述
[mysqld]
log_queries_not_using_indexes=1
- オンラインで設定変更
mysql> set @@global.log_queries_not_using_indexes=1;
個人的見解ですが、この設定は「スロークエリは出てないのになんか重いねぇ(´・ω・｀)」な状況のときに数分間だけ有効にしておいて、ある程度スロークエリログに出力されたら無効にするのがいいと思います。
