皆さんはスロークエリログを活用していますでしょうか。今回はこの連載でも第7回 スロークエリーログを使って遅いクエリを収集するや第113回 anemoeaterを使ってスローログを可視化してみるで紹介させていただいた、スロークエリログ関連のお話となります。
今回は、mysqldumpslowという、スロークエリログをもっと便利にするコマンドラインツールについて紹介していきます。mysqldumpslowという字面を見ると、mysqldumpでじっくりと時間をかけてダンプファイルを取ってきてくれると思い浮かべるかもしれませんが、全くの別物なので注意しましょう。
検証環境
今回の検証環境は、第125回 phpMyAdminでDockerで建てたMySQLにアクセスするで記載したdocker-composeを利用して作成します。手元で簡単に試せるように、githubの筆者のレポジトリにサンプルコードとして置いてあるので、気軽に試したい方はgit cloneして試してみてください。試すにはdockerとdocker-composeが必要です。
git cloneしてきたディレクトリに入り、以下のコマンドを実行して見ましょう。
mysqlクライアントが使用できる環境が簡単に立ち上がると思います。
今回はスロークエリログを有効にしたいので、第7回 スロークエリーログを使って遅いクエリを収集するで使用した以下のコマンドを実行して、スロークエリログが出力されることを確認しましょう。
スロークエリログの出力先はSHOWコマンドで確認できます。
実際に出力がされているか確認してみましょう。今回は、実行したクエリがスロークエリログとして出力されるはずです。
それでは、スロークエリログを確認してみましょう。
先ほどのクエリが出力されていることがわかりました。
mysqlslowdumpを使ってみる
mysqlslowdumpは、スロークエリログを解析してサマリーとして出力するコマンドラインツールです。第113回で紹介したanemoeaterと同様に、MySQLにログインする必要はなく、ログファイルだけを使用して解析をすることができます。
また、このツールを使うと、解析する過程で文字列や数字に関して自動で置き換えが行われるので、スロークエリログに個人情報や重要情報などが出力されてしまった場合にSQLを抽象化して出力でき、便利です。
使い方は簡単で、mysqldumpslowコマンドに引数としてログファイルを渡すだけで実行ができます。まずはオプションを付けずに実行してみましょう。
このような結果になりました。1行ずつ簡単に説明していくと、1行目はスロークエリログはどこのファイルから読んでいるかを書いています。2行目はこのクエリが現れた回数、クエリにかかった時間、ロックしていた時間、読み込んだ行数、実行したユーザとホストが書かれています。3行目には匿名化されたクエリが書かれています。
もう少し件数を増やしてみましょう。mysqlクライアントで以下のクエリを実行しましょう。
上記を実行した後で、もう一度実行してみます。
文字はSへ、数字はNに置換されていることがわかりました。ちなみに文字列や数字が複数個ある場合でも, 文字列は全てS, 数字は全てNで置換されます。
逆に匿名化されたくない場合は、-a
オプションを利用することで生のデータを見ることができます。どうしてこのオプションが必要なのか? というのを体感してもらうために、以下のクエリを実行してみましょう。
この場合に-a
オプションを付けずに実行した場合の結果で見てもらいたい部分だけ抽出すると、以下のようになっていることがわかります。Rowsの部分を見てもらうとわぁるのですが、2000行と1行で1回あたり、平均1000.5行読まれていることになってしまっています。
このようにデータの偏りが大きい場合などには、サマリーとして出力してしまうとうまく行かない場合があります。この時に-a
オプションを利用すると、以下のようにクエリに利用したデータも確認することができるようになります。
ただし、スロークエリログには個人情報や重要情報などが含まれている可能性も高いため、このオプションを利用するときには取り扱いに十分に注意して行ってください。
その他の便利なオプションとしては、-s
オプションと-t
オプションがあります。-s
オプションはソートオプションで多い順に出力を並べ替えをすることができます。詳細は以下の表にまとめておきます。
オプションの引数 |
並べ替えができる項目 |
t, at |
Time |
l, al |
Lock |
r, ar |
Rows |
c |
Count |
使い方は以下のようになります。以下では引数にrを渡しているので、Rowsの順に並んでいることがわかると思います。
続いて-t
オプションですが、このオプションの引数に指定した個数だけ結果を返してくれるようになります。以下では1を指定しているので、結果が1件になりました。
あまりに件数が多い場合などに、-s
オプションと組み合わせて見れる件数だけに絞るという使い方が考えられます。スロークエリログに引っかかっている件数が多いクエリであれば、少しでも最適化すればサーバの計算資源がより効率的に使えるでしょうし、回数が少なくとも時間がかかっているクエリを最適化していくなど、使い方はいろいろとあると思います。
まとめ
今回はmysqldumpslowというコマンドについて紹介しました。このコマンドはログファイルがあれば非常に簡単に使えるので、たとえば1日に1回cronでmysqldumpslowを動かして、結果をwebhook等を利用してslack等のツールに通知として流し、常日頃からスロークエリログを確認する等の使い方ができます。
スロークエリログを出してはいるものの活用があまりできていない場合は、このツールを使ってスロークエリログを定期的に確認する仕組みを作ってみるところから始めてはいかがでしょうか。