Re: BUG #18935: The optimiser's choice of sort doubles the execution time. - Mailing list pgsql-bugs

The following bug has been logged on the website:

Bug reference:      18935
Logged by:          hongjun xiao
Email address:      xiaohongjun@stu.xidian.edu.cn
PostgreSQL version: 17.4
Operating system:   Ubuntu 20.04.6 LTS
Description:        

database4=# explain analyze SELECT t0.c0 FROM t0 INNER JOIN t1* ON
((t1.c0)=(((t1.c0)-(((((t1.c0)*('(-795716537,-245904803]'::int4range)))-(range_merge(t1.c0,
t0.c0))))))) GROUP BY t0.c0;                                                         QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------- Group  (cost=365.27..365.62 rows=70 width=13) (actual time=16.143..17.958
rows=121 loops=1)   Group Key: t0.c0   ->  Sort  (cost=365.27..365.45 rows=70 width=13) (actual
time=16.141..16.540 rows=12688 loops=1)         Sort Key: t0.c0         Sort Method: quicksort  Memory: 385kB         ->  Nested Loop  (cost=0.00..363.13 rows=70 width=13) (actual
time=0.055..8.431 rows=12688 loops=1)               Join Filter: (t1.c0 = (t1.c0 - ((t1.c0 *
'[-795716536,-245904802)'::int4range) - range_merge(t1.c0, t0.c0))))               Rows Removed by Join Filter: 1650               ->  Seq Scan on t0  (cost=0.00..2.34 rows=134 width=13)
(actual time=0.025..0.040 rows=134 loops=1)               ->  Materialize  (cost=0.00..2.61 rows=107 width=13) (actual
time=0.000..0.005 rows=107 loops=134)                     ->  Seq Scan on t1  (cost=0.00..2.07 rows=107 width=13)
(actual time=0.015..0.028 rows=107 loops=1) Planning Time: 0.105 ms Execution Time: 17.998 ms
(13 rows)
database4=# set enable_sort=false;
SET
database4=# explain analyze SELECT t0.c0 FROM t0 INNER JOIN t1* ON
((t1.c0)=(((t1.c0)-(((((t1.c0)*('(-795716537,-245904803]'::int4range)))-(range_merge(t1.c0,
t0.c0))))))) GROUP BY t0.c0;                                                      QUERY PLAN
----------------------------------------------------------------------------------------------------------------------- HashAggregate  (cost=363.30..364.00 rows=70 width=13) (actual
time=8.034..8.042 rows=121 loops=1)   Group Key: t0.c0   Batches: 1  Memory Usage: 40kB   ->  Nested Loop  (cost=0.00..363.13 rows=70 width=13) (actual
time=0.019..5.680 rows=12688 loops=1)         Join Filter: (t1.c0 = (t1.c0 - ((t1.c0 *
'[-795716536,-245904802)'::int4range) - range_merge(t1.c0, t0.c0))))         Rows Removed by Join Filter: 1650         ->  Seq Scan on t0  (cost=0.00..2.34 rows=134 width=13) (actual
time=0.010..0.033 rows=134 loops=1)         ->  Materialize  (cost=0.00..2.61 rows=107 width=13) (actual
time=0.000..0.003 rows=107 loops=134)               ->  Seq Scan on t1  (cost=0.00..2.07 rows=107 width=13)
(actual time=0.004..0.007 rows=107 loops=1) Planning Time: 0.060 ms Execution Time: 8.064 ms
(11 rows)

I noticed underestimation problem here because of inability to predict the actual number of rows for this expression by the planner: range_merge(t1.c0, t0.c0))

As I know it is not possible to create extended statistics on different relations.

CREATE STATISTICS t0_t1_stats (dependencies) ON c0 FROM t0, t1;

But I added index on table t0: create index idx on t0(c0) and sort operation was skipped because of index scan but I could got this only with disable seqscan:

