目次
とある日
MySQLのslow queryを分析するのにmysqldumpslowがあるのをしったので調べました。
mysqldumpslow — スロークエリーログファイルの要約
MySQL スロークエリーログには、実行に時間がかかるクエリーに関する情報が含まれています (セクション5.4.5「スロークエリーログ」 を参照)。mysqldumpslow は、MySQL スロークエリーログファイルを解析し、その内容を要約します。
通常、mysqldumpslow は数字の特定の値および文字列データ値以外が同様のクエリーをグループ化します。 サマリーの出力を表示する際、これらの値を
Nおよび'S'に「抽象化」します。 値の抽象化動作を変更するには、-aおよび-nオプションを使用します。
スロークエリで吐き出したログを解析してくれるコマンド。
検証
slow queryの設定は割愛します。
root@6438500bc2d7:/# mysql -u root -p Enter password: Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 12 Server version: 8.0.24 MySQL Community Server - GPL Copyright (c) 2000, 2021, Oracle and/or its affiliates. Oracle is a registered trademark of Oracle Corporation and/or its affiliates. Other names may be trademarks of their respective owners. Type 'help;' or '\h' for help. Type '\c' to clear the current input statement. mysql> show variables like 'slow_query%'; +---------------------+---------------+ | Variable_name | Value | +---------------------+---------------+ | slow_query_log | ON | | slow_query_log_file | /tmp/slow.log | +---------------------+---------------+ 2 rows in set (0.03 sec)
tmp/slow.log
検証用に時間がかかりそうなクエリを発行しておきました。
使ったテーブルは公式サンプルのWorld_xのcityテーブルです。
適当にテーブル羅列させるだけでcross joinしてます。
sleep関数だと出ないと思ったので。（記録されてました）
root@6438500bc2d7:/# tail -n 20 /tmp/slow.log # User@Host: root[root] @ localhost [] Id: 9 # Query_time: 63.453060 Lock_time: 0.000195 Rows_sent: 3082424 Rows_examined: 36988 use world_x; SET timestamp=1639604923; select * from hello_worlds,hello_worlds as c2; # Time: 2021-12-15T21:50:13.393269Z # User@Host: root[root] @ localhost [] Id: 9 # Query_time: 14.230428 Lock_time: 0.018598 Rows_sent: 16638241 Rows_examined: 8158 SET timestamp=1639604999; select * from city , city as c2; # Time: 2021-12-15T22:06:54.966014Z # User@Host: root[root] @ localhost [] Id: 9 # Query_time: 8.817550 Lock_time: 0.000109 Rows_sent: 9908271 Rows_examined: 6509 SET timestamp=1639606006; select * from city , city as c2 limit 30000000; # Time: 2021-12-15T22:10:53.589360Z # User@Host: root[root] @ localhost [] Id: 9 # Query_time: 2.614147 Lock_time: 0.000101 Rows_sent: 3000000 Rows_examined: 4815 SET timestamp=1639606250; select * from city , city as c2 limit 3000000;
mysqldumpslow実行
何もつけずに実行すると以下のようになります。
root@6438500bc2d7:/# mysqldumpslow /tmp/slow.log Reading mysql slow query log from /tmp/slow.log Count: 1 Time=63.45s (63s) Lock=0.00s (0s) Rows=3082424.0 (3082424), root[root]@localhost select * from hello_worlds,hello_worlds as c2 Count: 1 Time=14.21s (14s) Lock=0.02s (0s) Rows=16638241.0 (16638241), root[root]@localhost select * from city , city as c2 Count: 2 Time=5.72s (11s) Lock=0.00s (0s) Rows=6454135.5 (12908271), root[root]@localhost select * from city , city as c2 limit N Count: 1 Time=3.01s (3s) Lock=0.00s (0s) Rows=1.0 (1), root[root]@localhost select sleep(N)
オプション
| オプション名 | 説明 |
|---|---|
| -a | すべての数字を N に、文字列を 'S' に抽象化しません |
| -n | 少なくとも指定された桁数の数字を抽象化 |
| --debug | デバッグ情報を書き込み |
| -g | パターンに一致するステートメントのみを考慮 |
| --help | ヘルプメッセージを表示して終了 |
| -h | ログファイル名内のサーバーのホスト名 |
| -i | サーバーインスタンスの名前 |
| -l | 合計時間からロック時間を減算しない |
| -r | ソート順序を逆転 |
| -s | 出力のソート方法 |
| -t | 最初から指定された数だけのクエリーのみ表示 |
| --verbose | 冗長モード |
使いそうなやつだけ紹介します。
-a
すべての数値をに抽象化し
N、文字列をに抽象化しないでください'S'。
つけない場合と比べて実数値が割り当てられてます。
root@6438500bc2d7:/# mysqldumpslow -a /tmp/slow.log Reading mysql slow query log from /tmp/slow.log Count: 1 Time=63.45s (63s) Lock=0.00s (0s) Rows=3082424.0 (3082424), root[root]@localhost select * from hello_worlds,hello_worlds as c2 Count: 1 Time=14.21s (14s) Lock=0.02s (0s) Rows=16638241.0 (16638241), root[root]@localhost select * from city , city as c2 Count: 1 Time=8.82s (8s) Lock=0.00s (0s) Rows=9908271.0 (9908271), root[root]@localhost select * from city , city as c2 limit 30000000 Count: 1 Time=3.01s (3s) Lock=0.00s (0s) Rows=1.0 (1), root[root]@localhost select sleep(3) Count: 1 Time=2.61s (2s) Lock=0.00s (0s) Rows=3000000.0 (3000000), root[root]@localhost select * from city , city as c2 limit 3000000
select * from city , city as c2 limit 30000000の30000000がそうです。
-s
出力を並べ替える方法。の値は
sort_type、次のリストから選択する必要があります。
root@6438500bc2d7:/# mysqldumpslow -s c /tmp/slow.log Reading mysql slow query log from /tmp/slow.log Count: 2 Time=5.72s (11s) Lock=0.00s (0s) Rows=6454135.5 (12908271), root[root]@localhost select * from city , city as c2 limit N Count: 1 Time=14.21s (14s) Lock=0.02s (0s) Rows=16638241.0 (16638241), root[root]@localhost select * from city , city as c2 Count: 1 Time=3.01s (3s) Lock=0.00s (0s) Rows=1.0 (1), root[root]@localhost select sleep(N) Count: 1 Time=63.45s (63s) Lock=0.00s (0s) Rows=3082424.0 (3082424), root[root]@localhost select * from hello_worlds,hello_worlds as c2 root@6438500bc2d7:/# mysqldumpslow -s t /tmp/slow.log Reading mysql slow query log from /tmp/slow.log Count: 1 Time=63.45s (63s) Lock=0.00s (0s) Rows=3082424.0 (3082424), root[root]@localhost select * from hello_worlds,hello_worlds as c2 Count: 1 Time=14.21s (14s) Lock=0.02s (0s) Rows=16638241.0 (16638241), root[root]@localhost select * from city , city as c2 Count: 2 Time=5.72s (11s) Lock=0.00s (0s) Rows=6454135.5 (12908271), root[root]@localhost select * from city , city as c2 limit N Count: 1 Time=3.01s (3s) Lock=0.00s (0s) Rows=1.0 (1), root[root]@localhost select sleep(N)
それぞれの項目の一文字目を選択すればいい感じですね。
-s *sort_type*出力を並べ替える方法。の値は
sort_type、次のリストから選択する必要があります。 -t、at：クエリ時間または平均クエリ時間で並べ替える -l、al：ロック時間または平均ロック時間で並べ替え -r、ar：送信された行または送信された平均行で並べ替える -c：カウントで並べ替えデフォルトでは、mysqldumpslowは平均クエリ時間（と同等
-s at）でソートします。
Time=5.72s (11s)
（）の中が平均時間なのかな？
-t
N出力に 最初のクエリのみを表示します。
tailとかで制限してたけどそもそもオプションにあった。
root@6438500bc2d7:/# mysqldumpslow -s t -t 3 /tmp/slow.log Reading mysql slow query log from /tmp/slow.log Count: 1 Time=63.45s (63s) Lock=0.00s (0s) Rows=3082424.0 (3082424), root[root]@localhost select * from hello_worlds,hello_worlds as c2 Count: 1 Time=14.21s (14s) Lock=0.02s (0s) Rows=16638241.0 (16638241), root[root]@localhost select * from city , city as c2 Count: 2 Time=5.72s (11s) Lock=0.00s (0s) Rows=6454135.5 (12908271), root[root]@localhost select * from city , city as c2 limit N
〆
初めて知りましたが便利ですね。
他にもMySQLで知らないが便利なコマンドとかありそう。
