Re: Query run in 27s with 15.2 vs 37ms with 14.6 - Mailing list pgsql-bugs

From Charles
Subject Re: Query run in 27s with 15.2 vs 37ms with 14.6
Date
Msg-id CABthHP84n1-aM5CV5RLJt2L9+9QG7Zp2EHsHf8tqHS04qASqrw@mail.gmail.com
Whole thread Raw
In response to Re: Query run in 27s with 15.2 vs 37ms with 14.6  (Jeff Janes <jeff.janes@gmail.com>)
Responses Re: Query run in 27s with 15.2 vs 37ms with 14.6
Re: Query run in 27s with 15.2 vs 37ms with 14.6
List pgsql-bugs
On Tue, Feb 21, 2023 at 2:25 AM Jeff Janes <jeff.janes@gmail.com> wrote:
On Mon, Feb 20, 2023 at 10:56 AM Charles <peacech@gmail.com> wrote:
 
The plan from 15.2:

Nested Loop  (cost=63003.26..64440.14 rows=1 width=89) (actual time=23.234..27407.834 rows=779 loops=1)
 
Plan generated by 14.6

Merge Join  (cost=61456.65..61716.09 rows=1 width=89) (actual time=25.509..37.185 rows=779 loops=1)

Given how close those plan estimates are to each other, I would say your query was very fragile under 14.6, and it was just a matter of luck of how the statistics were computed that you got the better plan on the older version.  As opposed to some important coding changes that happened between versions.  To verify that, Can you force each version to choose the other plan, for example by fiddling with enable_nestedloop on one and enable_mergjoin on the other?


Disabling mergejoin on 14.6 and disabling nestedloop on 15.2 causes both to use hashjoin where it runs for 37ms in 14.6 and 208ms in 15.2.

14.6:
Hash Join  (cost=61456.66..61716.21 rows=1 width=89) (actual time=23.391..36.458 rows=779 loops=1)
  Hash Cond: (stock_price.code = s.code)
  ->  Finalize GroupAggregate  (cost=61136.88..61384.43 rows=949 width=37) (actual time=22.698..35.350 rows=907 loops=1)
        Group Key: stock_price.code
        InitPlan 1 (returns $0)
          ->  Limit  (cost=0.41..0.43 rows=1 width=4) (actual time=0.235..0.278 rows=1 loops=1)
                ->  Index Only Scan Backward using stock_date_pkey on stock_date  (cost=0.28..181.48 rows=7261 width=4) (actual time=0.231..0.233 rows=6 loops=1)
                      Heap Fetches: 6
        ->  Gather Merge  (cost=61136.45..61357.90 rows=1898 width=37) (actual time=22.681..34.642 rows=907 loops=1)
              Workers Planned: 2
              Params Evaluated: $0
              Workers Launched: 2
              ->  Sort  (cost=60136.42..60138.80 rows=949 width=37) (actual time=1.235..1.257 rows=302 loops=3)
                    Sort Key: stock_price.code
                    Sort Method: quicksort  Memory: 95kB
                    Worker 0:  Sort Method: quicksort  Memory: 25kB
                    Worker 1:  Sort Method: quicksort  Memory: 25kB
                    ->  Partial HashAggregate  (cost=60077.63..60089.50 rows=949 width=37) (actual time=1.038..1.127 rows=302 loops=3)
                          Group Key: stock_price.code
                          Batches: 1  Memory Usage: 577kB
                          Worker 0:  Batches: 1  Memory Usage: 73kB
                          Worker 1:  Batches: 1  Memory Usage: 73kB
                          ->  Parallel Index Scan using idx_stock_price_date on stock_price  (cost=0.43..59671.39 rows=81248 width=13) (actual time=0.021..0.689 rows=1427 loops=3)
                                Index Cond: (date > $0)
                                Filter: (value > 0)
                                Rows Removed by Filter: 222
  ->  Hash  (cost=319.76..319.76 rows=1 width=29) (actual time=0.650..0.652 rows=779 loops=1)
        Buckets: 1024  Batches: 1  Memory Usage: 57kB
        ->  Index Scan using idx_stock_price_date on stock_price s  (cost=0.43..319.76 rows=1 width=29) (actual time=0.212..0.542 rows=779 loops=1)
              Index Cond: (date = '2023-02-20'::date)
              Filter: ((open > 0) AND (value > 0) AND (length(code) = 4))
              Rows Removed by Filter: 210
