Hello,
We’re trying to debug a performance issue affecting our staging database, and
we’ve narrowed it down to a difference in the query optimizer in 9.5.2.
Upgrading to 9.5 is important for us because we need the ability to import
foreign schemas.
This is the query we’re running:
CREATE TEMP TABLE tmp_joined_transactions_9gkgptn5xcp9 ( transaction_id integer
PRIMARY KEY );
INSERT INTO tmp_joined_transactions_9gkgptn5xcp9 (transaction_id)
SELECT DISTINCT ON ("transactions_transaction"."id")
"transactions_transaction"."id"
FROM "transactions_transaction" , "tmp_joined_transactions_75chlsokrsev"
WHERE (NOT ("transactions_transaction"."id"
IN (SELECT U0."id" AS Col1
FROM "transactions_transaction" U0
LEFT OUTER JOIN "transactions_commission" U1
ON ( U0."id" = U1."transaction_id" )
WHERE U1."id" IS NULL))
AND "transactions_transaction"."date_created" >= '2010-01-01'::date
AND "transactions_transaction"."date_created" <= '2015-12-31'::date
AND "transactions_transaction"."deal_status" IN (1)
AND (transactions_transaction.id =
tmp_joined_transactions_75chlsokrsev.transaction_id))
ORDER BY "transactions_transaction"."id" ASC;
And this is the EXPLAIN ANALYZE output in 9.5.2:
Insert on tmp_joined_transactions_9gkgptn5xcp9 (cost=42111.29..42991.60 rows=1
width=4) (actual time=470236.029..470236.029 rows=0 loops=1)
-> Unique (cost=42111.29..42991.59 rows=1 width=4) (actual
time=1109.636..470222.609 rows=4652 loops=1)
-> Nested Loop (cost=42111.29..42991.59 rows=1 width=4) (actual
time=1109.635..470219.259 rows=4652 loops=1)
Join Filter: (transactions_transaction.id =
tmp_joined_transactions_75chlsokrsev.transaction_id)
Rows Removed by Join Filter: 1153472704
-> Index Only Scan using
tmp_joined_transactions_75chlsokrsev_pkey on
tmp_joined_transactions_75chlsokrsev (cost=0.28..224.61 rows=5355 width=4)
(actual time=0.016..4.829 rows=4652 loops=1)
Heap Fetches: 4652
-> Materialize (cost=42111.01..42686.66 rows=1 width=4) (actual
time=0.240..51.639 rows=247953 loops=4652)
-> Bitmap Heap Scan on transactions_transaction
(cost=42111.01..42686.65 rows=1 width=4) (actual time=1109.580..1238.034
rows=247953 loops=1)
Recheck Cond: ((date_created >= '2010-01-01'::date)
AND (date_created <= '2015-12-31'::date))
Filter: ((NOT (hashed SubPlan 1)) AND (deal_status =
1))
Rows Removed by Filter: 21068
Heap Blocks: exact=8073
-> Bitmap Index Scan on
transactions_transaction_c69e55a4 (cost=0.00..18.02 rows=161 width=0) (actual
time=20.153..20.153 rows=269021 loops=1)
Index Cond: ((date_created >=
'2010-01-01'::date) AND (date_created <= '2015-12-31'::date))
SubPlan 1
-> Hash Right Join (cost=8799.57..42092.98 rows=1
width=4) (actual time=852.012..1086.671 rows=3395 loops=1)
Hash Cond: (u1.transaction_id = u0.id)
Filter: (u1.id IS NULL)
Rows Removed by Filter: 995248
-> Seq Scan on transactions_commission u1
(cost=0.00..27020.63 rows=1039763 width=8) (actual time=0.003..221.750
rows=1039763 loops=1)
-> Hash (cost=8395.92..8395.92 rows=32292
width=4) (actual time=153.984..153.984 rows=272663 loops=1)
Buckets: 131072 (originally 32768)
Batches: 4 (originally 1) Memory Usage: 3425kB
-> Seq Scan on
transactions_transaction u0 (cost=0.00..8395.92 rows=32292 width=4) (actual
time=0.003..71.988 rows=272663 loops=1)
Planning time: 0.410 ms
Execution time: 470237.400 ms
And this is the EXPLAIN ANALYZE output in 9.4.5:
Insert on tmp_joined_transactions_9gkgptn5xcp9 (cost=88544.31..88576.62
rows=2154 width=4) (actual time=1356.065..1356.065 rows=0 loops=1)
-> Unique (cost=88544.31..88555.08 rows=2154 width=4) (actual
time=1347.480..1350.548 rows=4715 loops=1)
-> Sort (cost=88544.31..88549.70 rows=2154 width=4) (actual
time=1347.477..1348.432 rows=4715 loops=1)
Sort Key: transactions_transaction.id
Sort Method: quicksort Memory: 414kB
-> Hash Join (cost=72700.01..88425.06 rows=2154 width=4)
(actual time=1107.077..1345.650 rows=4715 loops=1)
Hash Cond: (transactions_transaction.id =
tmp_joined_transactions_75chlsokrsev.transaction_id)
-> Seq Scan on transactions_transaction
(cost=72565.61..87199.11 rows=122287 width=4) (actual time=1104.855..1269.783
rows=251736 loops=1)
Filter: ((NOT (hashed SubPlan 1)) AND (date_created
>= '2010-01-01'::date) AND (date_created <= '2015-12-31'::date) AND
(deal_status = 1))
Rows Removed by Filter: 34441
SubPlan 1
-> Hash Right Join (cost=16466.94..72565.61
rows=1 width=4) (actual time=887.763..1103.391 rows=3551 loops=1)
Hash Cond: (u1.transaction_id = u0.id)
Filter: (u1.id IS NULL)
Rows Removed by Filter: 1047414
-> Seq Scan on transactions_commission u1
(cost=0.00..28019.85 rows=1073685 width=8) (actual time=0.004..360.549
rows=1072675 loops=1)
-> Hash (cost=11771.75..11771.75
rows=286175 width=4) (actual time=167.675..167.675 rows=286177 loops=1)
Buckets: 16384 Batches: 4 Memory
Usage: 2528kB
-> Seq Scan on
transactions_transaction u0 (cost=0.00..11771.75 rows=286175 width=4) (actual
time=0.002..84.517 rows=286177 loops=1)
-> Hash (cost=71.40..71.40 rows=5040 width=4) (actual
time=2.202..2.202 rows=4715 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 166kB
-> Seq Scan on tmp_joined_transactions_75chlsokrsev
(cost=0.00..71.40 rows=5040 width=4) (actual time=0.009..0.983 rows=4715
loops=1)
Planning time: 0.448 ms
Execution time: 1356.648 ms
The query is slower in 9.5.2 by several orders of magnitude (1300 ms vs 470000
ms).
Does anyone know if there is a way to modify our query to guide the query
optimizer back in the right direction?
Thank you for your assistance,
Markus Erdmann
