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-tf4489502.html#a12820410
Sent from the PostgreSQL - performance mailing list archive at Nabble.com.