Planning Time: 1.303 ms
Execution Time: 36.671 ms

15.2:
Hash Join  (cost=65863.57..69710.36 rows=1 width=89) (actual time=196.886..208.079 rows=779 loops=1)
  Hash Cond: (s.code = va.code)
  ->  Bitmap Heap Scan on stock_price s  (cost=20.61..3867.38 rows=1 width=29) (actual time=0.209..0.554 rows=779 loops=1)
        Recheck Cond: (date = '2023-02-20'::date)
        Filter: ((open > 0) AND (value > 0) AND (length(code) = 4))
        Rows Removed by Filter: 210
        Heap Blocks: exact=34
        ->  Bitmap Index Scan on idx_stock_price_date  (cost=0.00..20.60 rows=1090 width=0) (actual time=0.082..0.082 rows=1827 loops=1)
              Index Cond: (date = '2023-02-20'::date)
  ->  Hash  (cost=65830.40..65830.40 rows=1005 width=37) (actual time=196.635..207.098 rows=907 loops=1)
        Buckets: 1024  Batches: 1  Memory Usage: 49kB
        ->  Subquery Scan on va  (cost=65558.20..65830.40 rows=1005 width=37) (actual time=194.141..206.923 rows=907 loops=1)
              ->  Finalize GroupAggregate  (cost=65558.20..65820.35 rows=1005 width=37) (actual time=194.139..206.872 rows=907 loops=1)
                    Group Key: stock_price.code
                    InitPlan 1 (returns $0)
                      ->  Limit  (cost=0.53..0.58 rows=1 width=4) (actual time=0.117..0.117 rows=1 loops=1)
                            ->  Index Only Scan Backward using stock_date_pkey on stock_date  (cost=0.28..363.63 rows=7359 width=4) (actual time=0.114..0.116 rows=6 loops=1)
                                  Heap Fetches: 6
                    ->  Gather Merge  (cost=65557.62..65792.14 rows=2010 width=37) (actual time=194.123..205.341 rows=1992 loops=1)
                          Workers Planned: 2
                          Params Evaluated: $0
                          Workers Launched: 2
                          ->  Sort  (cost=64557.60..64560.11 rows=1005 width=37) (actual time=176.452..176.494 rows=664 loops=3)
                                Sort Key: stock_price.code
                                Sort Method: quicksort  Memory: 95kB
                                Worker 0:  Sort Method: quicksort  Memory: 43kB
                                Worker 1:  Sort Method: quicksort  Memory: 90kB
                                ->  Partial HashAggregate  (cost=64494.92..64507.48 rows=1005 width=37) (actual time=175.830..176.168 rows=664 loops=3)
                                      Group Key: stock_price.code
                                      Batches: 1  Memory Usage: 577kB
                                      Worker 0:  Batches: 1  Memory Usage: 193kB
                                      Worker 1:  Batches: 1  Memory Usage: 577kB
                                      ->  Parallel Seq Scan on stock_price  (cost=0.00..64038.54 rows=91275 width=13) (actual time=130.043..173.124 rows=1427 loops=3)
                                            Filter: ((value > 0) AND (date > $0))
                                            Rows Removed by Filter: 906975
Planning Time: 1.310 ms
Execution Time: 208.262 ms

pgsql-bugs by date:

Previous
From: "Hayato Kuroda (Fujitsu)"
Date:
Subject: RE: BUG #17789: process_pgfdw_appname() fails for autovacuum workers
Next
From: Charles
Date:
Subject: Re: Query run in 27s with 15.2 vs 37ms with 14.6