はじめに
不思議なスロークエリを発掘してしまいました。あると思います。謎のオーパーツが出土するサーバー。
役に立つかはわかりませんが、日曜大工レベルのクエリ調査の例として書いておきます。
今回問題のクエリ
SELECT t1.a, t1.b, t1.c, t2.d, t2.e from deka_table t1
left join deka_table t2 on (t2.id = t1.non_indexed_alternative_id)
where t1.a = hoge
and t1.b = hege
and (t1.indexed_time > 30 minutes mae or t2.indexed_time > 30 minutes mae)
(実際のクエリからは一部脚色を加えています。)
ここで、
・id, indexed_time はインデックスあり。他はインデックスなし
・t1とt2は超巨大な同一のテーブル
でも一見するとそんなに遅くなさそうなクエリですよね。というのも、一応インデックス付きの日時で絞られているからです。
でも実行ログをみていると、20秒くらいかかっているみたいです。
いいからテーピングだ!
とりあえずEXPLAINせよ、というのを昔先生に習った気がするのでやってみます。
EXPLAINの読み方ですが、ツリー構造をイメージして、下から見ていく感じになるそうです。
costの数字にでっかい数字が書いてあったら、それはとにかくヤバいということです。
Nested Loop Left Join (cost=0.00..3718339.79 rows=29 width=98)★3すごい合体
Filter: ((t1.indexed_time >= 30 minutes mae ) OR (t2.indexed_time >= 30 minutes mae ))★4フィルター
-> Seq Scan on deka_table t1 (cost=0.00..1585336.37 rows=145031 width=58)★1とてもでかいシーケンシャルスキャン
Filter: ((t1.a = hoge) AND (t1.b = hege))
-> Index Scan using id_pkey on deka_table t2 (cost=0.00..14.69 rows=1 width=48)★2インデックススキャン
Index Cond: (t2.log_id = t1.non_indexed_alternative_id)
今回の例だと、★1と★2をやる→★3でテーブル結合→最後に★4でフィルタする…という計画のようですね。
当初のクエリは★4の時刻条件でレコードの大部分を除去するつもりだったわけなので、
そうすると、T1とT2はほとんど全部を先に超合体しているということになりますね。
ふと考えてみると、この結果集合は以下の3つを検索しているはずです。
- t1.indexed_timeが30分以内でt2.indexed_timeが何でもOK ・・・(1)
- t2.indexed_timeが30分以内でt1.indexed_timeが何でもOK ・・・(2)
- t1.indexed_timeが30分以内かつt2.indexed_timeが30分以内 ・・・(3)
ここで、(1)と(2)はそもそも結合前の絞り込みをしようがないということですね。
なるほどPostgres先生は冷静だ…。結局、この絞り込みは後回しにする外なく、それで最後のFilterに使われていたんですね。
最適化がどうこうの前に、原理的にindexを使えないケースだということが分かりました。
indexはどういう時に効く?
試しに(t1.indexed_time > 30 minutes mae or t2.indexed_time > 30 minutes mae)の部分を、t1.indexed_time > 30 minutes maeだけにしてみるとどうでしょうか?
SELECT t1.a, t1.b, t1.c, t2.d, t2.e from deka_table t1
left join deka_table t2 on (t2.id = t1.non_indexed_alternative_id)
where t1.a = hoge
and t1.b = hege
and (t1.indexed_time > 30 minutes mae)
結果はこのようになりました。
Nested Loop Left Join (cost=0.00..9582.00 rows=15 width=98)
-> Index Scan using indexed_time_idx on deka_table t1 (cost=0.00..9360.92 rows=15 width=58)★インデックス検索になった
Index Cond: (t1.indexed_time > 30 minutes mae::timestamp without time zone)
Filter: t1.a = hoge and t1.b = hege
-> Index Scan using id_pkey on deka_table t2 (cost=0.00..14.73 rows=1 width=48)
Index Cond: (t2.id = t1.non_indexed_alternative_id)
なんかよさげです。 駆動表であるT1テーブルにインデックスが使われて、コストが一気に下がっていることが分かります。
ただ、これだと(1)と(3)の結果集合しか取れていないので、(2)を別で取らないといけません。
ちなみに逆のT2.indexed_time 側の絞りだけにしてみるとどうでしょうか?
SELECT t1.a, t1.b, t1.c, t2.d, t2.e from deka_table t1
left join deka_table t2 on (t2.id = t1.non_indexed_alternative_id)
where t1.a = hoge
and t1.b = hege
and (t2.indexed_time > 30 minutes mae)
結果はこのようになりました。
Hash Join (cost=9357.64..1594128.84 rows=1 width=98)
Hash Cond: (t1.non_indexed_alternative_id = t2.id)
-> Seq Scan on deka_table t1 (cost=0.00..1583856.62 rows=146331 width=58)
Filter: t1.a = hoge and t1.b = hege
-> Hash (cost=9324.87..9324.87 rows=2622 width=48)
-> Index Scan using indexed_time_idx on deka_table t2 (cost=0.00..9324.87 rows=2622 width=48)
Index Cond: (indexed_time >= 30 minutes mae::timestamp without time zone)
こちらはだめそうです。最初の例と変わらず、駆動表のT1テーブルに全件Seq Scanが走ったままになっています。
駆動表側がindex検索になって、かつ結合前にレコード数を絞れている必要がありそうですね。
完成品は?
結局もうすこし細かくパターン別でインデックスが効くように書きなおし、後から結果をまとめる構成にしました。
かなり速いクエリになったものの、あまり宜しくないサブクエリとかも入れていてかなり無骨なものになってしまったので、ここで紹介するのは遠慮させてください。。。
おわりに
EXPLAIN文使うといいよ、そしてインデックス使えてるか見ると良きですというだけのご紹介でした。
実務でこんな学生実験みたいなことをする羽目になるとは…
まぁたまにはこういう味変トラブルシュートも気分転換になってよいですね。
良きpostgresライフをお過ごしください。
参考
EXPLAIN文の読み方、スキャンの種類などがまとまっています。感謝!
駆動表と内部表について、絵もわかりやすいです。こちらも感謝。