ここでは、TablePlusのSHOW FULL PROCESSLIST、EXPLAIN ANALYZE、アプリケーションのSQLログを使って、体感速度への影響が大きい箇所から改善した進め方をまとめます！
SQLログの例は、普段利用しているLaravelで説明します！
今回の改善では、次の順番で一つずつ進めました。
- 画面全体の遅さを計測する
- 発行されているSQLを特定する
- SQLの実行計画と実測値を確認する
- 原因と優先度を整理する
- 修正する
- 再計測して効果を確認する
1. まず画面全体の遅さを計測する
最初に、どのリクエストが画面表示を待たせているかを確認します。
macOSのChromeではcommand + option + Iでデベロッパーツールを開き、ネットワークタブで画面を再読み込みします。必要に応じてキャッシュを無効化すると、ブラウザキャッシュの影響を減らして確認できます。
一覧画面そのものの表示が遅い場合は、一覧ページのHTMLを返すリクエストを見ます。ネットワークタブでは、通常このリクエストは種類がdocumentと表示されます。ここでいう「ドキュメント」は、ブラウザが最初に取得するHTMLドキュメント、つまり画面本体のリクエストを指します。
DurationやWaterfallを見ると、画面本体の応答に時間がかかっているのか、画面表示後のAPI呼び出しや画像・JavaScriptの読み込みに時間がかかっているのかを切り分けられます。
2. 発行されているSQLを特定する
画面本体のリクエストが遅いと分かったら、そのリクエスト中にどのSQLが実行されているかを確認します。
SHOW FULL PROCESSLISTで実行中のSQLを見る
TablePlusで対象DBに接続し、クエリエディタに次のSQLを準備します。
SHOW FULL PROCESSLIST;
次の手順で、画面を開いた瞬間に動いているSQLを捕捉します。
- ブラウザで対象画面を開き、デベロッパーツールのネットワークタブを表示する
- ネットワークのログを消去し、必要に応じてキャッシュを無効化をオンにする
- TablePlusで
SHOW FULL PROCESSLISTを実行できる状態にしておく - ブラウザでスーパーリロード（
command + shift + R）、またはリロードボタンを2本指クリック→キャッシュの消去とハード再読み込みを押す - 読み込み中の間に、TablePlusで
SHOW FULL PROCESSLISTを数回実行する
SHOW FULL PROCESSLISTで見えるのは、その瞬間に実行中または待機中のSQLだけです。SQLが短時間で終わる場合や、実行タイミングが重ならない場合は捕捉できません。また、DBユーザの権限によっては自分以外の接続が見えないことがあります。
その場合は、以下のようにアプリケーション側でSQLログを出すほうが確実です。
アプリケーションのSQLログでリクエスト中のSQLを記録する
今回の調査対象はLaravelのアプリケーションだったため、ローカル環境でDB::listen()を一時的に設定し、画面を開いたときに実行されたSQLと実行時間をログへ出しました。
他のフレームワークでも、クエリログやDBの計測機能を使って同じように確認できます。重要なのは、画面を開いた1回のリクエストで、どのSQLが何ミリ秒かかったかを記録することです。
use Illuminate\Database\Events\QueryExecuted;
use Illuminate\Support\Facades\DB;
use Illuminate\Support\Facades\Log;
// AppServiceProviderのboot()など、調査用の場所に一時的に設定する
if (app()->isLocal()) {
DB::listen(function (QueryExecuted $query) {
Log::debug('SQL executed', [
'sql' => $query->sql,
'bindings' => $query->bindings,
'time_ms' => $query->time,
]);
});
}
調査が終わったら、この設定は外します。
3. EXPLAIN ANALYZEで遅い理由を確認する
SHOW FULL PROCESSLISTやSQLログで候補を見つけたら、EXPLAIN ANALYZEで実際の実行内容を確認します。
以下は、ユーザ一覧を状態順・作成日時順に取得するSQLを抽象化した例です。
EXPLAIN ANALYZE
SELECT
u.id,
u.display_name,
u.status,
u.created_at
FROM users AS u
WHERE u.store_id = 123
AND u.deleted_at IS NULL
ORDER BY u.status ASC, u.created_at DESC
LIMIT 50;
出力には、各処理で実際にかかった時間、読み取った行数、繰り返し回数が表示されます。たとえば、次のような出力があったとします。
-> Limit: 50 row(s) (actual time=1830..1831 rows=50 loops=1)
-> Sort: u.status, u.created_at DESC
(actual time=1830..1831 rows=50 loops=1)
-> Index lookup on u using idx_users_store_id (store_id=123)
(actual time=0.12..1210 rows=1600000 loops=1)
この例では、約160万件を読み取ったあとにSortが実行され、結果として先頭の50件を返すまでに約1.8秒かかっています。
actual time=a..bは、その処理で最初の行を返すまでの時間と、最後の行を返すまでの時間の目安です。時間の大きいノードを起点に、想定より多くの行を読んでいないか、ソートや結合に時間を使っていないかを確認します。
SQLだけで完結させず、SQLが発行される順序と呼び出し元のコードも確認します。たとえば、一覧には50件しか表示しないのに、次の処理が対象ユーザ全件を読んでいることがありました。
- ページネーションの「全○件中」を表示するための件数取得
- 絞り込み欄に表示する、ステータス別の件数取得
このように「遅いSQL」と「遅い理由」を分けて把握すると、対策を選びやすくなります。実行計画とコードの対応を追う際は、SQLと対象メソッドをCodexに解析してもらい、読み取り件数や結合・ソートの観点で確認することも有効でした。
4. 優先度を付ける
見つけたSQLをすべて同時に直すのではなく、まずは次の観点で優先順位を付けます。
- 画面表示の完了を直接待たせているか
- 実行時間と呼び出し回数が大きいか
- 読み取り件数が不自然に多くないか
- 修正による効果を小さく検証できるか
この順番にすると、改善効果が大きい箇所から安全に進められます。
5. 修正する
優先度を付けたら、原因に合わせて修正します。代表的な選択肢は、インデックスの追加、クエリや結合順の見直し、画面表示と重い処理の分離です。
修正の効果を判断できるよう、可能であれば検証環境で小さく変更し、SQL単位と画面単位の両方で確認します。特にインデックスは書き込み時のコストや容量にも影響するため、効果を確認できたものだけを取り入れます。
6. 再計測して効果を確認する
修正後は、修正前と同じ条件で再計測します。検証ツールでは画面本体の応答時間を、EXPLAIN ANALYZEでは読み取り件数・ソート・結合にかかる時間を確認します。
SQL単体の実行時間だけでなく、一覧が表示されるまでの時間が短くなったかも確認します。期待した効果が出ていなければ、実行計画と呼び出し元のコードに戻り、次の原因を調査します。
実際の対応例
並び替え用のインデックスを追加する
ある一覧では、名前・ステータス・確認要否・チェック結果などで並び替えできるようになっていました。しかし、条件に合う多数のレコードを読み取ってから並び替える実行計画になっており、EXPLAIN ANALYZEではSortに時間がかかっていることを確認できました。
そこで、絞り込み条件と並び替えに使う列の組み合わせに対応したインデックスを、まず検証環境へ一時的に追加しました。再計測の結果、数秒かかっていたSQLが数ミリ秒で完了することを確認できたため、効果を確認したインデックスをマイグレーションとして追加する方針にしました。
インデックスは追加すればよいわけでは泣く、書き込み時のコストや容量も増えるとどこかで学習したため、効果を確認してから取り入れます。
ソートの処理順を変える
別の一覧では、以前は大量のユーザレコードを読んでから店舗情報と結合し、店舗名順に並び替えていました。この処理では、ユーザ側から読み始めることで結合後のデータ量が大きくなり、ソートの負荷が高くなっていました。
そこで、店舗側から先に店舗名順で候補を取得し、そこから対応するユーザを結合するようにクエリを調整しました。これはインデックスを追加するのではなく、SQLがどちらのテーブルから処理を始めるかを見直して改善した例です。
たとえば、変更前の実行計画では、次のような順序になっていました。
usersから対象レコードを大量に読み取る
-> storesを結合する
-> stores.nameで全体をソートする
-> 先頭の50件を返す
この形では、表示するのが50件でも、その前に大量のユーザレコードを結合・ソートする必要があります。
変更後は、店舗側から店舗名順に候補を取得し、必要なユーザだけを結合する構成にしました。
storesを店舗名順に読み取る
-> 対応するusersを結合する
-> 必要な件数に達した時点で取得を終える
その結果、結合後にソートする対象を減らせるため、一覧を返すまでの時間を短縮できました。
対応後は、EXPLAIN ANALYZEで読み取り件数とソートにかかる時間が減っていることを確認しました。
重い集計を画面表示後に取得する
一覧画面では、一覧レコードと同時に件数集計も取得していました。集計は正確な件数を返す一方で、対象件数が増えるほど画面の初期表示を待たせます。
そこで、一覧レコードを先に表示し、重い集計は画面表示後にJavaScriptから別リクエストで取得する形へ変更しました。集計値の取得中は...を表示し、取得が完了したら実際の件数に置き換えます。
これはSQLそのものを高速化するのではなく、ユーザが一覧を見始められるまでの時間を短くする改善です。画面の目的が「まず一覧を確認すること」であれば、体感速度の改善に直結します。
まとめ
パフォーマンスチューニングでは、感覚だけで修正を始めず、計測と再計測を繰り返すことが重要です。
- 画面全体の遅さを計測する
- 発行されているSQLを特定する
- SQLの実行計画と実測値を確認する
- 原因と優先度を整理する
- 修正する
- 再計測して効果を確認する
この流れで進めると、原因に対して適切な改善を選びやすくなりました。