きっかけ
「達人が教えるWebパフォーマンスチューニング」を読んでSQLのパフォーマンスチューニングを実践してみました。
対象の処理（仕様）
商品CSVアップロード機能
・商品を1000件登録する。
・商品登録時にそれぞれ「カテゴリ」4つ「タグ」3つ「商品画像」2つを同時に登録する。
・商品ごとに設定する「商品コード」はユニークで他商品と重複しない。
処理時間の計測
まず基準になる改善前の実行時間を計測します。
スロークエリログをそのまま確認することもできますが
pt-query-digestというライブラリを使うことでよりログが見やすくなります。
その前に、MySQLにスロークエリログを出力するよう設定をします。
// my.cnf [mysqld] slow_query_log = 1 （スロークエリログ出力の有無） slow_query_log_file = /var/log/mysql/mysql-slow.log（ログの出力先） long_query_time = 0（指定した処理時間以上かかったクエリのみ出力する）
long_query_time=0にすることで全てのクエリのログを出力するようにしています。
サーバ（コンテナ）を再起動させて設定を反映してください。
Percona Toolkitの導入
apt install percona-toolkit
インストール後、
pt-query-digest [スロークエリログのパス]
でスロークエリログの解析結果が表示されますが
出力設定を行ってから全てのクエリログが記録されているため、計測したいクエリが見つけにくい場合があります。
なので私は計測したい処理の直前にログファイルを一度削除し
対象の処理のみを実行した後、クエリログをpt-query-digestで分析しています。
スロークエリログの解析
上の画像は実際に出力された分析結果ですが
・Response time：実行時間の合計と全体に占める割合
・Calls：実行された回数
・R/Call：1回あたりの実行時間
・V/M：標準偏差
・Item：クエリのサマリー
を表しています。
またクエリごとに
・読み込んだレコード数（Rows examine）
・取得したレコード数（Rows sent）
がわかるため、インデックスを使用する指標にもなります。
※SQLのみを速くできても代わりにプログラム側が遅くなってしまっては意味がないため、対象の処理の開始と終了時のマイクロ時刻の差を取得して処理全体の時間を計測しています。
クエリの改善
上記の結果を参考にして以下の改善を行いました。
・「カテゴリ」「タグ」「画像」のINSERT処理をまとめて行う。
・インデックスを貼る
「カテゴリ」「タグ」「画像」のINSERT処理をまとめて行う
分析結果の1位のクエリは商品カテゴリテーブルへのINSERT処理でした。
このクエリに着目すると、商品1つの登録に4回のINSERTクエリが発行されているため
1回のBULK INSERTにすることで全体4000回の呼び出しを1000回に削減しました。
同様に「タグ」「画像」についても呼び出し回数を1000件に削減しました。
インデックスを貼る
上記の分析結果後
・商品が持つ「商品コード」項目は重複してはいけない
という仕様が追加されたため、重複チェックのためのクエリを追加しましたが
取得したレコードに対して読み込んだレコード数が多すぎたため
インデックスを貼ることで時間を削減しました。
プログラムの改善
全体の処理時間を短くするため、プログラム側の改善も行いました。
・ORMを使用せず、クエリビルダもしくはRawSQLを使用する。
・ORMのキャッシュ機能をプログラム側で代替する。
ORMを使用せず、クエリビルダもしくはRawSQLを使用する
確認できていませんが、世間的にORMはRawSQLよりも比較的遅いという話を聞きますし
自分でどのようなSQLを発行しているのか把握したいので、ORMを使用せずRawSQLでクエリを作成しました。
ORMのキャッシュ機能をプログラム側で代替する
今回改善対象のCMSで使われていたORMは過去のクエリを元に
DBにアクセスせずキャッシュから結果を返す処理を自動で行なっていたようで
この機能をプログラム側に配列を持たせて再現することでクエリの回数を減らしました。
まとめ
pt-query-digestを使用することで各クエリの性能を数値で取得できるようになったため
どのクエリを改善すべきかがわかり、とてもチューニングに有用なツールでした。
インデックスによるチューニングの実践は内容が深くなると思うので
別の記事でできたらと思います。
