pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feedAdding an additional join causes very different/slow query plan
5+ messages / 3 participants
[nested] [flat]
* Adding an additional join causes very different/slow query plan
@ 2013-12-16 21:52 Joe Van Dyk <joe@tanga.com>
0 siblings, 1 reply; 5+ messages in thread
From: Joe Van Dyk @ 2013-12-16 21:52 UTC (permalink / raw)
To: 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
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: Adding an additional join causes very different/slow query plan
@ 2013-12-16 21:59 Joe Van Dyk <joe@tanga.com>
parent: Joe Van Dyk <joe@tanga.com>
0 siblings, 1 reply; 5+ messages in thread
From: Joe Van Dyk @ 2013-12-16 21:59 UTC (permalink / raw)
To: pgsql-performance
Hm, setting set join_collapse_limit = 9 seemed to fix the problem. Is that
my best/only option?
On Mon, Dec 16, 2013 at 1:52 PM, Joe Van Dyk <joe@tanga.com> wrote:
> 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
>
>
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: Adding an additional join causes very different/slow query plan
@ 2013-12-17 00:14 Tom Lane <tgl@sss.pgh.pa.us>
parent: Joe Van Dyk <joe@tanga.com>
0 siblings, 1 reply; 5+ messages in thread
From: Tom Lane @ 2013-12-17 00:14 UTC (permalink / raw)
To: Joe Van Dyk <joe@tanga.com>; +Cc: pgsql-performance
Joe Van Dyk <joe@tanga.com> writes:
> Hm, setting set join_collapse_limit = 9 seemed to fix the problem. Is that
> my best/only option?
Yup, that's what I was just about to suggest. You might want to use
10 or 12 in case some of your queries are a bit more complex than
this one --- but don't go overboard, or you may find yourself with
unreasonable planning time.
regards, tom lane
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: Adding an additional join causes very different/slow query plan
@ 2013-12-17 00:37 Joe Van Dyk <joe@tanga.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
0 siblings, 1 reply; 5+ messages in thread
From: Joe Van Dyk @ 2013-12-17 00:37 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance
On Mon, Dec 16, 2013 at 4:14 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Joe Van Dyk <joe@tanga.com> writes:
> > Hm, setting set join_collapse_limit = 9 seemed to fix the problem. Is
> that
> > my best/only option?
>
> Yup, that's what I was just about to suggest. You might want to use
> 10 or 12 in case some of your queries are a bit more complex than
> this one --- but don't go overboard, or you may find yourself with
> unreasonable planning time.
>
Is there a way to measure the planning time? It's not reported in 'explain
analyze' or 'explain analyze verbose', right?
Joe
^ permalink raw reply [nested|flat] 5+ messages in thread
* Re: Adding an additional join causes very different/slow query plan
@ 2013-12-17 14:01 Stephen Frost <sfrost@snowman.net>
parent: Joe Van Dyk <joe@tanga.com>
0 siblings, 0 replies; 5+ messages in thread
From: Stephen Frost @ 2013-12-17 14:01 UTC (permalink / raw)
To: Joe Van Dyk <joe@tanga.com>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; pgsql-performance
* Joe Van Dyk (joe@tanga.com) wrote:
> On Mon, Dec 16, 2013 at 4:14 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> > Yup, that's what I was just about to suggest. You might want to use
> > 10 or 12 in case some of your queries are a bit more complex than
> > this one --- but don't go overboard, or you may find yourself with
> > unreasonable planning time.
> >
>
> Is there a way to measure the planning time? It's not reported in 'explain
> analyze' or 'explain analyze verbose', right?
You can just run 'explain' and that'll more-or-less get you there (turn
on \timing in psql). When reading this thread, I was thinking it might
be useful to add plan time somewhere in explain/explain analyze output
though..
Thanks,
Stephen
Attachments:
signature.asc (application/pgp-signature, 835B) download
^ permalink raw reply [nested|flat] 5+ messages in thread
end of thread, other threads:[~2013-12-17 14:01 UTC | newest]
Thread overview: 5+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2013-12-16 21:52 Adding an additional join causes very different/slow query plan Joe Van Dyk <joe@tanga.com>
2013-12-16 21:59 ` Joe Van Dyk <joe@tanga.com>
2013-12-17 00:14 ` Tom Lane <tgl@sss.pgh.pa.us>
2013-12-17 00:37 ` Joe Van Dyk <joe@tanga.com>
2013-12-17 14:01 ` Stephen Frost <sfrost@snowman.net>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox