Finally... issue is resolved :) Increased the DST to 10K and ran ANALYZE on the db again. QUERY PLAN ------------------------------------------------------------------------ ------------------------------------------------------------------------ ------------------ Sort (cost=7561.71..7562.23 rows=208 width=373) (actual time=43.663..43.899 rows=3445 loops=1) Sort Key: tblappliccomp.idnumber2, tblappliccomp.idnumber Sort Method: quicksort Memory: 1045kB -> Hash Left Join (cost=1006.54..7553.70 rows=208 width=373) (actual time=4.915..38.416 rows=3445 loops=1) Hash Cond: (tblappliccomp.usercrid = tbluser.idnumber) -> Nested Loop Left Join (cost=980.52..3337.69 rows=208 width=378) (actual time=4.651..17.277 rows=3445 loops=1) -> Bitmap Heap Scan on tblappliccomp (cost=980.52..1816.60 rows=208 width=181) (actual time=4.641..6.405 rows=3445 loops=1) Recheck Cond: ((applicid = 90000872) AND ("inout" = 1)) Filter: ((otherr IS NULL) OR (otherr = 0)) -> BitmapAnd (cost=980.52..980.52 rows=223 width=0) (actual time=4.608..4.608 rows=0 loops=1) -> Bitmap Index Scan on tblappliccompindapplicid (cost=0.00..67.00 rows=3555 width=0) (actual time=0.335..0.335 rows=3555 loops=1) Index Cond: (applicid = 90000872) -> Bitmap Index Scan on tblappliccompindinout (cost=0.00..913.16 rows=49177 width=0) (actual time=4.246..4.246 rows=49177 loops=1) Index Cond: ("inout" = 1) -> Index Scan using tblcompanyindidnumber on tblcompany (cost=0.00..7.30 rows=1 width=205) (actual time=0.002..0.002 rows=0 loops=3445) Index Cond: (tblappliccomp.companyid = idnumber) -> Hash (cost=21.01..21.01 rows=401 width=11) (actual time=0.217..0.217 rows=401 loops=1) Buckets: 1024 Batches: 1 Memory Usage: 19kB -> Seq Scan on tbluser (cost=0.00..21.01 rows=401 width=11) (actual time=0.005..0.151 rows=401 loops=1) SubPlan 1 -> Limit (cost=0.00..20.13 rows=1 width=15) (actual time=0.005..0.005 rows=1 loops=3445) -> Nested Loop Left Join (cost=0.00..20.13 rows=1 width=15) (actual time=0.005..0.005 rows=1 loops=3445) -> Index Scan using leeindapplicid on lee (cost=0.00..11.85 rows=1 width=8) (actual time=0.003..0.003 rows=1 loops=3445) Index Cond: (applicid = 70058598) Filter: ((eorg = tblappliccomp.companyid) AND (eevent = tblappliccomp.confid)) -> Index Scan using tblreferralindidnumber on tblreferral (cost=0.00..8.27 rows=1 width=23) (actual time=0.001..0.001 rows=1 loops=2947) Index Cond: (lee.referralid = idnumber) Total runtime: 44.260 ms (28 rows) -----Original Message----- From: pgsql-general-owner@xxxxxxxxxxxxxx [mailto:pgsql-general-owner@xxxxxxxxxxxxxx] On Behalf Of John Watts Sent: 19 May 2012 14:04 To: Tom Lane Cc: pgsql-general@xxxxxxxxxxxxxx Subject: Re: difference in query plan when db is restored Tom, thanks very much for your response. I've run REINDEX on the db and ANALYZE multiple times - there is no dramatic improvement. I appreciate all the impressive effort and contribution of PostgreSQL developers and am fully aware of importance of bug fixes. Please acknowledge I am running into the exact same problem with version 9.1.2. The query plan is again 33 rows and it takes 23992.996 ms to execute as opposed to 21 rows and less than one second execution on the production server. Not sure what where to go from here... QUERY PLAN ------------------------------------------------------------------------ ------------------------------------------------------------------------ ------------------ Sort (cost=7807.69..7808.19 rows=200 width=373) (actual time=23992.283..23992.577 rows=3445 loops=1) Sort Key: tblappliccomp.idnumber2, tblappliccomp.idnumber Sort Method: quicksort Memory: 1045kB -> Hash Left Join (cost=994.00..7800.05 rows=200 width=373) (actual time=15.723..23983.602 rows=3445 loops=1) Hash Cond: (tblappliccomp.usercrid = tbluser.idnumber) -> Nested Loop Left Join (cost=967.98..3238.24 rows=200 width=378) (actual time=5.741..30.190 rows=3445 loops=1) -> Bitmap Heap Scan on tblappliccomp (cost=967.98..1771.49 rows=200 width=181) (actual time=5.730..10.220 rows=3445 loops=1) Recheck Cond: ((applicid = 90000872) AND ("inout" = 1)) Filter: ((otherr IS NULL) OR (otherr = 0)) -> BitmapAnd (cost=967.98..967.98 rows=214 width=0) (actual time=5.689..5.689 rows=0 loops=1) -> Bitmap Index Scan on tblappliccompindapplicid (cost=0.00..66.27 rows=3458 width=0) (actual time=0.460..0.460 rows=3555 loops=1) Index Cond: (applicid = 90000872) -> Bitmap Index Scan on tblappliccompindinout (cost=0.00..901.36 rows=48670 width=0) (actual time=5.201..5.201 rows=49177 loops=1) Index Cond: ("inout" = 1) -> Index Scan using tblcompanyindidnumber on tblcompany (cost=0.00..7.32 rows=1 width=205) (actual time=0.004..0.004 rows=0 loops=3445) Index Cond: (tblappliccomp.companyid = idnumber) -> Hash (cost=21.01..21.01 rows=401 width=11) (actual time=0.213..0.213 rows=401 loops=1) Buckets: 1024 Batches: 1 Memory Usage: 19kB -> Seq Scan on tbluser (cost=0.00..21.01 rows=401 width=11) (actual time=0.006..0.139 rows=401 loops=1) SubPlan 1 -> Limit (cost=10.37..22.67 rows=1 width=15) (actual time=6.950..6.950 rows=1 loops=3445) -> Nested Loop Left Join (cost=10.37..22.67 rows=1 width=15) (actual time=6.949..6.949 rows=1 loops=3445) -> Bitmap Heap Scan on lee (cost=10.37..14.39 rows=1 width=8) (actual time=6.942..6.942 rows=1 loops=3445) Recheck Cond: ((applicid = 70058598) AND (eevent = tblappliccomp.confid)) Filter: (eorg = tblappliccomp.companyid) -> BitmapAnd (cost=10.37..10.37 rows=1 width=0) (actual time=6.936..6.936 rows=0 loops=3445) -> Bitmap Index Scan on leeindapplicid (cost=0.00..4.36 rows=3 width=0) (actual time=0.007..0.007 rows=3 loops=3445) Index Cond: (applicid = 70058598) -> Bitmap Index Scan on leeindeevent (cost=0.00..5.76 rows=189 width=0) (actual time=6.892..6.892 rows=85704 loops=3445) Index Cond: (eevent = tblappliccomp.confid) -> Index Scan using tblreferralindidnumber on tblreferral (cost=0.00..8.27 rows=1 width=23) (actual time=0.004..0.004 rows=1 loops=2947) Index Cond: (lee.referralid = idnumber) Total runtime: 23992.996 ms (33 rows) -----Original Message----- From: Tom Lane [mailto:tgl@xxxxxxxxxxxxx] Sent: 18 May 2012 19:29 To: John Watts Cc: pgsql-general@xxxxxxxxxxxxxx Subject: Re: difference in query plan when db is restored "John Watts" <jwatts@xxxxxxxxxxxxxxxxxxxx> writes: > Anyone? I'm still suspicious that you're not really re-ANALYZE'ing the relevant tables, because there are some discrepancies in the row count estimates that seem hard to explain otherwise, eg here: -> Index Scan using tblcompanyindidnumber on tblcompany (cost=0.00..8.40 rows=1 width=206) (actual time=0.003..0.003 rows=0 loops=3445) Index Cond: (tblappliccomp.companyid = tblcompany.idnumber) vs -> Bitmap Heap Scan on tblcompany (cost=13.07..1774.92 rows=620 width=185) (actual time=0.013..0.013 rows=0 loops=3445) Recheck Cond: (tblappliccomp.companyid = tblcompany.idnumber) -> Bitmap Index Scan on tblcompanyindidnumber (cost=0.00..12.91 rows=620 width=0) (actual time=0.011..0.011 rows=0 loops=3445) Index Cond: (tblappliccomp.companyid = tblcompany.idnumber) That might be caused by missing stats for either tblcompany or tblappliccomp. Or perhaps the problem is much different values of default_statistics_target? Also, I've got to say that this does not represent good practice: > server_version | 8.3.0 You're missing eighteen minor-release updates on that server. We don't do minor releases just to keep ourselves amused; there are a lot of rather significant bug fixes that you're missing, possibly including some that affect this issue. regards, tom lane -- Sent via pgsql-general mailing list (pgsql-general@xxxxxxxxxxxxxx) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-general -- Sent via pgsql-general mailing list (pgsql-general@xxxxxxxxxxxxxx) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-general