読者です 読者をやめる 読者になる 読者になる

Studio3104::BLOG.new

uninitialized constant Studio3104 (NameError)

クソクエリを燻り出す


非効率なクエリが投げられて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

漢(オトコ)のコンピュータ道: MySQL 5.1のスロークエリログ

スロークエリログを参照する

スロークエリログはこんな感じで出力されます。
実行に要した時間、ロックを取得した時間などとともに、クエリが記録されていきます。

# 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)

漢(オトコ)のコンピュータ道: MySQLのEXPLAINを徹底解説!!

スロークエリの統計情報を得る

実際の運用では、スロークエリログにはたくさんのクエリが記録されることもあるので、どんなクエリがどれだけ実行されていて、平均でどれだけの時間を要しているのだろうかという統計情報が必要になってくるでしょう。
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' )

MySQL 5.1のmysqldumpslowで快速チューニング - SH2の日記

スロークエリログをローテート

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;


個人的見解ですが、この設定は「スロークエリは出てないのになんか重いねぇ(´・ω・`)」な状況のときに数分間だけ有効にしておいて、ある程度スロークエリログに出力されたら無効にするのがいいと思います。

実録MySQLのチューニング 春の陣 - (ひ)メモ