株式会社Good Labでエンジニアをしている コータロー です。
日々、Java・SQL・Gitなどの技術情報や、新人エンジニア向けの学習ノウハウ、
AI活用についての情報を発信しています。
Good Labについて気になった方は、コーポレートサイトもぜひご覧ください。
▶コーポレートサイト
このシリーズについて
「知ってはいる。けど、人に説明しろと言われると詰まる」——そんな歯がゆいDB用語を、1記事1用語・図解中心で解消していくシリーズです。
- 第1回:ACIDの「C(一貫性)」、説明できますか?
- 第2回:トランザクション分離レベル ―「READ COMMITTED」で結局なにが読めるの?
- 第3回:ロックとデッドロック ―「誰が」「何を」「どこまで」ロックしている?
- 第4回:「スキーマ」って結局なに? ― 同じ単語が文脈で別物を指している
- 第5回:正規化 ―「第3正規形まで」の「まで」って何?
- 第6回:インデックス ― 貼ったのに効かないのはなぜ?
- 第7回:実行計画 ― EXPLAINの出力、どこを見る?
EXPLAINでは絶対に見つからない遅さ
前回、実行計画の読み方をやりました。これで遅いクエリは自分で診断できます。……1本ずつなら。
N+1問題が厄介なのは、ここです。
1本1本はすべて速い。なのに全体が遅い。
EXPLAIN は「このSQL1本がどう処理されるか」しか教えてくれません。「そのSQLが何本飛んでいるか」は、実行計画には映らないのです。
今回はこの「本数」の話です。実測はすべて PostgreSQL 16.14(Docker postgres:16) です。
N+1の正体:1 + N 回
著者一覧を表示し、各著者の本も一緒に出す画面を考えます。
一覧を取る 1回、そのあと各行について N回。合わせて 1 + N 回。これがN+1問題です。今回の例なら 1 + 100 = 101本のSQLが飛びます。
パラドックス:1本1本は速い
ここが歯がゆさの核心です。N+1のうちの1本を EXPLAIN ANALYZE にかけてみます。
EXPLAIN ANALYZE SELECT * FROM books WHERE author_id = 42;
Bitmap Heap Scan on books (cost=4.44..58.65 rows=20 width=17) (actual time=0.030..0.096 rows=20 loops=1)
Recheck Cond: (author_id = 42)
-> Bitmap Index Scan on idx_books_author (cost=0.00..4.44 rows=20 width=0) (actual time=0.025..0.025 rows=20 loops=1)
Execution Time: 0.124 ms
0.124 ms。 インデックスも効いています。第7回の観点で見ても、推定 rows=20 と実測 rows=20 が一致していて、何の問題もありません。
この「完璧なクエリ」が100本飛ぶ、というのがN+1です。1本を見ている限り、永遠に原因は見つかりません。
どこに潜んでいるのか
SQLを101本書いた人はいません。コードの上では、ループの中の何気ない1行に見えます。
author.books は、コードとしてはただのプロパティ参照です。しかしORM(O/Rマッパー)が遅延ロードを行う設計だと、アクセスされた瞬間に裏でSQLが1本発行されます。ループの中にあれば、当然その回数だけ飛びます。
JPA(Java)、Active Record(Rails)、Eloquent(Laravel)など、関連を後から自動で取ってくれるORMには等しく起こりえます。便利さの裏返しなので、フレームワークのバグではありません。
そして画面は正常に動きます。 データは正しく出るので、テストも通ります。気づくきっかけは、SQLログを見ることだけです。
PostgreSQLなら
log_statement = 'all'で発行SQLを全部ログに出せます。同じ形のSQLがパラメータ違いで延々並んでいたら、ほぼN+1です。pg_stat_statementsで「呼び出し回数(calls)」の多い順に並べるのも有効です。
実測:101本 vs 1本
同じ結果(著者100人とその本2000件)を3つの方法で取り、psqlのセッション内で経過時間を計測しました。psql自体の起動コストを含めないよう、clock_timestamp() で計測区間を囲んでいます。各5回実行しました。
| 方法 | SQLの本数 | 実測(5回、ms) |
|---|---|---|
| N+1 | 101本 | 10.551 / 10.794 / 10.153 / 9.908 / 11.511 |
| JOINで1回 | 1本 | 4.107 / 4.118 / 4.243 / 4.134 / 4.081 |
| INでまとめ取り | 2本 | 3.921 / 3.798 / 4.419 / 3.707 / 3.640 |
101本 = 約10ms、1本 = 約4ms。 1本あたり0.124msの「速いクエリ」を100本重ねた結果、全体では2倍以上の差になりました。
-- JOINで1回にまとめる
SELECT a.id, a.name, b.id, b.title
FROM authors a JOIN books b ON b.author_id = a.id
WHERE a.id <= 100 ORDER BY a.id;
-- INでまとめ取り(一覧1本 + 関連1本 = 2本)
SELECT id, name FROM authors ORDER BY id LIMIT 100;
SELECT author_id, id, title FROM books
WHERE author_id IN (SELECT id FROM authors ORDER BY id LIMIT 100);
どちらも**「N回」を「1回」に畳む**という発想は同じです。
| 直し方 | SQL | ORMでの呼び名(例) |
|---|---|---|
| JOINで1回に | JOIN |
eager loading / fetch join |
| まとめて取る | IN (...) |
batch fetch / preload |
ORMを使っている場合、生SQLを書き直すより**「関連を先に取ってくる」設定に変えるだけ**で解決することがほとんどです。
正直な注記:この実測は差が小さく出ています
ここは誠実に書きます。上の「2倍差」は、N+1の被害を控えめに見せた数字です。
今回の計測はすべて同じマシン上のDockerコンテナ相手で、ネットワークの往復がほぼゼロです。純粋に「本数」だけのコストを測ると、こうなりました。
SELECT 1; を101本 : 3.339 / 3.269 / 3.186 ms
SELECT 1; を1本 : 0.288 / 0.344 / 0.318 ms
100本余計に投げても約3ms。ローカルではSQL1往復が0.03ms程度しかかからないからです。
本番環境は違います。アプリサーバとDBサーバは別マシンで、1往復ごとにネットワーク遅延がかかります。
仮に1往復が0.5msかかる環境なら、100往復で50msが上乗せされます(これは実測ではなく単純な掛け算です)。往復が増えるほど差が開く、という構造だけ押さえてください。
「ローカルでは速いのに本番だけ遅い」の典型的な正体がこれです。逆に言えば、ローカル検証でN+1の被害を正しく見積もるのは難しい、ということでもあります。
まとめ:1行で説明するなら
「N+1問題は、一覧を取る1回のあと、各行の関連データをN回取りに行ってしまう状態です。厄介なのは1本1本は速いこと。インデックスも効いていて
EXPLAINでも問題なしと出るので、実行計画をいくら睨んでも見つかりません。問題はクエリの本数なので、SQLログかpg_stat_statementsの呼び出し回数で気づきます。直し方はJOINやINでN回を1回に畳むことです」
第7回とセットで覚えるとよい対比がこれです。
| 見るもの | 気づき方 | |
|---|---|---|
| 遅いクエリ | SQL 1本の中身 | EXPLAIN |
| N+1問題 | SQLの 本数 | SQLログ / 呼び出し回数 |
次回
クエリの「本数」の次は、接続の数です。DBへの接続は1本張るだけでも高価で、かといって無制限に増やすと今度はDBが倒れます。この綱引きを引き受けているのがコネクションプールです。
第9回:コネクションプール ——「プールサイズは何を基準に決める?」を図解します。
(シリーズ全11回の予定は第1回に掲載しています)
参考
- PostgreSQL 16 Documentation - Using EXPLAIN
- PostgreSQL 16 Documentation - Error Reporting and Logging(log_statement)
- PostgreSQL 16 Documentation - pg_stat_statements
- MySQL 8.0 Reference Manual - The General Query Log
@kotaro_ai_lab
AI活用や開発効率化について発信しています。フォローお気軽にどうぞ!