最近ではPaaS型のクラウドがかなり普及しており、サーバを自分で用意しなくても簡単にサービスを公開できるようになりました。そのため、自分向けの便利サービスなどを作っている人も多いのではないかと思います。しかし、サービスの初期段階だとうまく動いていた機能が時とともに、だんだんと重くなっていき使いにくくなることもあるかと思います。

そんな時には、データベースに限った話ではありませんが、チューニングをしよう！と考えるかと思いますが、どこをどのようにチューニングすれば高速化が見込めるかは、しっかりと計測してみないとわかりません。当てずっぽうにチューニングした結果、実はあまり関係がなかったということもあるかと思います。

そこで、今回はMySQLに簡単な設定をすることで遅いSQLを記録するためのスロークエリーログを有効にして、チューニングのために必要な情報を収集できるようにしたいと思います。

デモンストレーション環境

今回使用する環境はMac OS X（10.10.5）の上にHomebrewを用いて構築した5.7.9上での作業とします。Homebrewのインストールに関しては割愛させていただきます。

mysqlのインストールの詳細に関しても割愛させていただきますが、以下のコマンドを叩き、インストールを行いました。基本的には下記で説明がない限り、デフォルトの設定をそのまま利用しています。

$ brew install mysql

また、今回使用するデータは「第2回　MySQLにはじめてのデータを入れてみる」で紹介している郵便番号のテーブルを用いて紹介を行います。

スロークエリーログとは？

スロークエリーログとは、名前の通りSQLの実行にかかった時間がしきい値を超え、更に指定の行数以上の行をチェックする必要があったSQLを保存する仕組みになります。

デフォルトではスロークエリーログは無効になっており、設定を行わない場合は出力されません。

また、スロークエリーログを設定した場合でも、ユーザの削除や追加、一時的な設定の変更などに使うSET構文など、データベース管理ステートメントと呼ばれるデータベースを管理するために使われるSQLに関しては、出力がされないようになっています。

それほど問題になるケースは無いとは思いますが、スロークエリーログを出力する時にはファイルへの書き出しを行うため、すでに動いているサービスのデータベースに対してスロークエリーログを設定した場合などは、性能が低下していないか確認しつつ進めてください。

スロークエリーログを出力するように設定する

スロークエリーログはデフォルトでは出力されないため、スロークエリーログを確認したい場合はMySQLに設定を行う必要があります。

MySQLに設定を行うには、クライアントから指定する方法と、my.cnfやmy.iniファイルに設定ファイルを用意する方法の2つがあります。クライアントから設定を指定する場合は再起動をすると設定が戻ってしまうので、今後も使用していく場合は設定ファイルに書き込むようにしましょう。

クライアントから設定する場合は下記のコマンドを打ち込みます。設定値は1がONで0がOFFになります。

mysql> set global slow_query_log=1;
mysql> set global long_query_time=1;
mysql> set global log_queries_not_using_indexes=1;
mysql> set global slow_query_log_file ='/usr/local/var/mysql/slow_query.log';

最後のslow_query_log_fileのsetでエラーが出た場合は、別のディレクトリを指定するか、もしくは指定したファイルを適宜作って書き込み権限を与えてください。

設定ファイルに記載する場合は、以下の記述を/etc/my.cnfとしてください。Windowsの場合はdatadir内にmy.iniファイルがあるかと思われるので、そこに設定を追加します。クライアントから設定を変更していない場合は、設定を有効にするためMySQLを再起動しておいてください。

$ cat /etc/my.cnf
[mysqld]
slow_query_log=1
long_query_time=1
log_queries_not_using_indexes=1
slow_query_log_file=/usr/local/var/mysql/slow_query.log

今回の設定で行った内容は下表のとおりになります。

次に、この設定を元にスロークエリーログを収集してみようと思います。

スロークエリーログを発生させてみる

今回の設定でスロークエリーログが記録される条件は、1秒以上かかった場合、もしくはindexが未使用なSQLが実行された場合の2つです。第2回で作成したzipcodeデータベースのzipcodeテーブルに対して、以下のように東京都渋谷区に該当する郵便番号が何件存在するかを集計する簡単なselect文を実行してみようと思います。

mysql> use zipcode
mysql> SELECT COUNT(*) FROM zipcode WHERE city='渋谷区' AND prefecture='東京都';
+----------+
| COUNT(*) |
+----------+
|       73 |
+----------+
1 row in set (0.06 sec)

今回の実行結果は0.06秒で、1秒未満のため対象外になるように思えますが、zipcodeテーブルは現在一切のindexが貼られていない状態です。そのため上記のSQLでは当然indexが使われないため、スロークエリーログに記録がされているはずです。slow_query_log_fileで指定したファイルの中身を確認してみましょう。

$ cat /var/log/slow_query.log
/usr/local/Cellar/mysql/5.7.9/bin/mysqld, Version: 5.7.9 (Homebrew). started with:
Tcp port: 3306  Unix socket: /tmp/mysql.sock
Time                 Id Command    Argument
# Time: 2015-11-16T03:52:04.838389Z
# User@Host: root[root] @ localhost []  Id:    20
# Query_time: 0.052903  Lock_time: 0.000113 Rows_sent: 1  Rows_examined: 123864
use zipcode;
SET timestamp=1447645924;
SELECT COUNT(*) FROM zipcode WHERE city='渋谷区' AND prefecture='東京都';

一番最後の行に注目していただくと、先ほど実行したSQLがしっかりと記載されていることがわかります。今後対象となるSQLが実行されるたびに、スロークエリーログに追記されていきます。

まとめ

今回はスロークエリーログを使って遅いクエリを収集することができるようになりました。そこからIndexを貼り直したり、遅いSQLを別のSQLへの置換えを行ったりするなどのチューニングを進めていくことができるようになります。またサービスの公開前であれば、サービスのボトルネックになりそうな箇所の特定なども可能になります。

MySQLを運用している場合には、ぜひ一度スロークエリーログを覗いてみてはいかがでしょうか。