Mysql5.5でスロークエリに関して調べたのでまとめました。
Mysql5.1からスロークエリのパラメータが変わっているので注意しましょう。
そのためMysql5.1より前のバージョンでは内容が異なります。
設定を確認する
Mysqlのコンソールからshow variablesコマンドで、スロークエリの設定を確認できます。
mysql> show variables like 'slow%'; +---------------------+----------------+ | Variable_name | Value | +---------------------+----------------+ | slow_launch_time | 2 | | slow_query_log | OFF | | slow_query_log_file | mysql-slow.log | +---------------------+----------------+
slow_query_log がOFFになっているとスロークエリの出力は行われません。
mysql> show variables like 'long%'; +-----------------+-----------+ | Variable_name | Value | +-----------------+------------+ | long_query_time | 10.000000 | +-----------------+-----------+
slow_query_logがONのとき、long_query_timeを超えるクエリがスロークエリとして出力されます。
スロークエリを出力する（コンソールからの設定）
コンソールから設定を変更する場合はset globalコマンドで変更することができます。
mysql> set global slow_query_log_file = '/tmp/mysql-slow.log'; mysql> set global long_query_time = 5; mysql> set global slow_query_log = ON;
show vairables コマンドで設定を確認すると、変更されていることが確認できます。
long_query_time の値が変更されていない場合がありますが、その時は一度コンソールを閉じ
最ログインすると変更されていることが確認できます。
変更には相当のユーザー権限が必要です。rootでログイン出来る場合はrootで作業しましょう。
スロークエリを出力する（my.cnfの設定）
my.cnf にパラメータを設定してスロークエリのログを出力します。
root権限で設定ファイルを編集します。
$ sudo vim /etc/my.cnf
[mysqld] slow_query_log slow_query_log-file = /var/log/mysql/mysql-slow.sql long_query_time = 5
slow_query_log = ONを記述することでスロークエリの出力を有効にします。
デフォルトでは無効になっています。
mysql5.0以前ではlog_slow_queriesというオプションなので、記述してある場合はコメントアウトしてください。
log_output=FILEが指定されているとき、slow_query_log_fileオプションで指定されているファイルへログが記録されます。
long_query_timeで何秒以上かかったスロークエリをログへ記録するかを指定します。
Mysql5.1から、1秒未満の秒数（マイクロ秒まで）を小数で指定できるようになりました。
mysqldumpslowを使って集計する
mysqldumpslow コマンドを使ってスロークエリの集計を行うことができます。
-s オプションでどの項目でソートするかを指定することができます。
例では t: query timeを指定しました。その他のオプションは -h でヘルプを確認して下さい。
$ mysqldumpslow -s t /var/log/mysql/mysql-slow.sql Count: 93 Time=4.40s (409s) Lock=0.00s (0s) Rows=5.0 (465), ebisu[ebisu]@2hosts show index from `bom`.`logs` Count: 86 Time=3.76s (323s) Lock=0.00s (0s) Rows=0.4 (34), meguro[meguro]@localhost SELECT `hash`.`id` FROM `hash` WHERE (`key` = 'S')
スロークエリとなっているSQLが種類別に集計され、実行時間の遅いものから順番にレポートされました。
これをもとに上から順に対策を行っていけば良いというわけです。
これを応用すると、スロークエリだけでなくすべてのクエリの実行状況を集計することができます。
先に説明したパラメータをコンソールから変更してすべてのクエリをログに出力するように設定しましょう。
mysql > set global slow_query_log_file = '/tmp/slow.log'; mysql > set global long_query_time = 0;
このように設定することで、/tmp/slow.logに実行されたすべてのSQLが出力されます。
こうすると相応の負荷がサーバーにかかるので、ディスクやCPUを観察しながら数十秒〜数分間待ってから設定をもとに戻します。
出力されたログファイルを分析しましょう。
今回はソートオプションに c: count を指定します。
$ mysqldumpslow -s c /tmp/slow.log Count: 27153 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.0 (0), ebisu[ebisu]@localhost SELECT `m`.`id`, report.ratio AS `ratio` FROM `l` AS `l` LEFT JOIN `report` AS `report` ON l.id = report.l_id AND report.d = 'S' WHERE (l.p_id = 'S') AND (l.kind = 'S') AND (l.status = N) AND (l.deleted = N) AND (l.id not in (N)) Count: 18762 Time=0.00s (1s) Lock=0.00s (0s) Rows=0.0 (0), sugamo[sugamo]@localhost SELECT `settings`.`value` FROM `settings` WHERE (`key` = 'S') Count: 4032 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), 2users@2hosts # Count: 4031 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), tamachi[tamachi]@localhost SELECT `l`.* FROM `l` WHERE (id = N) AND (deleted = N) Count: 4026 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), 0users@0hosts administrator command: Quit Count: 4012 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), mejiro[mejiro]@localhost SELECT `filter`.`l_id` FROM `filter` WHERE (c_id = 'S') ORDER BY `l_id` asc Count: 4012 Time=0.00s (3s) Lock=0.00s (0s) Rows=0.1 (563), yoyogi[yoyogi]@localhost SELECT `hash`.`id` FROM `hash` WHERE (`key` = 'S') Count: 4012 Time=0.00s (0s) Lock=0.00s (0s) Rows=0.0 (0), osaki[osaki]@localhost set names 'S'
この方法をとれば、1回の実行には0.1秒しかかからないけれど毎分1万回実行されるため負荷の大半を占めている、
といったSQLを簡単に特定することができます。
スロークエリをDBに出力する
Mysql5.1からはスロークエリをログファイルではなくDBに保存することができるようになりました。
先にも少し出てきましたが、log_output オプションに TABLE を指定します。
my.cnf の場合は
[mysqld] log_output = TABLE
コンソールからの場合は
mysql> set global log_output = 'TABLE';
そうするとスロークエリログが mysql.slow_log というテーブルに出力されるようになります。
また、あわせて一般ログも mysql.general_log というテーブルに出用されるのでこちらも意識しておいてください。
これらのテーブルはCSVストレージエンジンを用いて作成され、以下のような構成になります。
mysql> show create table mysql.slow_log \G *************************** 1. row *************************** Table: slow_log Create Table: CREATE TABLE `slow_log` ( `start_time` timestamp NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP, `user_host` mediumtext NOT NULL, `query_time` time NOT NULL, `lock_time` time NOT NULL, `rows_sent` int(11) NOT NULL, `rows_examined` int(11) NOT NULL, `db` varchar(512) NOT NULL, `last_insert_id` int(11) NOT NULL, `insert_id` int(11) NOT NULL, `server_id` int(10) unsigned NOT NULL, `sql_text` mediumtext NOT NULL ) ENGINE=CSV DEFAULT CHARSET=utf8 COMMENT='Slow log' 1 row in set (0.00 sec)
テーブルに出力することで、SQLによる集計作業が行えるため柔軟にスロークエリを解析することができます。
参考
http://nippondanji.blogspot.jp/2009/01/mysql-51.html
http://www.kakashi.biz/%E3%83%97%E3%83%AD%E3%82%B0%E3%83%A9%E3%83%A0/mysql5-5-%E3%81%A7-slow-query-log-%E3%82%B9%E3%83%AD%E3%83%BC%E3%82%AF%E3%82%A8%E3%83%AA%E3%83%BC%E3%83%AD%E3%82%B0-%E3%82%92%E6%8E%A1%E3%82%8B/
http://d.hatena.ne.jp/sh2/20090414
