MySQLで運用中のシステムにSQLチューニングする方法～ボトルネックを発見せよ～

ビヨンドの原岡です。
今日はMySQLのSQLチューニングについてです。

 

• システムが遅い！
• サーバが急に重くなった！

 

という時に劇的な効果をもたらすのがSQLチューニングです。
今回は、ボトルネックを見つける方法です。

・なぜSQLチューニングか？

システムが急に遅くなる原因の半分（50％）くらいがDBが起因しています。
DBに問題があった場合、その中で7割がSQL起因かなと。

100% × 0.5 × 0.7 = 35%

というわけでSQLチューニングを覚えれば、
急にシステムが重くなる問題の1/3位が解決するはず！！

※今までの経験則によるものです

・SQLチューニングの流れ

では早速やってみましょう。
大きな流れで行くとSQLチューニングは以下のような流れになります。

① 重いSQLの特定
↓
② SQL解析
↓
③ SQLの変更orインデックス付与

重いSQLの特定

まずは重いSQL文を特定します。

・slowlogの出力

slowlogというログを出力して、重いSQLを出力します。
これは一定以上の時間がかかったSQLをログに出力することができます。

Slowlogの出力はmy.cnfに以下のように記載します。

[mysqld]
slow_query_log = 1　　　---slowlogを有効化
long_query_time = 1　　---SQLの出力時間の設定

long_query_timeはまずは1秒から始めるのがやりやすいです。
何故かと言うと、long_query_timeは0.1秒単位で設定できるのですが、0.1秒で設定すると大量に出力される場合もあるので、
まず1秒以上のSQL文からつぶしていくのがよいです。

5.1系以降は再起動せずに設定を変更できるglobal変数になったので、サーバを起動したまま設定可能です。

mysql> set global slow_query_log = 1; 
mysql> set global long_query_time = 1;

mysql> show variables like "%query%";

+------------------------------+----------------+
| Variable_name                | Value          |
+------------------------------+----------------+
| long_query_time              | 1.000000       |
| slow_query_log               | OFF            |
+------------------------------+----------------+

set globalのみだと再起動で設定が戻ってしまうためコンフィグファイルに追記しておきます。
※5.0系は上記が使えないので設定後に再起動します。

$ vi /etc/my.cnf 
---------------------
[mysqld]
slow_query_log = 1
long_query_time = 1
---------------------

$ service mysqld restrart

ファイルパスを指定しない場合はデータディレクトリに出力されます。

$ ll /var/lib/mysql/
mysql-slow.log

・Slowlogの見方

中身を見ると下記のようなログが出力されています。

$ tail -100 mysql-slow.log

(1)# Time: 150926  4:30:04

(2)# User@Host: hogeuser[hogedb] @ [172.16.0.1]
(3)# Query_time: 1.644283 Lock_time: 0.542217 Rows_sent: 3 Rows_examined: 9971
use hogedb;
(4)SET timestamp=1424145644;
SELECT 1 FROM aaa_history WHERE id = 26 AND code = 'bbbb';

ここで大事なのがRows_examined（処理対象行数）です。
これが「データベースがどれだけのデータを読み込んだか」というところになります。
つまりこの値が多いほどデータを読み込んでいるということです。

さらにRows_sentで割れば1行を出力するのに何行の読み込みをしたのかもわかります。
今回の場合は

Rows_examined: 9971　÷　Rows_sent: 3 　 = 3323

で1行を出力するのに3323行のデータを読み込んでいるということですね。

なのでざっとログを見ていってRows_examinedが大きいSQLをピックアップしていってください。
Rows_examinedの数値が大きいSQLがボトルネックになっている場合が多いです。

mysqldumpslowの実行

出力されたslowlogの統計を取り、さらに重いSQLを特定したい場合は、
mysqldumpslowというコマンドでslowlogの統計を取ることができます。
このコマンドを使うと、ちょっと重くて実行回数が多いSQLなどを見つけやすいです。

・ログの切り出し

slowlogをそのままmysqldumpslowをかけることもできますが、
長期間の運用でログがたまっている場合は適当な行数でログを切り出した方が直近の重いSQLを特定しやすいです。

$ tail -10000 /var/lib/mysql/mysql-slow.log > /home/hogeuser/160721_mysql-slow.log

・mysqldumpslowの実行

上記で切り出したログをmysqldumpslowで解析し、別のファイルに書き出します。

$ mysqldumpslow -s t /home/hogeuser/160721_mysql-slow.log > /home/hogeuser/160721_mysqldumpslow.log

-s
sort_typeで出力のソート方法を決定します。
ソートの内容は下記となります。

上記コマンドでslowlogの統計が出力されます。

・出力結果の確認

先ほど出力したファイルを確認すると、クエリー実行時間の多い順に出力されます。

$ more 160721_mysqldumpslow.log

①Count: 762 Time=14.12s (10761s) Lock=0.00s (0s) Rows=45.9 (34974), 5users@13hosts
use aaa_db;
SET timestamp=N;
②select * from aaa_history where id = N and mid = N and kid in (N,N,N,N,N,N,N,N,N,N,N,N,N) and status = N

①

②SQL
出力した結果の上位にあがっていて、「Countが少なく平均Timeが長いもの」は重いSQLです。
こちらはslowlogからでもみつけやすいボトルネックです。

出力した結果の上位にあがっていて、「Countが多く平均Timeが短く累計実行時間が長いもの」はある程度重く、回数がたくさん発生しているSQLです。
これはmysqldumpを使用しないと見つけにくいボトルネックになります。

次はSQLの解析方法について説明します。

MySQLで運用中のシステムにSQLチューニングする方法　その2　～SQL解析～