Incorrect estimates on columns - Mailing list pgsql-performance
From | Chris Kratz |
---|---|
Subject | Incorrect estimates on columns |
Date | |
Msg-id | 200710171334.24526.chris.kratz@vistashare.com Whole thread Raw |
Responses |
Re: Incorrect estimates on columns
Re: Incorrect estimates on columns |
List | pgsql-performance |
Hello Everyone, I'm struggling to get postgres to run a particular query quickly. It seems that very early on, the planner seems to mis-estimatethe number of rows returned by a join which causes it to assume that there is only 1 row as it goes up the tree. It then picks a nested loop join which seems to cause the whole query to be slow. Or at least if I turn off nestloop,it runs in 216ms. explain analyze SELECT 1 FROM rpt_agencyquestioncache_171_0 par right outer join namemaster dem on (par.nameid = dem.nameid and dem.programid = 171) right join activity_parentid_view ses on (par.activity = ses.activityid and ses.programid=171) left join ( select ct0.inter_agency_id,ct0.nameid from rpt_agencyquestioncache_171_0 ct0 join rpt_agencyquestioncache_171_2 ct2 on ct2.participantid =ct0.participantid ) as par30232 on (dem.nameid=par30232.nameid and par30232.inter_agency_id=30232) WHERE ( ( (par.provider_lfm) ='Child Guidance Treatment Centers Inc.')) QUERY PLAN ---------------------------------------------------------------------------------------------------------------------------------------------------------------------- Nested Loop Left Join (cost=1990.12..5666.92 rows=1 width=0) (actual time=82.185..91511.455 rows=1199 loops=1) Join Filter: (dem.nameid = ct0.nameid) -> Nested Loop Left Join (cost=45.92..1324.06 rows=1 width=4) (actual time=0.973..74.206 rows=1199 loops=1) -> Nested Loop (cost=45.92..1323.33 rows=1 width=8) (actual time=0.964..61.264 rows=1199 loops=1) -> Hash Join (cost=45.92..1251.07 rows=21 width=8) (actual time=0.948..10.439 rows=1199 loops=1) Hash Cond: (par.activity = a.activityid) -> Bitmap Heap Scan on rpt_agencyquestioncache_171_0 par (cost=21.92..1222.19 rows=1247 width=8) (actualtime=0.415..3.081 rows=1199 loops=1) Recheck Cond: (provider_lfm = 'Child Guidance Treatment Centers Inc.'::text) -> Bitmap Index Scan on rpt_aqc_45604_provider_lfm (cost=0.00..21.61 rows=1247 width=0) (actualtime=0.394..0.394 rows=1199 loops=1) Index Cond: (provider_lfm = 'Child Guidance Treatment Centers Inc.'::text) -> Hash (cost=19.21..19.21 rows=383 width=4) (actual time=0.513..0.513 rows=383 loops=1) -> Index Scan using activity_programid_idx on activity a (cost=0.00..19.21 rows=383 width=4)(actual time=0.034..0.307 rows=383 loops=1) Index Cond: (programid = 171) -> Index Scan using nameid_pk on namemaster dem (cost=0.00..3.43 rows=1 width=4) (actual time=0.023..0.036rows=1 loops=1199) Index Cond: (par.nameid = dem.nameid) Filter: (programid = 171) -> Index Scan using activity_session_session_idx on activity_session s (cost=0.00..0.72 rows=1 width=4) (actualtime=0.007..0.007 rows=0 loops=1199) Index Cond: (a.activityid = s."session") -> Hash Join (cost=1944.20..4292.49 rows=4029 width=4) (actual time=59.732..74.897 rows=4130 loops=1199) Hash Cond: (ct2.participantid = ct0.participantid) -> Seq Scan on rpt_agencyquestioncache_171_2 ct2 (cost=0.00..1747.00 rows=74800 width=4) (actual time=0.008..28.442rows=74800 loops=1199) -> Hash (cost=1893.84..1893.84 rows=4029 width=8) (actual time=5.578..5.578 rows=4130 loops=1) -> Bitmap Heap Scan on rpt_agencyquestioncache_171_0 ct0 (cost=55.48..1893.84 rows=4029 width=8) (actualtime=0.625..3.714 rows=4130 loops=1) Recheck Cond: (inter_agency_id = 30232) -> Bitmap Index Scan on rpt_aqc_45604_inter_agency_id (cost=0.00..54.47 rows=4029 width=0) (actualtime=0.609..0.609 rows=4130 loops=1) Index Cond: (inter_agency_id = 30232) Total runtime: 91514.109 ms (27 rows) I've increased statistics to 100 of all pertinent columns in the query to no effect. I've vacuumed and all analyzed all tables in question. Autovac is on. Settings of interest in postgresql.conf: shared_buffers = 1024MB work_mem = 256MB maintenance_work_mem = 256MB random_page_cost = 2.0 PG version: 8.2.4 Server Mem: 2G Ram If I reduce random_page_cost to 1.0, I get the following query plan. QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Nested Loop Left Join (cost=20.87..4377.13 rows=1 width=0) (actual time=146.402..29585.011 rows=1199 loops=1) -> Nested Loop Left Join (cost=20.87..4376.62 rows=1 width=4) (actual time=146.287..29572.257 rows=1199 loops=1) Join Filter: (dem.nameid = ct0.nameid) -> Nested Loop (cost=20.87..857.70 rows=1 width=8) (actual time=1.676..53.423 rows=1199 loops=1) -> Hash Join (cost=20.87..818.60 rows=21 width=8) (actual time=1.514..17.276 rows=1199 loops=1) Hash Cond: (par.activity = a.activityid) -> Index Scan using rpt_aqc_45604_provider_lfm on rpt_agencyquestioncache_171_0 par (cost=0.00..792.85rows=1247 width=8) (actual time=0.293..9.976 rows=1199 loops=1) Index Cond: (provider_lfm = 'Child Guidance Treatment Centers Inc.'::text) -> Hash (cost=16.08..16.08 rows=383 width=4) (actual time=0.940..0.940 rows=383 loops=1) -> Index Scan using activity_programid_idx on activity a (cost=0.00..16.08 rows=383 width=4)(actual time=0.135..0.676 rows=383 loops=1) Index Cond: (programid = 171) -> Index Scan using nameid_pk on namemaster dem (cost=0.00..1.85 rows=1 width=4) (actual time=0.024..0.026rows=1 loops=1199) Index Cond: (par.nameid = dem.nameid) Filter: (programid = 171) -> Nested Loop (cost=0.00..3468.56 rows=4029 width=4) (actual time=0.087..23.199 rows=4130 loops=1199) -> Index Scan using rpt_aqc_45604_inter_agency_id on rpt_agencyquestioncache_171_0 ct0 (cost=0.00..1126.10rows=4029 width=8) (actual time=0.019..2.517 rows=4130 loops=1199) Index Cond: (inter_agency_id = 30232) -> Index Scan using rpt_aqc_45606_participantid on rpt_agencyquestioncache_171_2 ct2 (cost=0.00..0.57 rows=1width=4) (actual time=0.003..0.003 rows=1 loops=4951870) Index Cond: (ct2.participantid = ct0.participantid) -> Index Scan using activity_session_session_idx on activity_session s (cost=0.00..0.49 rows=1 width=4) (actual time=0.007..0.007rows=0 loops=1199) Index Cond: (a.activityid = s."session") Total runtime: 29587.932 ms (22 rows) With nestloop off I get the following query plan: set enable_nestloop=false; QUERY PLAN ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Hash Left Join (cost=6393.91..7603.11 rows=1 width=0) (actual time=210.324..215.785 rows=1199 loops=1) Hash Cond: (a.activityid = s."session") -> Hash Left Join (cost=6130.14..7339.01 rows=1 width=4) (actual time=175.072..179.623 rows=1199 loops=1) Hash Cond: (dem.nameid = ct0.nameid) -> Hash Join (cost=1787.29..2992.69 rows=1 width=8) (actual time=92.812..96.361 rows=1199 loops=1) Hash Cond: (par.nameid = dem.nameid) -> Hash Join (cost=45.92..1251.07 rows=21 width=8) (actual time=1.046..3.148 rows=1199 loops=1) Hash Cond: (par.activity = a.activityid) -> Bitmap Heap Scan on rpt_agencyquestioncache_171_0 par (cost=21.92..1222.19 rows=1247 width=8) (actualtime=0.453..1.126 rows=1199 loops=1) Recheck Cond: (provider_lfm = 'Child Guidance Treatment Centers Inc.'::text) -> Bitmap Index Scan on rpt_aqc_45604_provider_lfm (cost=0.00..21.61 rows=1247 width=0) (actualtime=0.433..0.433 rows=1199 loops=1) Index Cond: (provider_lfm = 'Child Guidance Treatment Centers Inc.'::text) -> Hash (cost=19.21..19.21 rows=383 width=4) (actual time=0.566..0.566 rows=383 loops=1) -> Index Scan using activity_programid_idx on activity a (cost=0.00..19.21 rows=383 width=4)(actual time=0.035..0.303 rows=383 loops=1) Index Cond: (programid = 171) -> Hash (cost=1551.74..1551.74 rows=15170 width=4) (actual time=91.725..91.725 rows=15575 loops=1) -> Index Scan using namemaster_programid_idx on namemaster dem (cost=0.00..1551.74 rows=15170 width=4)(actual time=0.197..81.753 rows=15575 loops=1) Index Cond: (programid = 171) -> Hash (cost=4292.49..4292.49 rows=4029 width=4) (actual time=82.217..82.217 rows=4130 loops=1) -> Hash Join (cost=1944.20..4292.49 rows=4029 width=4) (actual time=65.129..79.879 rows=4130 loops=1) Hash Cond: (ct2.participantid = ct0.participantid) -> Seq Scan on rpt_agencyquestioncache_171_2 ct2 (cost=0.00..1747.00 rows=74800 width=4) (actual time=0.014..28.093rows=74800 loops=1) -> Hash (cost=1893.84..1893.84 rows=4029 width=8) (actual time=6.238..6.238 rows=4130 loops=1) -> Bitmap Heap Scan on rpt_agencyquestioncache_171_0 ct0 (cost=55.48..1893.84 rows=4029 width=8)(actual time=0.726..3.652 rows=4130 loops=1) Recheck Cond: (inter_agency_id = 30232) -> Bitmap Index Scan on rpt_aqc_45604_inter_agency_id (cost=0.00..54.47 rows=4029 width=0)(actual time=0.702..0.702 rows=4130 loops=1) Index Cond: (inter_agency_id = 30232) -> Hash (cost=150.01..150.01 rows=9101 width=4) (actual time=35.206..35.206 rows=9101 loops=1) -> Seq Scan on activity_session s (cost=0.00..150.01 rows=9101 width=4) (actual time=9.201..29.911 rows=9101 loops=1) Total runtime: 216.649 ms
pgsql-performance by date: