Thread: BUG #3085: Performance BUG
The following bug has been logged online:
Bug reference: 3085
Logged by:
Email address: postgres@bilteks.com
PostgreSQL version: 8.2.3
Operating system: FreeBSD 6.1
Description: Performance BUG
Details:
Test sequence:
%psql test
create table t1 (i4 int4);
insert into t1 SELECT generate_series(1,999999);
vacuum analyze;
EXPLAIN ANALYZE SELECT * FROM (
SELECT i4,(SELECT COUNT(1) FROM t1 AS subselect) AS c1
FROM t1 main_table
) AS external
ORDER BY external.c1+external.c1+external.c1;
QUERY PLAN
----------------------------------------------------------------------------
------------------------------------------------------
Sort (cost=17429.03..17664.97 rows=94374 width=4) (actual
time=2582.681..2861.135 rows=100000 loops=1)
Sort Key: (($1 + $2) + $3)
InitPlan
-> Aggregate (cost=1620.68..1620.69 rows=1 width=0) (actual
time=410.606..410.608 rows=1 loops=1)
-> Seq Scan on t1 subselect (cost=0.00..1384.74 rows=94374
width=0) (actual time=0.038..220.444 rows=100000 loops=1)
-> Aggregate (cost=1620.68..1620.69 rows=1 width=0) (actual
time=407.217..407.219 rows=1 loops=1)
-> Seq Scan on t1 subselect (cost=0.00..1384.74 rows=94374
width=0) (actual time=0.100..218.832 rows=100000 loops=1)
-> Aggregate (cost=1620.68..1620.69 rows=1 width=0) (actual
time=408.512..408.514 rows=1 loops=1)
-> Seq Scan on t1 subselect (cost=0.00..1384.74 rows=94374
width=0) (actual time=0.099..221.303 rows=100000 loops=1)
-> Aggregate (cost=1620.68..1620.69 rows=1 width=0) (actual
time=413.888..413.890 rows=1 loops=1)
-> Seq Scan on t1 subselect (cost=0.00..1384.74 rows=94374
width=0) (actual time=0.122..224.616 rows=100000 loops=1)
-> Seq Scan on t1 main_table (cost=0.00..1856.61 rows=94374 width=4)
(actual time=1640.477..2060.580 rows=100000 loops=1)
Total runtime: 3074.265 ms
(13 rows)
Time: 3077.961 ms
and similar:
drop table t1;
create table t1 (i4 int4);
insert into t1 SELECT generate_series(1,999);
vacuum analyze;
EXPLAIN ANALYZE SELECT i4,x1,huge.x1+huge.x1+huge.x1+huge.x1+huge.x1 FROM
(SELECT i4,c1+i4 as x1 FROM (
SELECT i4,(SELECT COUNT(1) FROM t1 AS subselect WHERE i4<main_table.i4)+i4
AS c1
FROM t1 main_table
) AS external) AS HUGE
ORDER BY i4-huge.x1+huge.x1+huge.x1+huge.x1+huge.x1;
QUERY PLAN
----------------------------------------------------------------------------
----------------------------------------------------------------------------
----------------------------------------------------------------------------
-------------------------------------------------
Sort (cost=201598.03..201600.52 rows=999 width=4) (actual
time=31236.239..31238.171 rows=999 loops=1)
Sort Key: (((((main_table.i4 - (((subplan) + main_table.i4) +
main_table.i4)) + (((subplan) + main_table.i4) + main_table.i4))
+(((subplan) + main_table.i4) + main_table.i4)) + (((subplan) +
main_table.i4) + main_table.i4)) + (((subplan) + main_table.i4) +
main_table.i4))
-> Seq Scan on t1 main_table (cost=0.00..201548.25 rows=999 width=4)
(actual time=11.886..31222.853 rows=999 loops=1)
SubPlan
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.857..2.859 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.060..1.795 rows=499 loops=999)
Filter: (i4 < $0)
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.787..2.789 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.061..1.775 rows=499 loops=999)
Filter: (i4 < $0)
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.829..2.831 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.060..1.768 rows=499 loops=999)
Filter: (i4 < $0)
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.780..2.782 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.061..1.767 rows=499 loops=999)
Filter: (i4 < $0)
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.831..2.833 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.063..1.745 rows=499 loops=999)
Filter: (i4 < $0)
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.781..2.783 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.062..1.764 rows=499 loops=999)
Filter: (i4 < $0)
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.801..2.803 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.060..1.779 rows=499 loops=999)
Filter: (i4 < $0)
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.808..2.810 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.080..1.766 rows=499 loops=999)
Filter: (i4 < $0)
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.750..2.752 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.055..1.746 rows=499 loops=999)
Filter: (i4 < $0)
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.852..2.854 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.061..1.782 rows=499 loops=999)
Filter: (i4 < $0)
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual
time=2.803..2.804 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333
width=0) (actual time=0.063..1.778 rows=499 loops=999)
Filter: (i4 < $0)
Total runtime: 31242.269 ms
(38 rows)
Best regards,
Alexander Kirpa
"" <postgres@bilteks.com> writes:
> Description: Performance BUG
You haven't actually shown us any bug. These are not the same query and
there's no reason to expect them to take the same amount of time.
regards, tom lane
On 1 Mar 2007, at 11:28, Tom Lane wrote:
> "" <postgres@bilteks.com> writes:
> > Description: Performance BUG
>
> You haven't actually shown us any bug. These are not the same query
> and there's no reason to expect them to take the same amount of time.
>
> regards, tom lane
>
Hi, Tom!
Sorry for long reply delay.
Yes. Both previous samples is different,
but I speak about incorrect planner work - see multiple 'aggregate'.
Try as alternative next sample:
drop table t1;
create table t1 (i4 int4);
insert into t1 SELECT generate_series(1,999);
vacuum analyze;
EXPLAIN ANALYZE
SELECT i4,x1,huge.x1+huge.x1+huge.x1+huge.x1+huge.x1 FROM
(SELECT i4,c1+i4+random()*0 as x1 FROM (
-- --------------^^^^^^^^^^-----------------------
SELECT i4,(SELECT COUNT(1) FROM t1 AS subselect WHERE
i4<main_table.i4)+i4
AS c1
FROM t1 main_table
) AS external) AS HUGE
ORDER BY i4-huge.x1+huge.x1+huge.x1+huge.x1+huge.x1;
and compare timing/planner results in cases with and without
'+random()*0' part.
On my test hardware I receive results:
with '+random()*0' - 2818ms
w/o '+random()*0' - 30527ms.
I believe that plan for case with '+random()*0' more correct, see it
below:
Sort (cost=18428.88..18431.38 rows=999 width=12) (actual
time=2816.722..2818.681 rows=999 loops=1)
Sort Key: ((((((i4)::double precision - x1) + x1) + x1) + x1) + x1)
-> Subquery Scan huge (cost=0.00..18379.11 rows=999 width=12)
(actual time=1.350..2810.169 rows=999 loops=1)
-> Seq Scan on t1 main_table (cost=0.00..18344.14 rows=999
width=4) (actual time=1.312..2791.659 rows=999 loops=1)
SubPlan
-> Aggregate (cost=18.32..18.33 rows=1 width=0)
(actual time=2.758..2.760 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49
rows=333 width=0) (actual time=0.055..1.736 rows=499 loops=999)
Filter: (i4 < $0)
Total runtime: 2821.200 ms
Best regards,
Alexander Kirpa
"Alexander Kirpa" <postgres@bilteks.com> writes:
> Sorry for long reply delay.
> Yes. Both previous samples is different,
> but I speak about incorrect planner work - see multiple 'aggregate'.
> Try as alternative next sample:
Well, I'm not sure I want to prevent the thing from flattening
subqueries just because they contain sub-subqueries; nor does
trying both ways sound attractive for typical problems.
What you can do if you need to prevent flattening in a particular case
is insert an "OFFSET 0" as an optimization fence:
regression=# explain analyze
SELECT i4,x1,huge.x1+huge.x1+huge.x1+huge.x1+huge.x1 FROM
(SELECT i4,c1+i4 as x1 FROM (
SELECT i4,(SELECT COUNT(1) FROM t1 AS subselect WHERE
i4<main_table.i4)+i4
AS c1
FROM t1 main_table
) AS external offset 0) AS HUGE
ORDER BY i4-huge.x1+huge.x1+huge.x1+huge.x1+huge.x1;
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------
Sort (cost=18416.39..18418.89 rows=999 width=12) (actual time=6896.629..6900.553 rows=999 loops=1)
Sort Key: ((((((huge.i4 - huge.x1) + huge.x1) + huge.x1) + huge.x1) + huge.x1))
-> Subquery Scan huge (cost=0.00..18366.62 rows=999 width=12) (actual time=4.955..6886.427 rows=999 loops=1)
-> Limit (cost=0.00..18334.15 rows=999 width=4) (actual time=4.889..6862.476 rows=999 loops=1)
-> Seq Scan on t1 main_table (cost=0.00..18334.15 rows=999 width=4) (actual time=4.874..6855.316
rows=999loops=1)
SubPlan
-> Aggregate (cost=18.32..18.33 rows=1 width=0) (actual time=6.831..6.835 rows=1 loops=999)
-> Seq Scan on t1 subselect (cost=0.00..17.49 rows=333 width=0) (actual
time=0.075..4.573rows=499 loops=999)
Filter: (i4 < $0)
Total runtime: 6906.130 ms
(10 rows)
regards, tom lane