Re: huge execution time difference with almost same plan

On L, 2004-09-04 at 17:35, Tatsuo Ishii wrote:
> Hi,
>
> I've been playing with OSDL DBT-3 for a while and found very strange
> phenomemon. The query in question is Q4:
>
> select o_orderpriority, count(*) as order_count from orders where
> o_orderdate >= date '1997-10-01' and o_orderdate < (date
> '1997-10-01' + interval '3 month')::date and o_orderkey in (
> select l_orderkey from lineitem where l_commitdate <
> l_receiptdate ) group by o_orderpriority order by
> o_orderpriority;
>
> (I modified the original query a little bit so that it could use
> i_o_orderdate index)
>
> First I turn off enable_seqscan since old plan used seq scan on orders.

Did it run even faster when it used seq scan on orders ?

> Sort (cost=86050.12..86050.12 rows=1 width=19) (actual time=302476.572..302476.575 rows=5 loops=1)
> Sort Key: orders.o_orderpriority
> -> HashAggregate (cost=86050.10..86050.11 rows=1 width=19) (actual time=302476.525..302476.538 rows=5 loops=1)
> -> Nested Loop IN Join (cost=0.00..86010.61 rows=7898 width=19) (actual time=64.341..302136.493 rows=52544 loops=1)
> -> Index Scan using orders_pkey on orders (cost=0.00..65387.00 rows=53357 width=30) (actual time=44.687..36364.312 rows=57306 loops=1)
> Filter: ((o_orderdate >= '1997-10-01'::date) AND (o_orderdate < '1998-01-01'::date))
> -> Index Scan using i_l_orderkey on lineitem (cost=0.00..3.14 rows=3 width=11) (actual time=4.628..4.628 rows=1 loops=57306)
> Index Cond: ("outer".o_orderkey = lineitem.l_orderkey)
> Filter: (l_commitdate < l_receiptdate)
> Total runtime: 302476.797 ms
> (10 rows)
>
> This took about 5 minutes. no so bad. (running on PostgreSQL 7.4.5
> BTW)
>
> Then I changed following variables.
>
> enable_seqscan to on
> effective_cache_size = 100000
> random_page_cost = 1.5
>
> This seems improve the query plan in the following part:
>
> Index Cond: ((o_orderdate >= '1997-10-01'::date) AND (o_orderdate < '1998-01-01'::date))
>
> However actual execution time was almost 6 times slower than above:
>
> Sort (cost=66763.68..66763.68 rows=1 width=19) (actual time=1915554.845..1915554.849 rows=5 loops=1)
> Sort Key: orders.o_orderpriority
> -> HashAggregate (cost=66763.66..66763.67 rows=1 width=19) (actual time=1915554.797..1915554.811 rows=5 loops=1)
> -> Nested Loop IN Join (cost=0.00..66724.17 rows=7898 width=19) (actual time=277.150..1915137.592 rows=52544 loops=1)
> -> Index Scan using i_o_orderdate on orders (cost=0.00..46100.56 rows=53357 width=30) (actual time=215.502..650031.049 rows=57306 loops=1)
> Index Cond: ((o_orderdate >= '1997-10-01'::date) AND (o_orderdate < '1998-01-01'::date))
> -> Index Scan using i_l_orderkey on lineitem (cost=0.00..3.14 rows=3 width=11) (actual time=22.064..22.064 rows=1 loops=57306)
> Index Cond: ("outer".o_orderkey = lineitem.l_orderkey)
> Filter: (l_commitdate < l_receiptdate)
> Total runtime: 1915555.070 ms
> (10 rows)
>
> Could anybody explain why? For me, these query plans are almost same,
> and I don't understand how could that difference come from.
> --
> Tatsuo Ishii
>
> ---------------------------(end of broadcast)---------------------------
> TIP 5: Have you checked our extensive FAQ?
>
> http://www.postgresql.org/docs/faqs/FAQ.html