planner regression in 8.4 (from 8.1)

From: Ben Chobot <bench(at)silentmedia(dot)com>
To: pgsql-bugs(at)postgresql(dot)org
Subject: planner regression in 8.4 (from 8.1)
Date: 2010-02-17 18:06:55
Message-ID: EF524E81-B815-4122-A337-7E50BCED514E@silentmedia.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs

I have a query which performs much better on 8.1.19 than on 8.4.2, unless I add "offset 0" to the subqueries. I believe this is due to miscalculating the expected row count of nest loop joins. I cannot give you my data, but I can give you the query and the plans. Let me know if anything else would be helpful.

The query as I used it on 8.1:

SELECT SUM(machines.quota_purchased), license_type_id FROM sm_pro_keys, machines
WHERE NOT deleted AND sm_pro_keys.machine_id = machines.id AND
machines.quota_purchased > 0 AND machines.user_id IN
( SELECT id FROM users WHERE NOT deleted AND user_group_id IN
( SELECT id FROM user_groups WHERE pro_partner_id IN
( SELECT id FROM pro_partners WHERE tree_sortkey BETWEEN
'000000000000000110000000000000001111010011011010' AND
tree_right('000000000000000110000000000000001111010011011010') )
) ) GROUP BY license_type_id;

The modified query (the difference is the last line):

SELECT SUM(machines.quota_purchased), license_type_id FROM sm_pro_keys, machines
WHERE NOT deleted AND sm_pro_keys.machine_id = machines.id AND
machines.quota_purchased > 0 AND machines.user_id IN
( SELECT id FROM users WHERE NOT deleted AND user_group_id IN
( SELECT id FROM user_groups WHERE pro_partner_id IN
( SELECT id FROM pro_partners WHERE tree_sortkey BETWEEN
'000000000000000110000000000000001111010011011010' AND
tree_right('000000000000000110000000000000001111010011011010') )
) offset 0) GROUP BY license_type_id;

On 8.1, the plan looks like this:

HashAggregate (cost=23040.78..23040.79 rows=1 width=12) (actual time=36.642..36.643 rows=1 loops=1)
-> Nested Loop (cost=20911.79..23040.77 rows=1 width=12) (actual time=36.615..36.629 rows=1 loops=1)
-> Nested Loop (cost=20911.79..23036.81 rows=1 width=12) (actual time=36.272..36.285 rows=1 loops=1)
-> HashAggregate (cost=20911.79..20911.91 rows=12 width=4) (actual time=36.227..36.227 rows=1 loops=1)
-> Nested Loop (cost=10.44..20911.76 rows=12 width=4) (actual time=36.221..36.222 rows=1 loops=1)
-> HashAggregate (cost=10.44..10.45 rows=1 width=4) (actual time=36.073..36.073 rows=1 loops=1)
-> Nested Loop (cost=4.21..10.44 rows=1 width=4) (actual time=36.058..36.065 rows=1 loops=1)
-> HashAggregate (cost=4.21..4.22 rows=1 width=4) (actual time=0.141..0.142 rows=1 loops=1)
-> Index Scan using pro_partners_tree_sortkey_idx on pro_partners (cost=0.00..4.20 rows=1 width=4) (actual time=0.132..0.133 rows=1 loops=1)
Index Cond: ((tree_sortkey >= B'000000000000000110000000000000001111010011011010'::bit varying) AND (tree_sortkey <= B'00000000000000011000000000000000111101001101101011111111111111111111111111111111'::bit varying))
-> Index Scan using user_groups_pro_partner_id_idx on user_groups (cost=0.00..6.19 rows=3 width=8) (actual time=35.913..35.916 rows=1 loops=1)
Index Cond: (user_groups.pro_partner_id = "outer".id)
-> Index Scan using users_user_groups_idx on users (cost=0.00..20800.07 rows=8099 width=8) (actual time=0.142..0.143 rows=1 loops=1)
Index Cond: (users.user_group_id = "outer".id)
Filter: (NOT deleted)
-> Index Scan using machines_sid_un on machines (cost=0.00..177.01 rows=5 width=16) (actual time=0.042..0.055 rows=1 loops=1)
Index Cond: (machines.user_id = "outer".id)
Filter: (quota_purchased > 0)
-> Index Scan using sm_pro_keys_machine_id_idx on sm_pro_keys (cost=0.00..3.95 rows=1 width=8) (actual time=0.339..0.340 rows=1 loops=1)
Index Cond: (sm_pro_keys.machine_id = "outer".id)
Total runtime: 36.794 ms
(21 rows)
On 8.4, the unmodified query looks like this:

