Re: Postgresql 13 query engine regression

From: Jonathan Chen <jonc(at)chen(dot)org(dot)nz>
To: pgsql-general(at)lists(dot)postgresql(dot)org
Subject: Re: Postgresql 13 query engine regression
Date: 2021-05-10 23:21:43
Message-ID: CAJuc1zP5NUaCHJmbYBru0CLY7axyMYjWyzn-PVphTM5A7jGFCw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: 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(at)github(dot)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(at)chen(dot)org(dot)nz>

In response to

Responses

Browse pgsql-general by date

  From Date Subject
Next Message Jonathan Chen 2021-05-10 23:33:55 Re: Postgresql 13 query engine regression
Previous Message Jonathan Chen 2021-05-10 22:55:34 Re: Postgresql 13 query engine regression