Re: Postgresql 13 query engine regression - Mailing list pgsql-general

From Jonathan Chen
Subject Re: Postgresql 13 query engine regression
Date
Msg-id CAJuc1zP5NUaCHJmbYBru0CLY7axyMYjWyzn-PVphTM5A7jGFCw@mail.gmail.com
Whole thread Raw
In response to Postgresql 13 query engine regression  (Jonathan Chen <jonc@chen.org.nz>)
Responses Re: Postgresql 13 query engine regression
List pgsql-general
Hi,

Here's a bit more detail:
select version();

        version

---------------------------------------------------------------------------------------------------------------------------------------------------------------------
 PostgreSQL 13.2 on amd64-portbld-freebsd12.2, compiled by FreeBSD
clang version 10.0.1 (git@github.com:llvm/llvm-project.git
llvmorg-10.0.1-0-gef32c611aa2), 64-bit

For reference, the query is (this is generated by the Odoo ORM, with
all its redundant bits):
SELECT "account_bank_statement_line".id
FROM "account_bank_statement_line"
LEFT JOIN "account_move" AS "account_bank_statement_line__move_id"
  ON ("account_bank_statement_line"."move_id" =
"account_bank_statement_line__move_id"."id")
WHERE
(
  ("account_bank_statement_line"."move_id" in
    (
      SELECT "account_move".id
      FROM "account_move"
      WHERE ("account_move"."state" = 'posted')
      AND ("account_move"."company_id" IS NULL  OR
("account_move"."company_id" in (1)))
      ORDER BY  "account_move"."id"
    )
  )
  AND ("account_bank_statement_line__move_id"."journal_id" = 29)
)
order by "account_bank_statement_line__move_id"."date" DESC,
"account_bank_statement_line"."id" DESC LIMIT 1;

Query plan:
 Limit  (cost=14226.75..15563.99 rows=1 width=8) (actual
time=129162.351..129162.409 rows=0 loops=1)
   Buffers: shared hit=97340
   ->  Nested Loop Semi Join  (cost=14226.75..6134771.07 rows=4577
width=8) (actual time=129162.350..129162.408 rows=0 loops=1)
         Join Filter: (account_bank_statement_line.move_id = account_move.id)
         Rows Removed by Join Filter: 1198285616
         Buffers: shared hit=97340
         ->  Gather Merge  (cost=1010.15..20911.67 rows=4577 width=16)
(actual time=3.596..24.065 rows=13453 loops=1)
               Workers Planned: 1
               Workers Launched: 1
               Buffers: shared hit=93061
               ->  Incremental Sort  (cost=10.14..19396.75 rows=2692
width=16) (actual time=0.669..34.507 rows=6726 loops=2)
                     Sort Key:
account_bank_statement_line__move_id.date DESC,
account_bank_statement_line.id DESC
                     Presorted Key: account_bank_statement_line__move_id.date
                     Full-sort Groups: 29  Sort Method: quicksort
Average Memory: 27kB  Peak Memory: 27kB
                     Pre-sorted Groups: 17  Sort Method: quicksort
Average Memory: 30kB  Peak Memory: 30kB
                     Buffers: shared hit=93061
                     Worker 0:  Full-sort Groups: 185  Sort Method:
quicksort  Average Memory: 28kB  Peak Memory: 28kB
                       Pre-sorted Groups: 56  Sort Method: quicksort
Average Memory: 28kB  Peak Memory: 28kB
                     ->  Nested Loop  (cost=0.58..19299.09 rows=2692
width=16) (actual time=0.284..31.917 rows=6726 loops=2)
                           Buffers: shared hit=92996
                           ->  Parallel Index Scan Backward using
account_move_date_index on account_move
account_bank_statement_line__move_id  (cost=0.29..13152.37 rows=16040
width=8) (actual time=0.271..14.465 rows=13556 loops=2)
                                 Filter: (journal_id = 29)
                                 Rows Removed by Filter: 40958
                                 Buffers: shared hit=25318
                           ->  Index Scan using
