I suffered the same fate when upgrading some time back. The single biggest issue for me was that the default 8.X setup changed what had been fast query plans using indexes to slow plans using sequential scans. Changing the random_page_cost in postgresql.conf from 4.0 to 2.0 (which indicates to Postgres that reading index pages isn't such a big deal, encouraging index use) solved most of these issues for me. Jeff -----Original Message----- From: smiley2211 [mailto:smiley2211@xxxxxxxxx] Sent: Friday, September 21, 2007 8:14 AM To: pgsql-performance@xxxxxxxxxxxxxx Subject: Re: Upgraded from 7.4 to 8.1.4 QUERIES NOW SLOW!!! Dennis, Thanks for your reply. No, the OLD server are no longer available (decommissioned) - the new servers are definitely better h\w. I do not have any queries to EXPLAIN ANALYZE as they are built by the application and I am not allowed to enable logging on for that server - so where do I go from here??? I am pretty much trying to make changes in the postgresql.conf file but don't have a CLUE as to what starting numbers I should be looking at to change(???) Here is the EXPLAIN ANALYZE for the ONE (1) query I do have...it takes 4 - 5 hours to run a SELECT with the 'EXPLAIN ANALYZE': QUERY PLAN ---------------------------------------------------------------------------- ---------------------------------------------------------------------------- ---------------------------------------------------------------------------- - ------------------- Limit (cost=100013612.76..299939413.70 rows=1 width=8) (actual time=10084289.859..10084289.861 rows=1 loops=1) -> Subquery Scan people_consent (cost=100013612.76..624068438343.99 rows=3121 width=8) (actual time=10084289.853..10084289.853 rows=1 loops=1) -> Append (cost=100013612.76..624068438312.78 rows=3121 width=815) (actual time=10084289.849..10084289.849 rows=1 loops=1) -> Nested Loop (cost=100013612.76..100013621.50 rows=2 width=815) (actual time=10084289.846..10084289.846 rows=1 loops=1) -> Unique (cost=100013612.76..100013612.77 rows=2 width=8) (actual time=10084289.817..10084289.817 rows=1 loops=1) -> Sort (cost=100013612.76..100013612.77 rows=2 width=8) (actual time=10084289.814..10084289.814 rows=1 loops=1) Sort Key: temp_consent.id -> Unique (cost=100013612.71..100013612.73 rows=2 width=36) (actual time=10084245.195..10084277.468 rows=7292 loops=1) -> Sort (cost=100013612.71..100013612.72 rows=2 width=36) (actual time=10084245.191..10084254.425 rows=7292 loops=1) Sort Key: id, daterecorded, answer -> Append (cost=100013515.80..100013612.70 rows=2 width=36) (actual time=10083991.226..10084228.613 rows=7292 loops=1) -> HashAggregate (cost=100013515.80..100013515.82 rows=1 width=36) (actual time=10083991.223..10083998.046 rows=3666 loops=1) -> Nested Loop (cost=100000060.61..100013515.80 rows=1 width=36) (actual time=388.263..10083961.330 rows=3702 loops=1) -> Nested Loop (cost=100000060.61..100013511.43 rows=1 width=36) (actual time=388.237..10083897.268 rows=3702 loops=1) -> Nested Loop (cost=100000060.61..100013507.59 rows=1 width=24) (actual time=388.209..10083833.870 rows=3702 loops=1) -> Nested Loop (cost=100000060.61..100013504.56 rows=1 width=24) -> (actual time=388.173..10083731.122 rows=3702 loops=1) Join Filter: ("inner".question_answer_id = "outer".id) -> Nested Loop (cost=60.61..86.33 rows=1 width=28) (actual time=13.978..114.768 rows=7430 loops=1) -> Index Scan using answers_answer_un on answers a (cost=0.00..5.01 -> rows=1 width=28) (actual time=0.084..0.088 rows=1 loops=1) Index Cond: ((answer)::text = 'Yes'::text) -> Bitmap Heap Scan on questions_answers qa (cost=60.61..81.23 rows=7 width=16) (actual time=13.881..87.112 rows=7430 loops=1) Recheck Cond: ((qa.answer_id = "outer".id) AND (((qa.question_tag)::text = 'consentTransfer'::text) OR ((qa.question_tag)::text = 'share WithEval'::text))) -> BitmapAnd (cost=60.61..60.61 rows=7 width=0) (actual time=13.198..13.198 rows=0 loops=1) -> Bitmap Index Scan on qs_as_answer_id (cost=0.00..5.27 rows=649 -> width=0) (actual time=9.689..9.689 rows=57804 loops=1) Index Cond: (qa.answer_id = "outer".id) -> BitmapOr (cost=55.08..55.08 rows=6596 width=0) (actual time=2.563..2.563 rows=0 loops=1) -> Bitmap Index Scan on qs_as_qtag (cost=0.00..27.54 rows=3298 -> width=0) (actual time=1.923..1.923 rows=6237 loops=1) Index Cond: ((question_tag)::text = 'consentTransfer'::text) -> Bitmap Index Scan on qs_as_qtag (cost=0.00..27.54 rows=3298 -> width=0) (actual time=0.634..0.634 rows=2047 loops=1) Index Cond: ((question_tag)::text = 'shareWithEval'::text) -> Seq Scan on encounters_questions_answers eqa (cost=100000000.00..100007608.66 rows=464766 width=8) (actual time=0.003..735.934 rows=464766 loop s=7430) -> Index Scan using encounters_id on encounters ec (cost=0.00..3.02 -> rows=1 width=8) (actual time=0.016..0.018 rows=1 loops=3702) Index Cond: (ec.id = "outer".encounter_id) -> Index Scan using enrollements_pk on enrollments en (cost=0.00..3.82 rows=1 width=20) (actual time=0.008..0.010 rows=1 loops=3702) Index Cond: ("outer".enrollment_id = en.id) -> Index Scan using people_pk on people p (cost=0.00..4.35 rows=1 width=8) (actual time=0.008..0.010 rows=1 loops=3702) Index Cond: (p.id = "outer".person_id) -> HashAggregate (cost=96.86..96.87 rows=1 width=36) (actual time=205.471..212.207 rows=3626 loops=1) -> Nested Loop (cost=60.61..96.85 rows=1 width=36) (actual time=13.163..196.421 rows=3722 loops=1) -> Nested Loop (cost=60.61..92.48 rows=1 width=36) (actual time=13.149..158.112 rows=3722 loops=1) -> Nested Loop (cost=60.61..89.36 rows=1 width=24) (actual time=13.125..120.021 rows=3722 loops=1) -> Nested Loop (cost=60.61..86.33 rows=1 width=28) (actual time=13.013..48.460 rows=7430 loops=1) -> Index Scan using answers_answer_un on answers a (cost=0.00..5.01 -> rows=1 width=28) (actual time=0.030..0.032 rows=1 loops=1) Index Cond: ((answer)::text = 'Yes'::text) -> Bitmap Heap Scan on questions_answers qa (cost=60.61..81.23 rows=7 width=16) (actual time=12.965..28.902 rows=7430 loops=1) Recheck Cond: ((qa.answer_id = "outer".id) AND (((qa.question_tag)::text = 'consentTransfer'::text) OR ((qa.question_tag)::text = 'shareWithEv al'::text))) -> BitmapAnd (cost=60.61..60.61 rows=7 width=0) (actual time=12.288..12.288 rows=0 loops=1) -> Bitmap Index Scan on qs_as_answer_id (cost=0.00..5.27 rows=649 -> width=0) (actual time=8.985..8.985 rows=57804 loops=1) Index Cond: (qa.answer_id = "outer".id) -> BitmapOr (cost=55.08..55.08 rows=6596 width=0) (actual time=2.344..2.344 rows=0 loops=1) -> Bitmap Index Scan on qs_as_qtag (cost=0.00..27.54 rows=3298 -> width=0) (actual time=1.762..1.762 rows=6237 loops=1) Index Cond: ((question_tag)::text = 'consentTransfer'::text) -> Bitmap Index Scan on qs_as_qtag (cost=0.00..27.54 rows=3298 -> width=0) (actual time=0.578..0.578 rows=2047 loops=1) Index Cond: ((question_tag)::text = 'shareWithEval'::text) -> Index Scan using ctccalls_qs_as_qaid on ctccalls_questions_answers -> cqa (cost=0.00..3.02 rows=1 width=8) (actual time=0.005..0.006 rows=1 loops=7430) Index Cond: (cqa.question_answer_id = "outer".id) -> Index Scan using ctccalls_pk on ctccalls c (cost=0.00..3.11 rows=1 width=20) (actual time=0.003..0.005 rows=1 loops=3722) Index Cond: (c.id = "outer".call_id) -> Index Scan using people_pk on people p (cost=0.00..4.35 rows=1 width=8) (actual time=0.004..0.005 rows=1 loops=3722) Index Cond: (p.id = "outer".person_id) -> Index Scan using people_pk on people (cost=0.00..4.35 rows=1 width=815) (actual time=0.018..0.018 rows=1 loops=1) Index Cond: (people.id = "outer".id) -> Subquery Scan "*SELECT* 2" (cost=100000000.00..623968424691.25 rows=3119 width=676) (never executed) -> Seq Scan on people (cost=100000000.00..623968424660.06 rows=3119 width=676) (never executed) Filter: (NOT (subplan)) SubPlan -> Subquery Scan temp_consent (cost=100010968.94..100010968.98 rows=2 width=8) (never executed) lines 1-69/129 56% Index Cond: (cqa.question_answer_id = "outer".id) -> Index Scan using ctccalls_pk on ctccalls c (cost=0.00..3.11 rows=1 width=20) (actual time=0.003..0.005 rows=1 loops=3722) Index Cond: (c.id = "outer".call_id) -> Index Scan using people_pk on people p (cost=0.00..4.35 rows=1 width=8) (actual time=0.004..0.005 rows=1 loops=3722) Index Cond: (p.id = "outer".person_id) -> Index Scan using people_pk on people (cost=0.00..4.35 rows=1 width=815) (actual time=0.018..0.018 rows=1 loops=1) Index Cond: (people.id = "outer".id) -> Subquery Scan "*SELECT* 2" (cost=100000000.00..623968424691.25 rows=3119 width=676) (never executed) -> Seq Scan on people (cost=100000000.00..623968424660.06 rows=3119 width=676) (never executed) Filter: (NOT (subplan)) SubPlan -> Subquery Scan temp_consent (cost=100010968.94..100010968.98 rows=2 width=8) (never executed) -> Unique (cost=100010968.94..100010968.96 rows=2 width=36) (never executed) -> Sort (cost=100010968.94..100010968.95 rows=2 width=36) (never executed) Sort Key: id, daterecorded, answer -> Append (cost=100010872.03..100010968.93 rows=2 width=36) (never executed) -> HashAggregate (cost=100010872.03..100010872.04 rows=1 width=36) (never executed) -> Nested Loop (cost=100000907.99..100010872.02 rows=1 width=36) (never executed) Join Filter: ("inner".question_answer_id = "outer".id) -> Nested Loop (cost=60.61..90.69 rows=1 width=36) (never executed) -> Nested Loop (cost=0.00..9.37 rows=1 width=36) (never executed) -> Index Scan using people_pk on people p (cost=0.00..4.35 rows=1 -> width=8) (never executed) Index Cond: (id = $0) -> Index Scan using answers_answer_un on answers a (cost=0.00..5.01 -> rows=1 width=28) (never executed) Index Cond: ((answer)::text = 'Yes'::text) -> Bitmap Heap Scan on questions_answers qa (cost=60.61..81.23 rows=7 width=16) (never executed) Recheck Cond: ((qa.answer_id = "outer".id) AND (((qa.question_tag)::text = 'consentTransfer'::text) OR ((qa.question_tag)::text = 'shareWithEval'::text) )) -> BitmapAnd (cost=60.61..60.61 rows=7 width=0) (never executed) -> Bitmap Index Scan on qs_as_answer_id (cost=0.00..5.27 rows=649 -> width=0) (never executed) Index Cond: (qa.answer_id = "outer".id) -> BitmapOr (cost=55.08..55.08 rows=6596 width=0) (never executed) -> Bitmap Index Scan on qs_as_qtag (cost=0.00..27.54 rows=3298 -> width=0) (never executed) Index Cond: ((question_tag)::text = 'consentTransfer'::text) -> Bitmap Index Scan on qs_as_qtag (cost=0.00..27.54 rows=3298 -> width=0) (never executed) Index Cond: ((question_tag)::text = 'shareWithEval'::text) -> Hash Join (cost=100000847.38..100010780.52 rows=65 width=20) (never executed) Hash Cond: ("outer".encounter_id = "inner".id) -> Seq Scan on encounters_questions_answers eqa (cost=100000000.00..100007608.66 rows=464766 width=8) (never executed) -> Hash (cost=847.37..847.37 rows=3 width=20) (never executed) -> Hash Join (cost=214.73..847.37 rows=3 width=20) (never executed) Hash Cond: ("outer".enrollment_id = "inner".id) -> Index Scan using encounters_id on encounters ec (cost=0.00..524.72 rows=21578 width=8) (never executed) -> Hash (cost=214.73..214.73 rows=1 width=20) (never executed) -> Index Scan using enrollements_pk on enrollments en -> (cost=0.00..214.73 rows=1 width=20) (never executed) Filter: ($0 = person_id) -> HashAggregate (cost=96.86..96.87 rows=1 width=36) (never executed) -> Nested Loop (cost=60.61..96.85 rows=1 width=36) (never executed) -> Nested Loop (cost=60.61..93.72 rows=1 width=32) (never executed) -> Nested Loop (cost=60.61..90.69 rows=1 width=36) (never executed) -> Nested Loop (cost=0.00..9.37 rows=1 width=36) (never executed) -> Index Scan using people_pk on people p (cost=0.00..4.35 rows=1 -> width=8) (never executed) Index Cond: (id = $0) -> Index Scan using answers_answer_un on answers a (cost=0.00..5.01 -> rows=1 width=28) (never executed) Index Cond: ((answer)::text = 'Yes'::text) -> Bitmap Heap Scan on questions_answers qa (cost=60.61..81.23 rows=7 width=16) (never executed) Recheck Cond: ((qa.answer_id = "outer".id) AND (((qa.question_tag)::text = 'consentTransfer'::text) OR ((qa.question_tag)::text = 'shareWithEval': :text))) -> BitmapAnd (cost=60.61..60.61 rows=7 width=0) (never executed) -> Bitmap Index Scan on qs_as_answer_id (cost=0.00..5.27 rows=649 -> width=0) (never executed) Index Cond: (qa.answer_id = "outer".id) -> BitmapOr (cost=55.08..55.08 rows=6596 width=0) (never executed) -> Bitmap Index Scan on qs_as_qtag (cost=0.00..27.54 rows=3298 -> width=0) (never executed) Index Cond: ((question_tag)::text = 'consentTransfer'::text) -> Bitmap Index Scan on qs_as_qtag (cost=0.00..27.54 rows=3298 -> width=0) (never executed) Index Cond: ((question_tag)::text = 'shareWithEval'::text) -> Index Scan using ctccalls_qs_as_qaid on ctccalls_questions_answers cqa (cost=0.00..3.02 rows=1 width=8) (never executed) Index Cond: (cqa.question_answer_id = "outer".id) -> Index Scan using ctccalls_pk on ctccalls c (cost=0.00..3.11 rows=1 width=20) (never executed) Index Cond: (c.id = "outer".call_id) Filter: ($0 = person_id) Total runtime: 10084292.497 ms (125 rows) Thanks...Marsha -- View this message in context: http://www.nabble.com/Upgraded-from-7.4-to-8.1.4-QUERIES-NOW-SLOW%21%21%21-t f4489502.html#a12820410 Sent from the PostgreSQL - performance mailing list archive at Nabble.com. ---------------------------(end of broadcast)--------------------------- TIP 3: Have you checked our extensive FAQ? http://www.postgresql.org/docs/faq ---------------------------(end of broadcast)--------------------------- TIP 6: explain analyze is your friend
