これだけ見れば大丈夫！ーMySQLパフォーマンス監視のツボ（クエリ編）

こんにちは、インフラ担当新人の nob です。
サーバー監視ツールで MySQL を監視しているのにデータが多すぎて活用していない。という方はいませんか？その豊富なデータをパフォーマンス・チューニングに活用しない手はありません。今回はサーバー監視ツールのグラフを読み解いた実戦経験を元に、「これだけ見れば大丈夫」というツボをまとめてみました。
これだけ見れば大丈夫！　クエリ編　３つのつぼと５つのグラフ

• （その１）監視ツールが何を見ているのか知る
• （その２）監視のキモ、グラフ３点セット (Questions, Lock Waits と Transaction Handler)
• （その３）グラフでチェックする SQL チューニング ( Select Type と Handler)

シンプルでお勧め、サーバー監視グラフ化ツール Cacti

運用しているサーバーには、単純なネットワークの死活監視から始まってシステム全体の性能を監視するまで、様々なサーバー監視のインフラが必要となります。有名どころでは Nagios, Zabbix, Hinemos などがありますが、今回使っているのは Cacti　http://www.cacti.net/ というサーバーパフォーマンスグラフ化ツールです。監視項目のグラフ表示の他、しきい値を超えるとメール通知する基本機能も備えています。またテンプレートを自作し好みの項目をグラフにすることも出来ますし、自作テンプレートはネットからも入手出来ます。機能がシンプルですので、インフラ・エンジニアの別の仕事（運用の自動化とか）に浮気することなく、MySQL のパフォーマンスに集中出来るのもよい所です。
私が MySQL のための Cacti テンプレートとして使ったのは better-cacti-templates です。導入については　ググれカス http://ggrks.org/の記事 cactiの導入とApacheとかMySQLとかのtemplateの導入 などを参考にしてください。

（その１）監視ツールが何を見ているのか知る

グラフのデータを活用するには、データの意味、つまりデータをどうやって採集しているのか 知る事が重要です。better-cacti-templates が採集している MySQL データは、SHOW STATUS コマンドで表示される MySQL の統計情報の項目と、SHOW ENGINE INNODB STATUS コマンドで表示される文章を元にしたオリジナルな項目、の２本だてで構成されています。Cacti のグラフの意味を知るのは

1. SHOW STATUS の項目に同じ名前の項目があるか、あれば MySQL リファレンスマニュアルで意味を調べる
2. SHOW STATUS に無い場合は、それはテンプレートの独自項目なので、テンプレートのスクリプトを解読する

という手順になります。better-cacti-templates の場合はテンプレートのソースの scripts/ss_get_mysql_stats.php を見ると独自項目の内容の詳細がわかります。今回の記事で取り上げなかった Cacti のデータ項目が気になった方は、ぜひソースの解読に挑戦してみて下さい。

（その２）監視のキモ、グラフ３点セット (Questions, Lock Waits と Transaction Handler)

まず最初はパフォーマンス監視のキモであるグラフの３点セットです。チューニングというより監視が目的の場合の重要なグラフがこの３つです。まずは Questions から見ていきます。

SQL の種類のグラフ MySQL Command Counters

このグラフはどういう種類の SQL 文が実行されたかまとめたものです。単位はインターバル（デフォルト５分）毎の回数ですが  m はミリ、つまり1/1000 回です。例えば 100 m  というのはその５分間で発生した回数が 0.1 回ということで、50分で１回発生した、という事を示しています。

Com は Command の略で Com Select / Delete / Insert / Update / Replace はその名前のとおりの SQL の実行回数です。 Com xxx Multi と付いているのは複数テーブルを一括して Update するMySQL 独特の構文です。ここで注目すべきは Questions です。MySQLリファレンスマニュアルには簡素に「MySQL への問い合わせ回数」と記述されています。なんでもカウントしますが、ここだけに計上されるのは SET などの補助的なコマンドと、エラー応答です。SET が急に増えることはありませんので、上のグラフの点線部のように増加した場合は、何かエラーが増加しています。
エラー内容の調査にはアプリケーション側での調査が必要ですが、 とりあえず Questions だけが増加して来たら、何かの悪い兆候と思ってください。

ロック待ち時間を見るのに最適 InnoDB Current Lock Waits

監視３点セットの２点目はこのグラフです。データの項目は Innodb Lock Wait Secs ですが、この値は SHOW ENGINE INNODB STATUS で表示されるトランザクション情報のうち、”TRX HAS BEEN WAITING n SEC FOR THIS LOCK TO BE GRANTED” の n をシステムのトランザクション全部で合計したものです。ここでいうロックは行ロックやテーブルロックの区別はありませんが、パフォーマンスからみればロック待ちの時間はゼロが良く、この値が増加しているのも悪い兆候です。

上のグラフでは、ちょうど Questions と同じ時間帯で Lock Waits も上昇しています。表示中の  k はキロ、1000 です。２つ合わせるとエラーが増加してロックの待ち時間も増えている、となります。MySQL だと真っ先に疑われるのはデッドロックですが、この例では INNODB STATUS を見ても記録されていませんでした。さてどうしたものか？そこで生きてくるのが次の３点目のグラフです。

トランザクション状況を一瞥する MySQL Transaction Handler

このグラフは項目の名前どおりにコミット数とロールバック数をグラフにしたものです。グラフ点線部にそれまで無かったロールバックが記録されていたことがわかります。