account_bank_statement_line_move_id_idx on account_bank_statement_line
 (cost=0.29..0.37 rows=1 width=8) (actual time=0.001..0.001 rows=0
loops=27112)
                                 Index Cond: (move_id =
account_bank_statement_line__move_id.id)
                                 Buffers: shared hit=67678
         ->  Materialize  (cost=13216.60..14771.30 rows=88840 width=4)
(actual time=0.003..3.716 rows=89072 loops=13453)
               Buffers: shared hit=4279
               ->  Sort  (cost=13216.60..13438.70 rows=88840 width=4)
(actual time=35.560..39.472 rows=89072 loops=1)
                     Sort Key: account_move.id
                     Sort Method: quicksort  Memory: 6906kB
                     Buffers: shared hit=4279
                     ->  Seq Scan on account_move  (cost=0.00..5914.43
rows=88840 width=4) (actual time=0.007..21.195 rows=89072 loops=1)
                           Filter: (((company_id IS NULL) OR
(company_id = 1)) AND ((state)::text = 'posted'::text))
                           Rows Removed by Filter: 19957
                           Buffers: shared hit=4279
 Planning:
   Buffers: shared hit=83
 Planning Time: 0.708 ms
 Execution Time: 129162.830 ms

If I remove the "LIMIT 1", the Query plan changes to:
 Sort  (cost=21589.50..21600.94 rows=4577 width=8) (actual
time=46.266..46.269 rows=0 loops=1)
   Sort Key: account_bank_statement_line__move_id.date DESC,
account_bank_statement_line.id DESC
   Sort Method: quicksort  Memory: 25kB
   Buffers: shared hit=4390
   ->  Hash Join  (cost=16543.33..21311.21 rows=4577 width=8) (actual
time=46.263..46.266 rows=0 loops=1)
         Hash Cond: (account_bank_statement_line__move_id.id =
account_bank_statement_line.move_id)
         Buffers: shared hit=4390
         ->  Bitmap Heap Scan on account_move
account_bank_statement_line__move_id  (cost=635.74..5255.59 rows=27268
width=8) (actual time=1.258..1.259 rows=1 loops=1)
               Recheck Cond: (journal_id = 29)
               Heap Blocks: exact=1
               Buffers: shared hit=108
               ->  Bitmap Index Scan on account_move_sequence_index2
(cost=0.00..628.93 rows=27268 width=0) (actual time=1.125..1.125
rows=27112 loops=1)
                     Index Cond: (journal_id = 29)
                     Buffers: shared hit=107
         ->  Hash  (cost=15678.84..15678.84 rows=18300 width=12)
(actual time=44.992..44.994 rows=0 loops=1)
               Buckets: 32768  Batches: 1  Memory Usage: 256kB
               Buffers: shared hit=4282
               ->  Merge Semi Join  (cost=14323.71..15678.84
rows=18300 width=12) (actual time=44.991..44.992 rows=0 loops=1)
                     Merge Cond: (account_bank_statement_line.move_id
= account_move.id)
                     Buffers: shared hit=4282
                     ->  Index Scan using
account_bank_statement_line_move_id_idx on account_bank_statement_line
 (cost=0.29..901.45 rows=18300 width=8) (actual time=0.004..0.004
rows=1 loops=1)
                           Buffers: shared hit=3
                     ->  Sort  (cost=13216.60..13438.70 rows=88840
width=4) (actual time=35.261..39.169 rows=89072 loops=1)
                           Sort Key: account_move.id
                           Sort Method: quicksort  Memory: 6906kB
                           Buffers: shared hit=4279
                           ->  Seq Scan on account_move
