Question about plan difference between 9.3 and 9.3.2
| От | Jeff Ross |
|---|---|
| Тема | Question about plan difference between 9.3 and 9.3.2 |
| Дата | |
| Msg-id | 52D96E38.6000601@openvistas.net обсуждение исходный текст |
| Ответы |
Re: Question about plan difference between 9.3 and 9.3.2
|
| Список | pgsql-general |
Hi all,
I had to move our production database to a new server with virtually identical hardware. At the same time I went to 9.3.2 from 9.3.
Queries on the old server (nirvana) run many magnitudes faster than on the new server (dukkha).
The two are configured the same except for the IP address to listen on.
Here's an example of the difference between the old and new.
_postgresql@nirvana:/var/postgresql $ psql wykids
psql (9.3.0)
Type "help" for help.
wykids=# explain analyze select pp_full_name from view_person where pp_id = 21058;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
Index Scan using people_pk on people (cost=0.29..8.37 rows=1 width=30) (actual time=0.101..0.107 rows=1 loops=1)
Index Cond: (pp_id = 21058)
Total runtime: 0.308 ms
(3 rows)
jross@dukkha:/var/www/stars/clearinghouse $ psql wykids
psql (9.3.2)
Type "help" for help.
jross@wykids dukkha# explain analyze select pp_full_name from view_person where pp_id = 21058;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Subquery Scan on view_person (cost=0.29..321.63 rows=1 width=32) (actual time=4.756..4.770 rows=1 loops=1)
-> Index Scan using people_pk on people (cost=0.29..321.58 rows=1 width=492) (actual time=4.747..4.753 rows=1 loops=1)
Index Cond: (pp_id = 21058)
SubPlan 1
-> Nested Loop Left Join (cost=0.57..16.73 rows=1 width=15) (actual time=0.107..0.107 rows=0 loops=1)
-> Index Scan using no_duplicate_people_ids on providers (cost=0.29..8.35 rows=1 width=4) (actual time=0.094..0.094 rows=0 loops=1)
Index Cond: (pv_people_id = people.pp_id)
Filter: ((pv_facility_id IS NOT NULL) AND ((pv_status)::text = 'Active'::text))
Rows Removed by Filter: 1
-> Index Scan using facilities_pkey on facilities (cost=0.28..8.34 rows=1 width=19) (never executed)
Index Cond: (providers.pv_facility_id = fc_facility_id)
SubPlan 2
-> Nested Loop Left Join (cost=0.57..16.73 rows=1 width=8) (actual time=0.021..0.021 rows=0 loops=1)
-> Index Scan using no_duplicate_people_ids on providers providers_1 (cost=0.29..8.35 rows=1 width=4) (actual time=0.012..0.012 rows=0 loops=1)
Index Cond: (pv_people_id = people.pp_id)
Filter: ((pv_facility_id IS NOT NULL) AND ((pv_status)::text = 'Active'::text))
Rows Removed by Filter: 1
-> Index Scan using facilities_pkey on facilities facilities_1 (cost=0.28..8.34 rows=1 width=12) (never executed)
Index Cond: (providers_1.pv_facility_id = fc_facility_id)
SubPlan 3
-> Nested Loop Left Join (cost=0.57..16.73 rows=1 width=3) (actual time=0.021..0.021 rows=0 loops=1)
-> Index Scan using no_duplicate_people_ids on providers providers_2 (cost=0.29..8.35 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=1)
Index Cond: (pv_people_id = people.pp_id)
Filter: ((pv_facility_id IS NOT NULL) AND ((pv_status)::text = 'Active'::text))
Rows Removed by Filter: 1
-> Index Scan using facilities_pkey on facilities facilities_2 (cost=0.28..8.34 rows=1 width=7) (never executed)
Index Cond: (providers_2.pv_facility_id = fc_facility_id)
SubPlan 4
-> Nested Loop Left Join (cost=0.57..16.73 rows=1 width=6) (actual time=0.020..0.020 rows=0 loops=1)
-> Index Scan using no_duplicate_people_ids on providers providers_3 (cost=0.29..8.35 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=1)
Index Cond: (pv_people_id = people.pp_id)
Filter: ((pv_facility_id IS NOT NULL) AND ((pv_status)::text = 'Active'::text))
Rows Removed by Filter: 1
-> Index Scan using facilities_pkey on facilities facilities_3 (cost=0.28..8.34 rows=1 width=10) (never executed)
Index Cond: (providers_3.pv_facility_id = fc_facility_id)
SubPlan 5
-> Index Only Scan using pne_no_duplicates on people_no_email (cost=0.14..4.20 rows=1 width=4) (actual time=0.017..0.017 rows=0 loops=1)
Index Cond: (pne_pp_id = people.pp_id)
Heap Fetches: 0
SubPlan 6
-> Index Only Scan using pne_no_duplicates on people_no_email people_no_email_1 (cost=0.14..4.20 rows=1 width=4) (actual time=0.007..0.007 rows=0 loops=1)
Index Cond: (pne_pp_id = people.pp_id)
Heap Fetches: 0
SubPlan 7
-> Aggregate (cost=46.62..46.67 rows=1 width=0) (actual time=0.079..0.082 rows=1 loops=1)
-> Index Scan using ck_people_id_idx on clearinghouse_checkout (cost=0.29..46.61 rows=1 width=0) (actual time=0.025..0.025 rows=0 loops=1)
Index Cond: (ck_people_id = people.pp_id)
Filter: ((ck_return_date IS NULL) AND (ck_due_date < ('now'::cstring)::date))
SubPlan 8
-> Sort (cost=8.34..8.35 rows=1 width=11) (actual time=0.182..0.182 rows=0 loops=1)
Sort Key: people_previous_last_name.ppln_date_recorded
Sort Method: quicksort Memory: 17kB
-> Index Scan using people_previous_last_name_ppln_pp_id_idx on people_previous_last_name (cost=0.28..8.33 rows=1 width=11) (actual time=0.034..0.034 rows=0 loops=1)
Index Cond: (ppln_pp_id = people.pp_id)
SubPlan 9
-> Index Scan using pp_race_cat_pp_id_idx on people_race_categories (cost=0.28..8.34 rows=1 width=4) (actual time=0.065..0.065 rows=0 loops=1)
Index Cond: (people.pp_id = pp_race_cat_pp_id)
Filter: (pp_race_cat_id = 1)
Rows Removed by Filter: 1
SubPlan 10
-> Index Scan using pp_race_cat_pp_id_idx on people_race_categories people_race_categories_1 (cost=0.28..8.34 rows=1 width=4) (actual time=0.014..0.014 rows=0 loops=1)
Index Cond: (people.pp_id = pp_race_cat_pp_id)
Filter: (pp_race_cat_id = 2)
Rows Removed by Filter: 1
SubPlan 11
-> Index Scan using pp_race_cat_pp_id_idx on people_race_categories people_race_categories_2 (cost=0.28..8.34 rows=1 width=4) (actual time=0.013..0.013 rows=0 loops=1)
Index Cond: (people.pp_id = pp_race_cat_pp_id)
Filter: (pp_race_cat_id = 3)
Rows Removed by Filter: 1
SubPlan 12
-> Index Scan using pp_race_cat_pp_id_idx on people_race_categories people_race_categories_3 (cost=0.28..8.34 rows=1 width=4) (actual time=0.013..0.013 rows=0 loops=1)
Index Cond: (people.pp_id = pp_race_cat_pp_id)
Filter: (pp_race_cat_id = 4)
Rows Removed by Filter: 1
SubPlan 13
-> Index Scan using pp_race_cat_pp_id_idx on people_race_categories people_race_categories_4 (cost=0.28..8.34 rows=1 width=4) (actual time=0.013..0.017 rows=1 loops=1)
Index Cond: (people.pp_id = pp_race_cat_pp_id)
Filter: (pp_race_cat_id = 5)
SubPlan 14
-> Index Scan using pp_ethnic_cat_pp_id_idx on people_ethnic_categories (cost=0.29..8.35 rows=1 width=4) (actual time=0.056..0.056 rows=0 loops=1)
Index Cond: (people.pp_id = pp_ethnic_cat_pp_id)
Filter: (pp_ethnic_cat_id = 1)
Rows Removed by Filter: 1
SubPlan 15
-> Index Scan using pp_ethnic_cat_pp_id_idx on people_ethnic_categories people_ethnic_categories_1 (cost=0.29..8.35 rows=1 width=4) (actual time=0.012..0.017 rows=1 loops=1)
Index Cond: (people.pp_id = pp_ethnic_cat_pp_id)
Filter: (pp_ethnic_cat_id = 2)
SubPlan 16
-> Hash Join (cost=8.39..12.29 rows=1 width=8) (actual time=0.228..0.522 rows=1 loops=1)
Hash Cond: (languages.lang_id = people_primary_language.ppl_lang_id)
-> Seq Scan on languages (cost=0.00..3.65 rows=53 width=12) (actual time=0.009..0.190 rows=53 loops=1)
-> Hash (cost=8.34..8.34 rows=1 width=4) (actual time=0.068..0.068 rows=1 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 1kB
-> Index Scan using ppl_pp_id_idx on people_primary_language (cost=0.28..8.34 rows=1 width=4) (actual time=0.048..0.053 rows=1 loops=1)
Index Cond: (people.pp_id = ppl_pp_id)
SubPlan 17
-> Hash Join (cost=8.26..12.16 rows=1 width=8) (actual time=0.109..0.109 rows=0 loops=1)
Hash Cond: (languages_1.lang_id = people_secondary_language.psl_lang_id)
-> Seq Scan on languages languages_1 (cost=0.00..3.65 rows=53 width=12) (actual time=0.006..0.006 rows=1 loops=1)
-> Hash (cost=8.21..8.21 rows=1 width=4) (actual time=0.028..0.028 rows=0 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 0kB
-> Index Scan using psl_pp_id_idx on people_secondary_language (cost=0.15..8.21 rows=1 width=4) (actual time=0.018..0.018 rows=0 loops=1)
Index Cond: (people.pp_id = psl_pp_id)
SubPlan 18
-> Limit (cost=4.80..4.81 rows=1 width=12) (actual time=0.145..0.145 rows=0 loops=1)
-> Sort (cost=4.80..4.81 rows=1 width=12) (actual time=0.137..0.137 rows=0 loops=1)
Sort Key: people_accreditation_categories.pp_acc_date_recorded
Sort Method: quicksort Memory: 17kB
-> Seq Scan on people_accreditation_categories (cost=0.00..4.79 rows=1 width=12) (actual time=0.030..0.030 rows=0 loops=1)
Filter: ((people.pp_id = pp_acc_pp_id) AND (pp_acc_cat_id = 1))
Rows Removed by Filter: 69
SubPlan 19
-> Limit (cost=4.80..4.81 rows=1 width=12) (actual time=0.071..0.071 rows=0 loops=1)
-> Sort (cost=4.80..4.81 rows=1 width=12) (actual time=0.063..0.063 rows=0 loops=1)
Sort Key: people_accreditation_categories_1.pp_acc_date_recorded
Sort Method: quicksort Memory: 17kB
-> Seq Scan on people_accreditation_categories people_accreditation_categories_1 (cost=0.00..4.79 rows=1 width=12) (actual time=0.027..0.027 rows=0 loops=1)
Filter: ((people.pp_id = pp_acc_pp_id) AND (pp_acc_cat_id = 2))
Rows Removed by Filter: 69
SubPlan 20
-> Index Only Scan using pla_pp_id_idx on people_locked_accounts (cost=0.14..4.20 rows=1 width=4) (actual time=0.010..0.010 rows=0 loops=1)
Index Cond: (pla_pp_id = people.pp_id)
Heap Fetches: 0
SubPlan 21
-> Index Scan using pla_pp_id_idx on people_locked_accounts people_locked_accounts_1 (cost=0.14..8.20 rows=1 width=34) (actual time=0.007..0.007 rows=0 loops=1)
Index Cond: (people.pp_id = pla_pp_id)
SubPlan 22
-> Index Scan using pla_pp_id_idx on people_locked_accounts people_locked_accounts_2 (cost=0.14..8.20 rows=1 width=4) (actual time=0.006..0.006 rows=0 loops=1)
Index Cond: (people.pp_id = pla_pp_id)
SubPlan 23
-> Index Scan using pla_pp_id_idx on people_locked_accounts people_locked_accounts_3 (cost=0.14..8.20 rows=1 width=5) (actual time=0.007..0.007 rows=0 loops=1)
Index Cond: (people.pp_id = pla_pp_id)
SubPlan 26
-> Result (cost=61.44..61.49 rows=1 width=0) (actual time=2.747..2.751 rows=1 loops=1)
InitPlan 25 (returns $29)
-> Nested Loop (cost=51.83..61.44 rows=1 width=66) (actual time=2.709..2.730 rows=1 loops=1)
InitPlan 24 (returns $28)
-> Aggregate (cost=51.50..51.55 rows=1 width=4) (actual time=2.574..2.577 rows=1 loops=1)
-> Function Scan on education (cost=0.25..50.25 rows=500 width=4) (actual time=2.507..2.535 rows=7 loops=1)
Filter: has_earned
Rows Removed by Filter: 2
-> Index Scan using pp_ed_cat_pp_id_idx on people_education_categories (cost=0.29..8.35 rows=1 width=55) (actual time=2.652..2.657 rows=1 loops=1)
Index Cond: (pp_ed_cat_pp_id = people.pp_id)
Filter: (pp_ed_cat_id = $28)
Rows Removed by Filter: 6
-> Seq Scan on education_categories (cost=0.00..1.47 rows=1 width=19) (actual time=0.011..0.016 rows=1 loops=1)
Filter: (ed_cat_id = $28)
Rows Removed by Filter: 8
Total runtime: 8.645 ms
(149 rows)
I asked about this on IRC and was told that there were a lot of planner improvements in 9.3.2 but this kind of slowdown can't be an improvement.
I ran the slow query through explain.depesz.com--the result is here.
http://explain.depesz.com/s/fiHh
More complex queries that run in a couple hundred ms on the old server are taking about 9 seconds to complete on the new server, and postgres is using 90+% of cpu for the entire time. I've vacuumed analyzed the new server but that didn't seem to make a difference.
Thanks for any insight!
Jeff Ross
I had to move our production database to a new server with virtually identical hardware. At the same time I went to 9.3.2 from 9.3.
Queries on the old server (nirvana) run many magnitudes faster than on the new server (dukkha).
The two are configured the same except for the IP address to listen on.
Here's an example of the difference between the old and new.
_postgresql@nirvana:/var/postgresql $ psql wykids
psql (9.3.0)
Type "help" for help.
wykids=# explain analyze select pp_full_name from view_person where pp_id = 21058;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
Index Scan using people_pk on people (cost=0.29..8.37 rows=1 width=30) (actual time=0.101..0.107 rows=1 loops=1)
Index Cond: (pp_id = 21058)
Total runtime: 0.308 ms
(3 rows)
jross@dukkha:/var/www/stars/clearinghouse $ psql wykids
psql (9.3.2)
Type "help" for help.
jross@wykids dukkha# explain analyze select pp_full_name from view_person where pp_id = 21058;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Subquery Scan on view_person (cost=0.29..321.63 rows=1 width=32) (actual time=4.756..4.770 rows=1 loops=1)
-> Index Scan using people_pk on people (cost=0.29..321.58 rows=1 width=492) (actual time=4.747..4.753 rows=1 loops=1)
Index Cond: (pp_id = 21058)
SubPlan 1
-> Nested Loop Left Join (cost=0.57..16.73 rows=1 width=15) (actual time=0.107..0.107 rows=0 loops=1)
-> Index Scan using no_duplicate_people_ids on providers (cost=0.29..8.35 rows=1 width=4) (actual time=0.094..0.094 rows=0 loops=1)
Index Cond: (pv_people_id = people.pp_id)
Filter: ((pv_facility_id IS NOT NULL) AND ((pv_status)::text = 'Active'::text))
Rows Removed by Filter: 1
-> Index Scan using facilities_pkey on facilities (cost=0.28..8.34 rows=1 width=19) (never executed)
Index Cond: (providers.pv_facility_id = fc_facility_id)
SubPlan 2
-> Nested Loop Left Join (cost=0.57..16.73 rows=1 width=8) (actual time=0.021..0.021 rows=0 loops=1)
-> Index Scan using no_duplicate_people_ids on providers providers_1 (cost=0.29..8.35 rows=1 width=4) (actual time=0.012..0.012 rows=0 loops=1)
Index Cond: (pv_people_id = people.pp_id)
Filter: ((pv_facility_id IS NOT NULL) AND ((pv_status)::text = 'Active'::text))
Rows Removed by Filter: 1
-> Index Scan using facilities_pkey on facilities facilities_1 (cost=0.28..8.34 rows=1 width=12) (never executed)
Index Cond: (providers_1.pv_facility_id = fc_facility_id)
SubPlan 3
-> Nested Loop Left Join (cost=0.57..16.73 rows=1 width=3) (actual time=0.021..0.021 rows=0 loops=1)
-> Index Scan using no_duplicate_people_ids on providers providers_2 (cost=0.29..8.35 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=1)
Index Cond: (pv_people_id = people.pp_id)
Filter: ((pv_facility_id IS NOT NULL) AND ((pv_status)::text = 'Active'::text))
Rows Removed by Filter: 1
-> Index Scan using facilities_pkey on facilities facilities_2 (cost=0.28..8.34 rows=1 width=7) (never executed)
Index Cond: (providers_2.pv_facility_id = fc_facility_id)
SubPlan 4
-> Nested Loop Left Join (cost=0.57..16.73 rows=1 width=6) (actual time=0.020..0.020 rows=0 loops=1)
-> Index Scan using no_duplicate_people_ids on providers providers_3 (cost=0.29..8.35 rows=1 width=4) (actual time=0.011..0.011 rows=0 loops=1)
Index Cond: (pv_people_id = people.pp_id)
Filter: ((pv_facility_id IS NOT NULL) AND ((pv_status)::text = 'Active'::text))
Rows Removed by Filter: 1
-> Index Scan using facilities_pkey on facilities facilities_3 (cost=0.28..8.34 rows=1 width=10) (never executed)
Index Cond: (providers_3.pv_facility_id = fc_facility_id)
SubPlan 5
-> Index Only Scan using pne_no_duplicates on people_no_email (cost=0.14..4.20 rows=1 width=4) (actual time=0.017..0.017 rows=0 loops=1)
Index Cond: (pne_pp_id = people.pp_id)
Heap Fetches: 0
SubPlan 6
-> Index Only Scan using pne_no_duplicates on people_no_email people_no_email_1 (cost=0.14..4.20 rows=1 width=4) (actual time=0.007..0.007 rows=0 loops=1)
Index Cond: (pne_pp_id = people.pp_id)
Heap Fetches: 0
SubPlan 7
-> Aggregate (cost=46.62..46.67 rows=1 width=0) (actual time=0.079..0.082 rows=1 loops=1)
-> Index Scan using ck_people_id_idx on clearinghouse_checkout (cost=0.29..46.61 rows=1 width=0) (actual time=0.025..0.025 rows=0 loops=1)
Index Cond: (ck_people_id = people.pp_id)
Filter: ((ck_return_date IS NULL) AND (ck_due_date < ('now'::cstring)::date))
SubPlan 8
-> Sort (cost=8.34..8.35 rows=1 width=11) (actual time=0.182..0.182 rows=0 loops=1)
Sort Key: people_previous_last_name.ppln_date_recorded
Sort Method: quicksort Memory: 17kB
-> Index Scan using people_previous_last_name_ppln_pp_id_idx on people_previous_last_name (cost=0.28..8.33 rows=1 width=11) (actual time=0.034..0.034 rows=0 loops=1)
Index Cond: (ppln_pp_id = people.pp_id)
SubPlan 9
-> Index Scan using pp_race_cat_pp_id_idx on people_race_categories (cost=0.28..8.34 rows=1 width=4) (actual time=0.065..0.065 rows=0 loops=1)
Index Cond: (people.pp_id = pp_race_cat_pp_id)
Filter: (pp_race_cat_id = 1)
Rows Removed by Filter: 1
SubPlan 10
-> Index Scan using pp_race_cat_pp_id_idx on people_race_categories people_race_categories_1 (cost=0.28..8.34 rows=1 width=4) (actual time=0.014..0.014 rows=0 loops=1)
Index Cond: (people.pp_id = pp_race_cat_pp_id)
Filter: (pp_race_cat_id = 2)
Rows Removed by Filter: 1
SubPlan 11
-> Index Scan using pp_race_cat_pp_id_idx on people_race_categories people_race_categories_2 (cost=0.28..8.34 rows=1 width=4) (actual time=0.013..0.013 rows=0 loops=1)
Index Cond: (people.pp_id = pp_race_cat_pp_id)
Filter: (pp_race_cat_id = 3)
Rows Removed by Filter: 1
SubPlan 12
-> Index Scan using pp_race_cat_pp_id_idx on people_race_categories people_race_categories_3 (cost=0.28..8.34 rows=1 width=4) (actual time=0.013..0.013 rows=0 loops=1)
Index Cond: (people.pp_id = pp_race_cat_pp_id)
Filter: (pp_race_cat_id = 4)
Rows Removed by Filter: 1
SubPlan 13
-> Index Scan using pp_race_cat_pp_id_idx on people_race_categories people_race_categories_4 (cost=0.28..8.34 rows=1 width=4) (actual time=0.013..0.017 rows=1 loops=1)
Index Cond: (people.pp_id = pp_race_cat_pp_id)
Filter: (pp_race_cat_id = 5)
SubPlan 14
-> Index Scan using pp_ethnic_cat_pp_id_idx on people_ethnic_categories (cost=0.29..8.35 rows=1 width=4) (actual time=0.056..0.056 rows=0 loops=1)
Index Cond: (people.pp_id = pp_ethnic_cat_pp_id)
Filter: (pp_ethnic_cat_id = 1)
Rows Removed by Filter: 1
SubPlan 15
-> Index Scan using pp_ethnic_cat_pp_id_idx on people_ethnic_categories people_ethnic_categories_1 (cost=0.29..8.35 rows=1 width=4) (actual time=0.012..0.017 rows=1 loops=1)
Index Cond: (people.pp_id = pp_ethnic_cat_pp_id)
Filter: (pp_ethnic_cat_id = 2)
SubPlan 16
-> Hash Join (cost=8.39..12.29 rows=1 width=8) (actual time=0.228..0.522 rows=1 loops=1)
Hash Cond: (languages.lang_id = people_primary_language.ppl_lang_id)
-> Seq Scan on languages (cost=0.00..3.65 rows=53 width=12) (actual time=0.009..0.190 rows=53 loops=1)
-> Hash (cost=8.34..8.34 rows=1 width=4) (actual time=0.068..0.068 rows=1 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 1kB
-> Index Scan using ppl_pp_id_idx on people_primary_language (cost=0.28..8.34 rows=1 width=4) (actual time=0.048..0.053 rows=1 loops=1)
Index Cond: (people.pp_id = ppl_pp_id)
SubPlan 17
-> Hash Join (cost=8.26..12.16 rows=1 width=8) (actual time=0.109..0.109 rows=0 loops=1)
Hash Cond: (languages_1.lang_id = people_secondary_language.psl_lang_id)
-> Seq Scan on languages languages_1 (cost=0.00..3.65 rows=53 width=12) (actual time=0.006..0.006 rows=1 loops=1)
-> Hash (cost=8.21..8.21 rows=1 width=4) (actual time=0.028..0.028 rows=0 loops=1)
Buckets: 1024 Batches: 1 Memory Usage: 0kB
-> Index Scan using psl_pp_id_idx on people_secondary_language (cost=0.15..8.21 rows=1 width=4) (actual time=0.018..0.018 rows=0 loops=1)
Index Cond: (people.pp_id = psl_pp_id)
SubPlan 18
-> Limit (cost=4.80..4.81 rows=1 width=12) (actual time=0.145..0.145 rows=0 loops=1)
-> Sort (cost=4.80..4.81 rows=1 width=12) (actual time=0.137..0.137 rows=0 loops=1)
Sort Key: people_accreditation_categories.pp_acc_date_recorded
Sort Method: quicksort Memory: 17kB
-> Seq Scan on people_accreditation_categories (cost=0.00..4.79 rows=1 width=12) (actual time=0.030..0.030 rows=0 loops=1)
Filter: ((people.pp_id = pp_acc_pp_id) AND (pp_acc_cat_id = 1))
Rows Removed by Filter: 69
SubPlan 19
-> Limit (cost=4.80..4.81 rows=1 width=12) (actual time=0.071..0.071 rows=0 loops=1)
-> Sort (cost=4.80..4.81 rows=1 width=12) (actual time=0.063..0.063 rows=0 loops=1)
Sort Key: people_accreditation_categories_1.pp_acc_date_recorded
Sort Method: quicksort Memory: 17kB
-> Seq Scan on people_accreditation_categories people_accreditation_categories_1 (cost=0.00..4.79 rows=1 width=12) (actual time=0.027..0.027 rows=0 loops=1)
Filter: ((people.pp_id = pp_acc_pp_id) AND (pp_acc_cat_id = 2))
Rows Removed by Filter: 69
SubPlan 20
-> Index Only Scan using pla_pp_id_idx on people_locked_accounts (cost=0.14..4.20 rows=1 width=4) (actual time=0.010..0.010 rows=0 loops=1)
Index Cond: (pla_pp_id = people.pp_id)
Heap Fetches: 0
SubPlan 21
-> Index Scan using pla_pp_id_idx on people_locked_accounts people_locked_accounts_1 (cost=0.14..8.20 rows=1 width=34) (actual time=0.007..0.007 rows=0 loops=1)
Index Cond: (people.pp_id = pla_pp_id)
SubPlan 22
-> Index Scan using pla_pp_id_idx on people_locked_accounts people_locked_accounts_2 (cost=0.14..8.20 rows=1 width=4) (actual time=0.006..0.006 rows=0 loops=1)
Index Cond: (people.pp_id = pla_pp_id)
SubPlan 23
-> Index Scan using pla_pp_id_idx on people_locked_accounts people_locked_accounts_3 (cost=0.14..8.20 rows=1 width=5) (actual time=0.007..0.007 rows=0 loops=1)
Index Cond: (people.pp_id = pla_pp_id)
SubPlan 26
-> Result (cost=61.44..61.49 rows=1 width=0) (actual time=2.747..2.751 rows=1 loops=1)
InitPlan 25 (returns $29)
-> Nested Loop (cost=51.83..61.44 rows=1 width=66) (actual time=2.709..2.730 rows=1 loops=1)
InitPlan 24 (returns $28)
-> Aggregate (cost=51.50..51.55 rows=1 width=4) (actual time=2.574..2.577 rows=1 loops=1)
-> Function Scan on education (cost=0.25..50.25 rows=500 width=4) (actual time=2.507..2.535 rows=7 loops=1)
Filter: has_earned
Rows Removed by Filter: 2
-> Index Scan using pp_ed_cat_pp_id_idx on people_education_categories (cost=0.29..8.35 rows=1 width=55) (actual time=2.652..2.657 rows=1 loops=1)
Index Cond: (pp_ed_cat_pp_id = people.pp_id)
Filter: (pp_ed_cat_id = $28)
Rows Removed by Filter: 6
-> Seq Scan on education_categories (cost=0.00..1.47 rows=1 width=19) (actual time=0.011..0.016 rows=1 loops=1)
Filter: (ed_cat_id = $28)
Rows Removed by Filter: 8
Total runtime: 8.645 ms
(149 rows)
I asked about this on IRC and was told that there were a lot of planner improvements in 9.3.2 but this kind of slowdown can't be an improvement.
I ran the slow query through explain.depesz.com--the result is here.
http://explain.depesz.com/s/fiHh
More complex queries that run in a couple hundred ms on the old server are taking about 9 seconds to complete on the new server, and postgres is using 90+% of cpu for the entire time. I've vacuumed analyzed the new server but that didn't seem to make a difference.
Thanks for any insight!
Jeff Ross
В списке pgsql-general по дате отправления: