タイトル: SQLの実行ログ出力方法
SEOタイトル: SQLの実行ログ出力方法
| この記事の要点 |
|
Laravel の Eloquent やクエリビルダが実際にどんな SQL を発行しているかを確認する方法を、目的別にまとめます。N+1 問題の発見や、意図しない条件で検索されていないかの確認に使えます。
目的別の方法の選び方
| やりたいこと | 方法 | 実行されるか |
|---|---|---|
| 特定の処理で発行された SQL を一覧で見る | DB::enableQueryLog / getQueryLog | 実行される |
| 1 つのクエリの SQL 文を確認する | toSql / toRawSql / dumpRawSql | 実行されない |
| すべての SQL をログファイルに残す | DB::listen | 実行される |
| ブラウザ上で常に確認する | Laravel Debugbar / Telescope | 実行される |
方法 1: DB::enableQueryLog と getQueryLog
クエリログの収集を有効にしてから処理を実行し、最後に収集した結果を取り出します。
use Illuminate\Support\Facades\DB;
DB::enableQueryLog();
// ここで SQL を実行する処理
$items = TestTable::orderBy('col1', 'desc')->paginate(9);
dd(DB::getQueryLog());
上記の実装をすることで、SQL を走らせると画面に以下のような結果が出力されます。
array:1 [▼
0 => array:3 [▼
"query" => "select * from `test_table` order by `col1` desc limit 9 offset 0"
"bindings" => []
"time" => 2.22
]
]
query は SQL 文(プレースホルダは ? のまま)、bindings はプレースホルダに入る値、time は実行時間(ミリ秒)です。古い記事では use DB; と書かれていることがありますが、現在は use Illuminate\Support\Facades\DB; と完全なクラス名で書くのが確実です。
クエリログはメモリに溜まり続けるため、バッチ処理などで大量の SQL を流す場合は有効にしたままにしないでください。必要なら DB::disableQueryLog() や DB::flushQueryLog() で止める・消すことができます。別の DB 接続を使っている場合は DB::connection('mysql2')->enableQueryLog() のように接続ごとに有効にします。
方法 2: toSql / toRawSql で SQL 文だけ見る
クエリを実行せずに、組み立てられた SQL を確認できます。
$query = User::where('status', 'active')->where('age', '>=', 20);
// プレースホルダのままの SQL
echo $query->toSql();
// select * from `users` where `status` = ? and `age` >= ?
// バインド値を埋め込んだ SQL(Laravel 10.15 以降)
echo $query->toRawSql();
// select * from `users` where `status` = 'active' and `age` >= 20
// 出力して続行 / 出力して停止
$query->dumpRawSql();
$query->ddRawSql();
toRawSql() の出力はそのままデータベースクライアントに貼り付けて実行できるので、EXPLAIN で実行計画を調べるときに便利です。ただし、get() や first() を呼ぶ前のクエリビルダに対して使う必要があります。リレーションの Eager Loading(with)で追加発行される SQL は含まれないため、それらも見たい場合は方法 1 か方法 3 を使います。
方法 3: DB::listen ですべての SQL をログに出す
アプリ全体で発行された SQL を storage/logs/laravel.log に記録するには、app/Providers/AppServiceProvider.php の boot() にリスナーを登録します。
use Illuminate\Database\Events\QueryExecuted;
use Illuminate\Support\Facades\DB;
use Illuminate\Support\Facades\Log;
public function boot(): void
{
if (config('app.debug')) {
DB::listen(function (QueryExecuted $query) {
Log::debug('SQL', [
'sql' => $query->sql,
'bindings' => $query->bindings,
'time_ms' => $query->time,
]);
});
}
}
この例では APP_DEBUG=true のときだけ記録します。専用のログチャンネル(config/logging.php に sql チャンネルを追加し、Log::channel('sql') で書く)を作ると、通常のログと混ざらず見やすくなります。
遅いクエリだけを検出したい場合は、DB::whenQueryingForLongerThan() を使うと、1 リクエスト内のクエリ合計時間がしきい値を超えたときだけ処理を実行できます。
方法 4: 開発用パッケージで画面に表示する
- Laravel Debugbar(barryvdh/laravel-debugbar): ページ下部にツールバーを出し、そのリクエストで実行された SQL・件数・時間・重複クエリを表示する
- Laravel Telescope(公式): リクエスト・クエリ・ジョブ・例外などを記録し、専用画面で後から閲覧できる。遅いクエリの強調表示もある
どちらも開発環境専用として composer require --dev で入れるのが基本です。本番環境で有効のままにすると、SQL やリクエスト内容が外部から見える危険があります。
よくある落とし穴
- getQueryLog が空になる: enableQueryLog を SQL 実行より後に呼んでいる、または別の接続で実行されている
- dd() の後の処理が動かない: dd は処理を止める。続行したいなら
dump()を使う - 本番でログが肥大化する: DB::listen を無条件に登録すると、全リクエストの SQL が記録されディスクを圧迫する。パスワードや個人情報がバインド値としてログに残る点にも注意
- toRawSql の値は参考用: 埋め込み表示はあくまで確認用。実際の実行はプリペアドステートメントで行われている
確認方法
方法 3 を設定した場合は、ページを 1 回開いてから storage/logs/laravel.log を確認します。同じ形の SQL が何十回も並んでいれば N+1 問題の可能性が高く、with() による Eager Loading で回数を減らせます。修正前後でログに出る SQL の件数を比べると、効果を確認できます。