Adding an additional join causes very different/slow query plan

From: Joe Van Dyk <joe(at)tanga(dot)com>
To: "pgsql-performance(at)postgresql(dot)org" <pgsql-performance(at)postgresql(dot)org>
Subject: Adding an additional join causes very different/slow query plan
Date: 2013-12-16 21:52:29
Message-ID: CACfv+pJ-NCBHLiHmeiCg_J5eunSavhQCDERRm4ryS8iHrzEdbQ@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

The actual query selects columns from each of those tables.

If I remove the join on order_shipping_addresses, it's very fast. Likewise,
if I remove the join on skus, base_skus, or products, it's also very fast.

I'm pretty sure I have all the necessary indexes.

The below is also at
https://gist.github.com/joevandyk/88624f7c23790200cccd/raw/gistfile1.txt

Postgres appears to use the number of joins to determine which plan to use?
If I go over that by one, then it seems to switch to a very different/slow
plan. Is there a way I can speed this up?

-- This is really slow
explain analyze
select
pl.uuid as packing_list_id
from orders o
join order_shipping_addresses osa on osa.order_id = o.id
join line_items li on li.order_id = o.id
join skus on skus.id = li.sku_id
join base_skus bs using (base_sku_id)
join products p on p.id = li.product_id
left join packed_line_items plis on plis.line_item_id = li.id
left join packing_list_items pli using (packed_line_item_id)
left join packing_lists pl on pl.id = pli.packing_list_id
where pl.uuid = '58995488567';

Hash Join (cost=529945.66..1169006.25 rows=1 width=8) (actual
time=16994.025..18442.838 rows=1 loops=1)
Hash Cond: (pli.packing_list_id = pl.id)
-> Hash Join (cost=529937.20..1156754.36 rows=3264913 width=8)
(actual time=6394.260..18186.960 rows=3373977 loops=1)
Hash Cond: (plis.packed_line_item_id = pli.packed_line_item_id)
-> Hash Join (cost=389265.00..911373.32 rows=3264913
width=16) (actual time=5260.162..13971.003 rows=3373977 loops=1)
Hash Cond: (li.sku_id = skus.id)
-> Hash Join (cost=379645.45..836455.51 rows=3264913
width=20) (actual time=5130.797..12370.225 rows=3373977 loops=1)
Hash Cond: (li.order_id = osa.order_id)
-> Hash Join (cost=7256.32..353371.98
rows=3265060 width=24) (actual time=29.692..3674.827 rows=3373977
loops=1)
Hash Cond: (li.product_id = p.id)
-> Merge Join (cost=16.25..284912.04
rows=3265060 width=28) (actual time=0.093..2659.779 rows=3373977
loops=1)
Merge Cond: (li.id = plis.line_item_id)
-> Index Only Scan using
line_items_id_product_id_order_id_sku_id_idx on line_items li
(cost=0.43..116593.45 rows=3240868 width=16) (actual
time=0.073..531.457 rows=3606900 loops=1)
Heap Fetches: 14
-> Index Scan using
packed_line_items_line_item_id_idx on packed_line_items plis
(cost=0.43..119180.75 rows=3373974 width=20) (actual
time=0.014..1052.544 rows=3373977 loops=1)
-> Hash (cost=6683.92..6683.92 rows=44492
width=4) (actual time=29.561..29.561 rows=44492 loops=1)
Buckets: 8192 Batches: 1 Memory Usage: 1565kB
-> Seq Scan on products p
(cost=0.00..6683.92 rows=44492 width=4) (actual time=0.006..23.023
rows=44492 loops=1)
-> Hash (cost=325301.79..325301.79 rows=2870027
width=8) (actual time=5097.168..5097.168 rows=2870028 loops=1)
Buckets: 65536 Batches: 8 Memory Usage: 14039kB
-> Hash Join (cost=111732.51..325301.79
rows=2870027 width=8) (actual time=828.796..4582.395 rows=2870028
loops=1)
Hash Cond: (o.id = osa.order_id)
-> Seq Scan on orders o
(cost=0.00..126120.27 rows=2870027 width=4) (actual
time=0.009..636.423 rows=2870028 loops=1)
-> Hash (cost=64643.56..64643.56
rows=2870156 width=4) (actual time=827.832..827.832 rows=2870028
loops=1)
Buckets: 65536 Batches: 8
Memory Usage: 12636kB
-> Seq Scan on
order_shipping_addresses osa (cost=0.00..64643.56 rows=2870156
width=4) (actual time=0.008..419.783 rows=2870028 loops=1)
-> Hash (cost=8324.48..8324.48 rows=103606 width=4)
(actual time=129.271..129.271 rows=103606 loops=1)
Buckets: 16384 Batches: 1 Memory Usage: 3643kB
-> Hash Join (cost=3389.30..8324.48 rows=103606
width=4) (actual time=28.641..113.012 rows=103606 loops=1)
Hash Cond: (skus.base_sku_id = bs.base_sku_id)
-> Seq Scan on skus (cost=0.00..2863.06
rows=103606 width=20) (actual time=0.014..13.836 rows=103606 loops=1)
-> Hash (cost=2098.02..2098.02
rows=103302 width=16) (actual time=28.549..28.549 rows=103302 loops=1)
Buckets: 16384 Batches: 1 Memory
Usage: 4843kB
-> Seq Scan on base_skus bs
(cost=0.00..2098.02 rows=103302 width=16) (actual time=0.013..13.572
rows=103302 loops=1)
-> Hash (cost=78727.09..78727.09 rows=3374009 width=24)
(actual time=1132.577..1132.577 rows=3373977 loops=1)
Buckets: 65536 Batches: 16 Memory Usage: 11596kB
-> Seq Scan on packing_list_items pli
(cost=0.00..78727.09 rows=3374009 width=24) (actual
time=0.007..562.361 rows=3373977 loops=1)
-> Hash (cost=8.45..8.45 rows=1 width=12) (actual
time=0.037..0.037 rows=1 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 1kB
-> Index Scan using packing_lists_uuid_key on packing_lists
pl (cost=0.43..8.45 rows=1 width=12) (actual time=0.036..0.036 rows=1
loops=1)
Index Cond: (uuid = 58995488567::bigint)
Total runtime: 18453.209 ms

-- This is way faster. Only thing I did was remove one of the joins.
explain analyze
select
pl.uuid as packing_list_id
from orders o
-- join order_shipping_addresses osa on osa.order_id = o.id
join line_items li on li.order_id = o.id
join skus on skus.id = li.sku_id
join base_skus bs using (base_sku_id)
join products p on p.id = li.product_id
left join packed_line_items plis on plis.line_item_id = li.id
left join packing_list_items pli using (packed_line_item_id)
left join packing_lists pl on pl.id = pli.packing_list_id
where pl.uuid = '58995488567';

Nested Loop (cost=3.15..23.08 rows=1 width=8) (actual
time=0.256..0.260 rows=1 loops=1)
-> Nested Loop (cost=2.86..22.76 rows=1 width=12) (actual
time=0.223..0.226 rows=1 loops=1)
-> Nested Loop (cost=2.44..22.25 rows=1 width=28) (actual
time=0.197..0.200 rows=1 loops=1)
-> Nested Loop (cost=2.15..21.93 rows=1 width=16)
(actual time=0.177..0.179 rows=1 loops=1)
-> Nested Loop (cost=1.72..21.34 rows=1
width=20) (actual time=0.146..0.148 rows=1 loops=1)
-> Nested Loop (cost=1.29..20.86 rows=1
width=12) (actual time=0.098..0.099 rows=1 loops=1)
-> Nested Loop (cost=0.86..20.34
rows=1 width=24) (actual time=0.082..0.082 rows=1 loops=1)
-> Index Scan using
packing_lists_uuid_key on packing_lists pl (cost=0.43..8.45 rows=1
width=12) (actual time=0.039..0.039 rows=1 loops=1)
Index Cond: (uuid =
58995488567::bigint)
-> Index Scan using
packing_list_items_packing_list_id_idx on packing_list_items pli
(cost=0.43..11.88 rows=2 width=24) (actual time=0.040..0.040 rows=1
loops=1)
Index Cond:
(packing_list_id = pl.id)
-> Index Scan using
packed_line_items_packed_line_item_id_key on packed_line_items plis
(cost=0.43..0.50 rows=1 width=20) (actual time=0.015..0.016 rows=1
loops=1)
Index Cond:
(packed_line_item_id = pli.packed_line_item_id)
-> Index Only Scan using
line_items_id_product_id_order_id_sku_id_idx on line_items li
(cost=0.43..0.47 rows=1 width=16) (actual time=0.044..0.044 rows=1
loops=1)
Index Cond: (id = plis.line_item_id)
Heap Fetches: 0
-> Index Only Scan using orders_pkey on orders o
(cost=0.43..0.58 rows=1 width=4) (actual time=0.028..0.028 rows=1
loops=1)
Index Cond: (id = li.order_id)
Heap Fetches: 1
-> Index Scan using skus_id_product_id_idx on skus
(cost=0.29..0.32 rows=1 width=20) (actual time=0.019..0.020 rows=1
loops=1)
Index Cond: (id = li.sku_id)
-> Index Only Scan using base_skus_pkey on base_skus bs
(cost=0.42..0.49 rows=1 width=16) (actual time=0.024..0.024 rows=1
loops=1)
Index Cond: (base_sku_id = skus.base_sku_id)
Heap Fetches: 1
-> Index Only Scan using products_pkey on products p
(cost=0.29..0.32 rows=1 width=4) (actual time=0.027..0.028 rows=1
loops=1)
Index Cond: (id = li.product_id)
Heap Fetches: 1
Total runtime: 0.434 ms

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Joe Van Dyk 2013-12-16 21:59:35 Re: Adding an additional join causes very different/slow query plan
Previous Message Drew Jetter 2013-12-16 20:54:43 Help with cursor query that is intermittently slow