Slowquerylogを取ってみることにしてみた

Slowquerylogというのは

long_query_time 秒より実行に時間がかかる SQL ステートメントすべてが入ります
by mysql公式ページ

というもので、ボトルネックを探したりするものだ、と思う。多分。

てことでデフォルトではOFFになってるみたいなので、設定からやってみよう。
まずはMysqlのバージョンから、ちぇけちぇけー。

$ mysql -V
mysql  Ver 14.14 Distrib 5.1.69, for redhat-linux-gnu (x86_64) using readline 5.1

mysql> SELECT version();
+------------+
| version()  |
+------------+
| 5.1.69-log |
+------------+
1 row in set (0.00 sec)

5.1だったわ、5.5だと思ってたw
5.1系で利用する場合でググるのさ。

# vi /etc/my.cnf

slow_query_log = 1
log_output = FILE
slow_query_log_file=/var/lib/mysql/slow.log
long_query_time = 1
log_queries_not_using_indexes = 1

上から箇条書きすると
ログを取るよ
出力を対象はFILE
ログファイルを置くところは/var/lib/mysql/slow.log
この秒数以上かかったやつを記録する
インデックスを使用しないやつを記録する

てな感じ。
mysqldを再起動して設定完了。

なのだが。。。

ところがどっこい。

# mysqldumpslow -s t /var/lib/mysql/slow.log

Reading mysql slow query log from /var/lib/mysql/slow.log
mysql> SHOW VARIABLES LIKE 'slow%';
+---------------------+---------------------------------+
| Variable_name       | Value                           |
+---------------------+---------------------------------+
| slow_launch_time    | 2                               |
| slow_query_log      | OFF                             |
| slow_query_log_file | /var/run/mysqld/mysqld-slow.log |
+---------------------+---------------------------------+
3 rows in set (0.00 sec)

mysql> SHOW VARIABLES LIKE 'long%';
+-----------------+-----------+
| Variable_name   | Value     |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)

ログファイルが生成されてないし、設定の反映すらされていない、これが現実。

よく分からないので別の方法でもやってみた。
ログインしてSET GLOBALを使う。

mysql> SET GLOBAL slow_query_log = 1;
Query OK, 0 rows affected (0.00 sec)

SET GLOBAL long_query_time = 1;
Query OK, 0 rows affected (0.00 sec)

いったんログインしなおして確認してみたら

mysql> SHOW VARIABLES LIKE 'slow%';
+---------------------+-------------------------+
| Variable_name       | Value                   |
+---------------------+-------------------------+
| slow_launch_time    | 2                       |
| slow_query_log      | ON                      |
| slow_query_log_file | /var/lib/mysql/slow.log |
+---------------------+-------------------------+
3 rows in set (0.00 sec)

mysql> SHOW VARIABLES LIKE 'long%';
+-----------------+----------+
| Variable_name   | Value    |
+-----------------+----------+
| long_query_time | 1.000000 |
+-----------------+----------+
1 row in set (0.00 sec)

今度は上手くいったみたい、なんじゃらほいほい。
何回かサイトにアクセスしてみてログを出して、mysqldumpslowをやってみた。

# mysqldumpslow -s t /var/lib/mysql/slow.log

Reading mysql slow query log from /var/lib/mysql/slow.log
Count: 5  Time=0.00s (0s)  Lock=0.00s (0s)  Rows=7.0 (35), ******[******]@********
  SELECT *, ((N.N * (MATCH (`title`) AGAINST ( "S" ))) + (N.N * (MATCH (`content`) AGAINST ( "S"

よしよし。
言葉の意味はよく分からんけど、こんな感じでうまく出力された。
mysqldumpslowじゃなくてcatでLogを見たらえげつない量だったw

Logを取れるようにはなったけど、これだけだといつ見るの?暇な時でしょってことになっちゃう。ので
Logwatchと同じく深夜にCRONを回すことにする。

スクリプトははったりエンジニアの備忘録さんのを若干変更して利用させていただいてます。
テストしてみたけど、うまくmysqldumpでまとまったログの内容のメールが飛んできた。

あとから確認してみたけど、一通りの設定が完了した後だと、/etc/my.cnfに記述した内容もmysqldの再起動でうまく反映されるようになったのだ、よく分からん。分からなさ過ぎて糸口も見つからない。

その辺は謎のままだ。

ログの内容もまだ分からんので、まだまだ覚えることは多いのであった。

相変わらず毎日wp-loginへの攻撃は続いている。
ロリポのニュースも見た。
ぷち管理者としては注意喚起したいところだ。

 

参考サイト

遊介の徒然!!
mysql5.5 で slow query log スロークエリーログ を採る

よんちゅBLOG
MySQL5.0/5.1でスロークエリログを記録

はったりエンジニアの備忘録
MySQLのスロークエリをメールで受け取る

 

Similar Posts:


Leave a Reply

Your email address will not be published. Required fields are marked *