2児のパパ系Webエンジニア
の開発日記 A Dad-of-Two Engineer's Development Diary

2児のパパ系Webエンジニア
の開発日記

A Dad-of-Two Engineer's Development Diary

EXPLAIN ANALYZEでLaravelの遅いクエリを実測！loopsの読み方とtoBase()の落とし穴

テック
EXPLAIN ANALYZEでLaravelの遅いクエリを実測！loopsの読み方とtoBase()の落とし穴

🙌 結論から

遅いクエリを調べるときは、EXPLAIN だけで終わらせず EXPLAIN ANALYZE で「実際に何ミリ秒かかったか」まで見たほうが早いです。

EXPLAIN が出すのは、オプティマイザの推定だけなんですよね。

EXPLAIN ANALYZE は MySQL 8.0.18 から使える構文で、クエリを本当に実行して、各ステップの実測時間・行数・ループ回数を出してくれます！

ただ、Laravel 側には少し落とし穴があります(・_・;)

標準の explain() では ANALYZE が付けられないので、私は toBase() を挟んでから自作のマクロで流すようにしています👍

もう当たり前感あるかもですが、loops の数字を掛け算して読むのがいちばん大事なところでした👀

💡 EXPLAINの推定だけ見て安心していた

以前の私は、遅い画面があると EXPLAIN を流して、type と key を見て終わりにしていました。

type が ALL じゃない、key にインデックス名が入っている、よし大丈夫・・・という見方です笑

でも、インデックスはちゃんと使われているのに遅い、というケースがけっこうあるんですよね(´･ω･`)

EXPLAIN の rows は「たぶんこのくらい読むだろう」という見積もりなので、統計情報がずれていると実際の件数とかなり離れます。

EXPLAIN ANALYZE の出力は、ステップごとに次の2つのカッコが並ぶツリー形式です。

  • (cost=… rows=…): オプティマイザの推定
  • (actual time=… rows=… loops=…): 実際に実行して測った値

この「推定」と「実測」が同じ行に並ぶのがマジでありがたいです！

推定の rows と実測の rows が桁で違っていたら、統計が古い可能性があります。

そういうときは ANALYZE TABLE orders; で統計情報を取り直してから、もう一度流すようにしています💪

同じクエリなのに実行計画ごと変わることもあるので、ここは本当に重要です🔥

👀 loopsを掛け忘れると犯人を見落とします

最初に読み違えたのがここでした。

actual time=0.5..210 の2つの数字は、最初の1行を返すまでの時間と全部の行を返し終わるまでの時間（ミリ秒）です。

そして、MySQL 公式ブログの解説によると、actual time と rows はループ1回あたりの平均値です。

つまり、loops が大きいステップは、表示されている時間に loops を掛けないと本当のコストが見えません。

説明用に簡略化した例ですが、注文一覧で「支払い済みの注文を新しい順に20件、ユーザー名つきで」取るクエリだと、こんな出力になります⇩

-> Limit: 20 row(s)  (actual time=1520..1520 rows=20 loops=1)
    -> Sort: orders.created_at DESC, limit input to 20 row(s) per chunk  (actual time=1520..1520 rows=20 loops=1)
        -> Nested loop inner join  (cost=… rows=5000) (actual time=0.9..1480 rows=48000 loops=1)
            -> Filter: (orders.status = 'paid')  (cost=… rows=5000) (actual time=0.5..210 rows=48000 loops=1)
                -> Table scan on orders  (actual time=0.4..180 rows=120000 loops=1)
            -> Single-row index lookup on users using PRIMARY (id=orders.user_id)  (cost=0.25 rows=1) (actual time=0.02..0.02 rows=1 loops=48000)

（数値は読み方を説明するための例です。cost の値は省略しています）

一番下の users の主キー検索は、1回あたり 0.02 ミリ秒なので一見すごく速そうです。

でも loops=48000 なので、合計すると 0.02 × 48000 = 960 ミリ秒くらいになります！

「速そうに見える1行」が、実は全体の半分以上を食べているというのが、loops を掛けて初めて分かるんですよね(;_;)

もう一つ見てほしいのが Filter の行です。

推定は rows=5000 なのに、実測は rows=48000 で、10倍近くずれています(・∀・)

この例なら、私は次の順で手を入れます。

  • ANALYZE TABLE orders; で統計を取り直す
  • (status, created_at) の複合インデックスを検討して、テーブルスキャンとソートを避ける
  • ユーザー名の JOIN は、20件に絞ったあとで取る形にできないか考える

読む順番は、一番深いところ（インデントが一番右）から上へです。

上から読むと Limit や Sort ばかり目に入って、どこが重いのか分かりにくいので、この順番は覚えておくとかなり楽です✨

🔧 私はLaravelのクエリをこうやって流しています

ここが一番真似してほしいところです！

まず知っておきたいのは、Laravel のクエリビルダーにある explain() の中身です。

フレームワークのソース（Illuminate\Database\Concerns\ExplainsQueries）を見ると、toSql() の前に 'EXPLAIN ' を足して select() しているだけでした。

explain() で見られるのは、普通の EXPLAIN（推定）までということですね。

私は AppServiceProvider の boot() に、EXPLAIN ANALYZE 用のマクロを1つ足しています⇩

use Illuminate\Database\Query\Builder;

public function boot(): void
{
    if (! $this->app->environment(['local', 'staging'])) {
        return;
    }

    Builder::macro('explainAnalyze', function (): string {
        /** @var Builder $this */
        $rows = $this->getConnection()->select(
            'EXPLAIN ANALYZE '.$this->toSql(),
            $this->getBindings()
        );

        return collect($rows)->pluck('EXPLAIN')->implode("\n");
    });
}

toSql() だけだとバインド値が ? のままなので、getBindings() も一緒に渡すのがポイントです！

使うときは php artisan tinker でこう呼んでいます。

echo Order::query()
    ->where('status', 'paid')
    ->join('users', 'users.id', '=', 'orders.user_id')
    ->select('orders.*', 'users.name')
    ->latest('orders.created_at')
    ->limit(20)
    ->toBase()
    ->explainAnalyze();

ここで toBase() を挟んでいるのがハマりどころの回避策です。

Eloquent のビルダーは、SoftDeletes の deleted_at is null のようなグローバルスコープを、get() や toBase() のタイミングでまとめて付けます。

標準の explain() や toSql() は、Eloquent 側の $passthru に入っているので、内部で toBase() を通ってスコープ付きの SQL になります。

ところが自作のマクロは $passthru に入っていないので、スコープを付ける前のクエリビルダーにそのまま転送されます。

つまり toBase() を忘れると、本番で実際に流れる SQL より条件が1つ少ない SQL を測ることになるんですよね・・・

私はこれに気づくまで、本番のスロークエリと数字が合わなくて首をかしげていました笑

もう一つ、with() で書いたイーガーロードは別のクエリとして流れるので、この結果には入りません。

イーガーロード側も気になるときは、DB::listen() やデバッグツールで SQL を拾って、1本ずつ EXPLAIN ANALYZE に通しています。

SQL をそのまま DB クライアントに貼りたいときは、ddRawSql() でバインド済みの SQL を出して、頭に EXPLAIN ANALYZE を付けて流すのも手軽です(^^)

🤔 使う前に押さえておきたいこと

推しておいてなんですが、気をつけたい点もあります。

一番大事なのは、EXPLAIN ANALYZE はクエリを本当に実行することです。

10秒かかるクエリなら、EXPLAIN ANALYZE もちゃんと10秒かかります😴

本番のプライマリで重いクエリを何度も流すのは避けて、私はステージングか、本番に近いデータを入れたローカルで測るようにしています。

途中で止めたくなったら、KILL QUERY か Ctrl+C で止められます。

公式マニュアルによると、対象は SELECT・TABLE 文と、複数テーブルの UPDATE・DELETE です。

更新系も実際に書き換わるので、試すならトランザクションの中で流してロールバックしたほうが安心です( .. )

バージョンまわりも一応押さえておきます。

  • EXPLAIN ANALYZE は MySQL 8.0.18 以降。5.7 の環境では使えません
  • MySQL 8.0 は 2026年4月でサポートが終わっていて、今のLTSは 8.4 と、2026年4月21日に出た 9.7
  • 9.7 のマニュアルでは、EXPLAIN ANALYZE の出力形式は FORMAT=TREE（標準）と FORMAT=JSON。JSON は explain_json_format_version が 2 のときだけ使えます
  • FORMAT=JSON INTO @変数 で結果を変数に入れる書き方もありますが、SELECT だけが対象です

JSON で変数に入れられると、JSON_EXTRACT で使ったインデックス名を取り出して自動チェックに回す、みたいな使い方もできそうです🤔

まだ私はそこまでやっていませんが、CI でスロークエリの劣化を見張りたい人には面白い機能かも・・・！

🔗 関連記事と使い分け

同じ「遅いクエリを直す」話を何本か書いているので、どれをいつ使うかを整理しておきます。

私の流れは、スロークエリログで見つける → EXPLAIN ANALYZE で中身を測る → インデックスやクエリを直す → もう一度測る、の順番です👍

パパ系Webエンジニア〜愛用ガジェット一覧 🛍️

この記事を書いている作業環境のガジェットを楽天ROOMにまとめています ✨ 在宅エンジニアのデスク作りの参考にどうぞ 🙌

👍 まとめ

遅いクエリは、EXPLAIN の推定で止めずに EXPLAIN ANALYZE で実測すると、犯人の見つかり方がかなり変わります。

読むときは、一番深いステップから上へ、actual time と rows は loops を掛けて合計で見る、この2つだけ覚えておけば大丈夫です。

Laravel では explain() が普通の EXPLAIN しか流さないので、toBase() を挟んでマクロで EXPLAIN ANALYZE を付けるのが私のやり方でした(^o^)/

正直、最初は「EXPLAIN で十分でしょ・・・」と思っていましたが、loops=48000 みたいな行を一度見ると戻れなくなります😎

スロークエリで悩んでいる人は、次に遅い画面が出たときに一度流してみてください🙌

※ バージョン番号・料金・機能は今後も変わる可能性があります。最新情報は MySQL 公式マニュアル をご確認ください👀

参考になったらシェアしてもらえるとうれしいです🙌

Xでポスト Threads はてブ LINE