はじめに

不思議なスロークエリを発掘してしまいました。あると思います。謎のオーパーツが出土するサーバー。
役に立つかはわかりませんが、日曜大工レベルのクエリ調査の例として書いておきます。

今回問題のクエリ

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は超巨大な同一のテーブル
でも一見するとそんなに遅くなさそうなクエリですよね。というのも、一応インデックス付きの日時で絞られているからです。
でも実行ログをみていると、２０秒くらいかかっているみたいです。

いいからテーピングだ！

とりあえずEXPLAINせよ、というのを昔先生に習った気がするのでやってみます。
EXPLAINの読み方ですが、ツリー構造をイメージして、下から見ていく感じになるそうです。
costの数字にでっかい数字が書いてあったら、それはとにかくヤバいということです。

 Nested Loop Left Join  (cost=0.00..3718339.79 rows=29 width=98)★３すごい合体
   Filter: ((t1.indexed_time >= 30 minutes mae ) OR (t2.indexed_time >= 30 minutes mae ))★４フィルター
   ->  Seq Scan on deka_table t1  (cost=0.00..1585336.37 rows=145031 width=58)★１とてもでかいシーケンシャルスキャン
         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)★２インデックススキャン
         Index Cond: (t2.log_id = t1.non_indexed_alternative_id)

今回の例だと、★１と★２をやる→★３でテーブル結合→最後に★４でフィルタする…という計画のようですね。
当初のクエリは★４の時刻条件でレコードの大部分を除去するつもりだったわけなので、
そうすると、T1とT2はほとんど全部を先に超合体しているということになりますね。

ふと考えてみると、この結果集合は以下の３つを検索しているはずです。

t1.indexed_timeが３０分以内でt2.indexed_timeが何でもOK　・・・（１）
t2.indexed_timeが３０分以内でt1.indexed_timeが何でもOK　・・・（２）
t1.indexed_timeが３０分以内かつt2.indexed_timeが３０分以内　・・・（３）

ここで、（１）と（２）はそもそも結合前の絞り込みをしようがないということですね。
なるほど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テーブルにインデックスが使われて、コストが一気に下がっていることが分かります。

ただ、これだと（１）と（３）の結果集合しか取れていないので、（２）を別で取らないといけません。
ちなみに逆の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文の読み方、スキャンの種類などがまとまっています。感謝！

駆動表と内部表について、絵もわかりやすいです。こちらも感謝。