デッドロックではなくても何かのエラーでトランザクションが アボートされるとロールバックが発生します。「元のクエリのロック時間」＋「更新を巻き戻す時間」＋「再実行時間」、、、、という具合に無駄に処理が増え、ロックの競合確率やロック待ちも増加し、レスポンスが悪くなります。
というように以上３点のグラフを見ればクエリで異常が発生していないかどうか監視できます。

（その３）グラフでチェックする SQL チューニング ( Select Type と Handler)

MySQL ではスローログを活用してプロファイリングするのが有効です。ところがデータ量が少ないシステム開発中にはクエリは高速に動いてしまい、スローログには記録されません。そこでさらに log_queries_not_using_indexes をセットして、インデックスを使っていないクエリ、インデックスを使っていても全件検索しているクエリを全て記録し、そこをチューニングします。ところが、小さいテーブルを SELECT * FROM Table しているものとか、全件コピーするために INSERT INTO .. SELECT … をやっているものとか、わかってて全件検索しているクエリも記録されるので件数がかなり多く負荷になります。そのため log_queries_not_using_indexes は本番稼働時には外されることも多いです。
さて、開発も最終段階でスローログの設定も本番と同じにしたとします。データが少ない今はスローログには何もひっかかりませんが、もしインデックス張り忘れなどのチューニング忘れのクエリが残っていれば、データの増加後に速度が低下して初めて気がつくことになります。クエリ全部に EXPLAIN を実行して検査するというのも現実的ではありません。問題が発生してからではなく、発生する前に未然に対応することは出来ないでしょうか？　そんなときに活躍するのがサーバー監視のグラフです。

SELECT の使い方を知る My SQL Select Types

クエリのチューニングはほぼイコール SELECT のタイプ、ということに尽きます。個別のクエリに対して EXPLAIN をすることでどのような実行計画を使っているのか知る事が出来ますが、このグラフを見ることでシステム単位でどういうタイプのものが実行されているのか、その全体像を知ることが出来ます。

Select Scan はテーブル（またはインデックスでも）の先頭行から全件検索（スキャン）をした回数です。Select Range は WHERE などの指定によって範囲が限定された探索を行った回数です。SQL のチューニングとして、「 SELECT にはインデックスを使用して探索行数や行ロックの範囲を少なくしよう」というのが一般的ですが、意図的に全件取り出す必要性もありますから、スキャンはゼロにはなりません。それでも Select Range  >>>  Select Scan というのがが望ましい状態です。上のグラフ例では反対に Select Scan が多くなっています。インデックスを使う余地のあるクエリが相当数あることがわかります。
もう一つのチューニングとして「JOIN はインデックスで行う」というものがあります。これがちゃんと守られているかどうかはインデックスのないカラムで JOIN すると記録される Select Full Join と範囲指定の効果はあるがやはりインデックスは使わず JOIN した時の Select Full Range Join （青の点線部）をみるとわかります。上のグラフでは 139 ミリ回という小さい値ですが、ここはゼロであることを目指しているので、見えた瞬間お！誰だ！という具合に気がづくことが出来ます。

クエリの I/O 動作を知ることが出来るグラフ  MySQL Handlers

Handler というのは MySQL のストレージエンジンのインターフェースで、その種類を見ることで InnoDB がファイル I/O 、ディスク I/O に近いローレベルでどういう仕事をしているのか見ることが出来ます。

Write, Update, Delete は名前のとおりの動作なので割愛して、ポイントとなるのは以下の Read 系の操作です。

• Handler Read First テーブルやインデックスの全件検索（スキャン）の際には、まず最初に先頭レコードの取得を行います。その回数が Read First です。
• Handler Read Key インデックスを使ってさらに範囲指定の効果が効いている場合、キー値に基づいてジャンプして行を読み取る操作を行います。その回数です。
• Handler Read Next キー値に基づいて行を特定した後、後続の行を読んだ回数です。
• Handler Read Prev 内容としては Next  と同様で、キー値でポイントを決めた後、その前の行を取得する操作です。
• Handler Read Rnd InnoDB でプライマリキーの値を指定して1行データを読み込む場合、ディスクへのアクセス方法がシーケンシャルアクセスではなくランダムアクセスということで、MySQL の世界では歴史的に Random Read という用語が使われています。この Handler Read Rnd はプライマリキーを指定してピンポイントに１行読み込んだ回数になります。
• Handler Read Rnd Next Read Rnd によってポイントを決めた後、引き続き連続して行を読み取った回数になります。単純なスキャン操作をしていることになるのであまり嬉しくない回数です。

Handlerr Read First は全件検索あたり１回しか計上されないので読み取り回数と比べると小さくてグラフでは見えませんが、数字を見ることで全件検索の回数の傾向がつかめます。同様に Handler Read Rnd と Handler Read Rnd Next を見ることで、全件検索によって読み込んだ行数がわかります。
上の２つのグラフを総合すると「全件検索する Select の割合が多いが読み込んだ行数の割合は少なかった」ということがわかります。このことから、チューニングされていないクエリがかなりあるものの、この段階ではあまり影響が出ておらず、今後データ量が増加すると影響が出るかもしれない、ということまで知ることが出来ます。

最後に

以上３つのツボ５つのグラフを見るだけで、実行されている SQL の挙動をつかみパフォーマンスチューニングへと活かすことが出来ますので、みなさんも是非ご活用ください！
次回後編は　これだけ見れば大丈夫！ーMySQLパフォーマンス監視のツボ（システム編） を予定しています。ご期待ください！
ーーーー
インフィニットループではプログラミングやインフラが好き、というエンジニアを募集しています。詳しくは募集ページ　https://www.infiniteloop.co.jp/recruitment/ まで