HashAggregate (cost=193503.37..193503.82 rows=36 width=12) (actual time=3389.899..3389.900 rows=1 loops=1)
-> Hash Semi Join (cost=178202.84..193475.12 rows=5649 width=12) (actual time=1612.034..3389.861 rows=1 loops=1)
Hash Cond: (machines.user_id = users.id)
-> Merge Join (cost=142309.11..148916.54 rows=5649 width=16) (actual time=1466.097..3317.794 rows=168536 loops=1)
Merge Cond: (sm_pro_keys.machine_id = machines.id)
-> Index Scan using sm_pro_keys_machine_id_idx on sm_pro_keys (cost=0.00..97619.86 rows=3086901 width=8) (actual time=0.059..1359.843 rows=3004929 loops=1)
-> Sort (cost=142290.93..142535.59 rows=97866 width=16) (actual time=1466.024..1502.852 rows=168970 loops=1)
Sort Key: machines.id
Sort Method: quicksort Memory: 14062kB
-> Seq Scan on machines (cost=0.00..134178.56 rows=97866 width=16) (actual time=0.058..1354.628 rows=168911 loops=1)
Filter: ((NOT deleted) AND (quota_purchased > 0))
-> Hash (cost=153.63..153.63 rows=2178408 width=4) (actual time=0.207..0.207 rows=1 loops=1)
-> Nested Loop (cost=4.58..153.63 rows=2178408 width=4) (actual time=0.203..0.204 rows=1 loops=1)
-> HashAggregate (cost=4.58..4.59 rows=1 width=4) (actual time=0.145..0.146 rows=1 loops=1)
-> Nested Loop (cost=2.28..4.57 rows=1 width=4) (actual time=0.142..0.143 rows=1 loops=1)
-> HashAggregate (cost=2.28..2.29 rows=1 width=4) (actual time=0.093..0.093 rows=1 loops=1)
-> Index Scan using pro_partners_tree_sortkey_idx on pro_partners (cost=0.00..2.28 rows=1 width=4) (actual time=0.076..0.076 rows=1 loops=1)
Index Cond: ((tree_sortkey >= B'000000000000000110000000000000001111010011011010'::bit varying) AND (tree_sortkey <= B'00000000000000011000000000000000111101001101101011111111111111111111111111111111'::bit varying))
-> Index Scan using user_groups_pro_partner_id_idx on user_groups (cost=0.00..2.27 rows=1 width=8) (actual time=0.046..0.047 rows=1 loops=1)
Index Cond: (user_groups.pro_partner_id = pro_partners.id)
-> Index Scan using users_user_groups_idx on users (cost=0.00..147.14 rows=152 width=8) (actual time=0.057..0.057 rows=1 loops=1)
Index Cond: (users.user_group_id = user_groups.id)
Filter: (NOT users.deleted)
Total runtime: 3391.269 ms
(24 rows)

Note the nested loop with 2 million expected rows, though its inner nodes are only expected to have 1 and 152 each.

The plan with the offset 0 clause looks like this:

HashAggregate (cost=28011.35..28011.50 rows=12 width=12) (actual time=0.158..0.158 rows=1 loops=1)
-> Nested Loop (cost=27741.68..28011.29 rows=12 width=12) (actual time=0.145..0.146 rows=1 loops=1)
-> Nested Loop (cost=27741.68..27837.74 rows=200 width=12) (actual time=0.129..0.130 rows=1 loops=1)
-> HashAggregate (cost=27741.68..27743.68 rows=200 width=4) (actual time=0.071..0.071 rows=1 loops=1)
-> Limit (cost=4.58..153.67 rows=2207041 width=4) (actual time=0.068..0.069 rows=1 loops=1)
-> Nested Loop (cost=4.58..153.67 rows=2207041 width=4) (actual time=0.068..0.069 rows=1 loops=1)
-> HashAggregate (cost=4.58..4.59 rows=1 width=4) (actual time=0.051..0.051 rows=1 loops=1)
-> Nested Loop (cost=2.28..4.57 rows=1 width=4) (actual time=0.048..0.049 rows=1 loops=1)
-> HashAggregate (cost=2.28..2.29 rows=1 width=4) (actual time=0.033..0.033 rows=1 loops=1)
-> Index Scan using pro_partners_tree_sortkey_idx on pro_partners (cost=0.00..2.28 rows=1 width=4) (actual time=0.018..0.018 rows=1 loops=1)
Index Cond: ((tree_sortkey >= B'000000000000000110000000000000001111010011011010'::bit varying) AND (tree_sortkey <= B'00000000000000011000000000000000111101001101101011111111111111111111111111111111'::bit varying))
-> Index Scan using user_groups_pro_partner_id_idx on user_groups (cost=0.00..2.27 rows=1 width=8) (actual time=0.014..0.014 rows=1 loops=1)
Index Cond: (user_groups.pro_partner_id = pro_partners.id)
-> Index Scan using users_user_groups_idx on users (cost=0.00..147.18 rows=152 width=8) (actual time=0.015..0.015 rows=1 loops=1)
Index Cond: (users.user_group_id = user_groups.id)
Filter: (NOT users.deleted)
-> Index Scan using machines_user_idx on machines (cost=0.00..0.46 rows=1 width=16) (actual time=0.057..0.058 rows=1 loops=1)
Index Cond: (machines.user_id = users.id)
Filter: ((NOT machines.deleted) AND (machines.quota_purchased > 0))
-> Index Scan using sm_pro_keys_machine_id_idx on sm_pro_keys (cost=0.00..0.86 rows=1 width=8) (actual time=0.014..0.014 rows=1 loops=1)
Index Cond: (sm_pro_keys.machine_id = machines.id)
Total runtime: 0.353 ms
(22 rows)

FWIW, I can get a similar execution speed in 8.4.2 by turning off hashjoins and mergejoins. The estimate for the nested loop is still way off, but at least the offset 0 is keeping the plan better.

Anyway, we have our workaround, but I just wanted to make sure this would get on a to-fix list. If I can provide anything else (you know, short of the data to actually make a helpful test case), let me know.

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message janandith jayawardena 2010-02-17 19:21:04 Re: BUG #5327: postgresql gives checksum error when upgrading 8.2.6 binaries to 8.2.14 in windows.
Previous Message Chris Travers 2010-02-17 17:41:29 Re: BUG #5331: Integer overflow in tmie counter