set enable_seqscan = off;

 Group  (cost=0.14..375.12 rows=70 width=13) (actual time=0.129..44.850 rows=121.00 loops=1)
   Group Key: t0.c0
   Buffers: shared hit=3
   ->  Nested Loop  (cost=0.14..374.94 rows=70 width=13) (actual time=0.125..37.008 rows=12688.00 loops=1)
         Join Filter: (t1.c0 = (t1.c0 - ((t1.c0 * '[-795716536,-245904802)'::int4range) - range_merge(t1.c0, t0.c0))))
         Rows Removed by Join Filter: 1650
         Buffers: shared hit=3
         ->  Index Only Scan using idx on t0  (cost=0.14..14.15 rows=134 width=13) (actual time=0.067..0.267 rows=134.00 loops=1)
               Heap Fetches: 134
               Index Searches: 1
               Buffers: shared hit=2
         ->  Materialize  (cost=0.00..2.61 rows=107 width=13) (actual time=0.000..0.016 rows=107.00 loops=134)
               Storage: Memory  Maximum Storage: 21kB
               Buffers: shared hit=1
               ->  Seq Scan on t1  (cost=0.00..2.07 rows=107 width=13) (actual time=0.026..0.063 rows=107.00 loops=1)
                     Disabled: true
                     Buffers: shared hit=1
 Planning Time: 0.289 ms
 Execution Time: 44.956 ms
(19 rows)

The execution ti,e on my laptop is almost the same with disabled sorting:

set enable_sort = off;

-----------------------------------------------------------------------------------------------------------------------
 HashAggregate  (cost=363.30..364.00 rows=70 width=13) (actual time=55.001..55.077 rows=121.00 loops=1)
   Group Key: t0.c0
   Batches: 1  Memory Usage: 40kB
   Buffers: shared hit=2
   ->  Nested Loop  (cost=0.00..363.13 rows=70 width=13) (actual time=0.050..38.315 rows=12688.00 loops=1)
         Join Filter: (t1.c0 = (t1.c0 - ((t1.c0 * '[-795716536,-245904802)'::int4range) - range_merge(t1.c0, t0.c0))))
         Rows Removed by Join Filter: 1650
         Buffers: shared hit=2
         ->  Seq Scan on t0  (cost=0.00..2.34 rows=134 width=13) (actual time=0.024..0.065 rows=134.00 loops=1)
               Buffers: shared hit=1
         ->  Materialize  (cost=0.00..2.61 rows=107 width=13) (actual time=0.000..0.014 rows=107.00 loops=134)
               Storage: Memory  Maximum Storage: 21kB
               Buffers: shared hit=1
               ->  Seq Scan on t1  (cost=0.00..2.07 rows=107 width=13) (actual time=0.007..0.023 rows=107.00 loops=1)
                     Buffers: shared hit=1
 Planning Time: 0.144 ms
 Execution Time: 55.166 ms
(17 rows)

Original query plan:

-----------------------------------------------------------------------------------------------------------------------------
 Group  (cost=365.27..365.62 rows=70 width=13) (actual time=47.471..51.439 rows=121.00 loops=1)
   Group Key: t0.c0
   Buffers: shared hit=5
   ->  Sort  (cost=365.27..365.45 rows=70 width=13) (actual time=47.467..48.234 rows=12688.00 loops=1)
         Sort Key: t0.c0
         Sort Method: quicksort  Memory: 385kB
         Buffers: shared hit=5
         ->  Nested Loop  (cost=0.00..363.13 rows=70 width=13) (actual time=0.077..34.222 rows=12688.00 loops=1)
               Join Filter: (t1.c0 = (t1.c0 - ((t1.c0 * '[-795716536,-245904802)'::int4range) - range_merge(t1.c0, t0.c0))))
               Rows Removed by Join Filter: 1650
               Buffers: shared hit=2
               ->  Seq Scan on t0  (cost=0.00..2.34 rows=134 width=13) (actual time=0.028..0.061 rows=134.00 loops=1)
                     Buffers: shared hit=1
               ->  Materialize  (cost=0.00..2.61 rows=107 width=13) (actual time=0.000..0.015 rows=107.00 loops=134)
                     Storage: Memory  Maximum Storage: 21kB
                     Buffers: shared hit=1
                     ->  Seq Scan on t1  (cost=0.00..2.07 rows=107 width=13) (actual time=0.016..0.053 rows=107.00 loops=1)
                           Buffers: shared hit=1
 Planning:
   Buffers: shared hit=25 read=3
 Planning Time: 0.863 ms
 Execution Time: 51.609 ms

-- 
Regards,
Alena Rybakina
Postgres Professional