(cost=0.00..5914.43 rows=88840 width=4) (actual time=0.006..20.668
rows=89072 loops=1)
                                 Filter: (((company_id IS NULL) OR
(company_id = 1)) AND ((state)::text = 'posted'::text))
                                 Rows Removed by Filter: 19957
                                 Buffers: shared hit=4279
 Planning:
   Buffers: shared hit=40
 Planning Time: 0.471 ms
 Execution Time: 46.321 ms

For comparison, the original query on Postgresql 12:
 select version();
                                                version
--------------------------------------------------------------------------------------------------------
 PostgreSQL 12.2 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.3
20140911 (Red Hat 4.8.3-9), 64-bit

The query plan result is:
 Limit  (cost=21228.94..21228.94 rows=1 width=8) (actual
time=75.172..75.172 rows=0 loops=1)
   Buffers: shared hit=10127, temp read=153 written=154
   ->  Sort  (cost=21228.94..21240.31 rows=4547 width=8) (actual
time=75.171..75.171 rows=0 loops=1)
         Sort Key: account_bank_statement_line__move_id.date DESC,
account_bank_statement_line.id DESC
         Sort Method: quicksort  Memory: 25kB
         Buffers: shared hit=10127, temp read=153 written=154
         ->  Hash Join  (cost=16505.50..21206.20 rows=4547 width=8)
(actual time=75.167..75.168 rows=0 loops=1)
               Hash Cond: (account_bank_statement_line__move_id.id =
account_bank_statement_line.move_id)
               Buffers: shared hit=10127, temp read=153 written=154
               ->  Bitmap Heap Scan on account_move
account_bank_statement_line__move_id  (cost=629.42..5183.52 rows=26968
width=8) (actual time=1.253..5.304 rows=27166 loops=1)
                     Recheck Cond: (journal_id = 29)
                     Heap Blocks: exact=1337
                     Buffers: shared hit=1444
                     ->  Bitmap Index Scan on
account_move_sequence_index2  (cost=0.00..622.68 rows=26968 width=0)
(actual time=1.116..1.116 rows=27166 loops=1)
                           Index Cond: (journal_id = 29)
                           Buffers: shared hit=107
               ->  Hash  (cost=15646.27..15646.27 rows=18385 width=12)
(actual time=66.937..66.937 rows=1 loops=1)
                     Buckets: 32768  Batches: 1  Memory Usage: 257kB
                     Buffers: shared hit=8683, temp read=153 written=154
                     ->  Merge Semi Join  (cost=14283.78..15646.27
rows=18385 width=12) (actual time=66.896..66.933 rows=1 loops=1)
                           Merge Cond:
(account_bank_statement_line.move_id = account_move.id)
                           Buffers: shared hit=8683, temp read=153 written=154
                           ->  Index Scan using
account_bank_statement_line_move_id_idx on account_bank_statement_line
 (cost=0.29..907.70 rows=18385 width=8) (actual time=0.009..3.437
rows=18385 loops=1)
                                 Buffers: shared hit=4466
                           ->  Sort  (cost=13173.22..13395.83
rows=89045 width=4) (actual time=45.424..53.377 rows=89103 loops=1)
                                 Sort Key: account_move.id
                                 Sort Method: external merge  Disk: 1224kB
                                 Buffers: shared hit=4217, temp
read=153 written=154
                                 ->  Seq Scan on account_move
(cost=0.00..5852.72 rows=89045 width=4) (actual time=0.007..23.127
rows=89108 loops=1)
                                       Filter: (((company_id IS NULL)
OR (company_id = 1)) AND ((state)::text = 'posted'::text))
                                       Rows Removed by Filter: 19940
                                       Buffers: shared hit=4217
 Planning Time: 0.495 ms
 Execution Time: 75.544 ms
-- 
Jonathan Chen <jonc@chen.org.nz>



pgsql-general by date:

Previous
From: Jonathan Chen
Date:
Subject: Re: Postgresql 13 query engine regression
Next
From: Jonathan Chen
Date:
Subject: Re: Postgresql 13 query engine regression