Re: Upgraded from 7.4 to 8.1.4 QUERIES NOW SLOW!!!

In response to smiley2211 <smiley2211(at)yahoo(dot)com>:
>
> Dennis,
>
> Thanks for your reply.
>
> No, the OLD server are no longer available (decommissioned) - the new
> servers are definitely better h\w.

Says who? I've heard that one before, and I've seen it be false.
Some wonk replaced a 1Ghz system with 1G of RAM and a high-end SCSI
RAID 10 with a new 3ghz server with 4G of ram and a cheapo SATA-based
RAID 5, but doesn't know he was better off with the older system?

That may not apply to you, or it might. We don't know because you
didn't give us details.

> 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???

Update your resume. If you're expected to performance tune this system,
but you're not allowed to enable logging and you can't get a look at
the queries, you're going to looking for new employment soon, because
you've been asked to do the impossible.

> 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':

It's very difficult (if not impossible) to make sense of this output
without the query itself. It would also be nice if your mail program
didn't mangle the output, as it would save folks having to reconstruct
it.

>
>
> 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.
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 3: Have you checked our extensive FAQ?
>
> http://www.postgresql.org/docs/faq
>
>
>
>
>
>

--
Bill Moran
Collaborative Fusion Inc.
http://people.collaborativefusion.com/~wmoran/

wmoran(at)collaborativefusion(dot)com
Phone: 412-422-3463x4023

****************************************************************
IMPORTANT: This message contains confidential information and is
intended only for the individual named. If the reader of this
message is not an intended recipient (or the individual
responsible for the delivery of this message to an intended
recipient), please be advised that any re-use, dissemination,
distribution or copying of this message is prohibited. Please
notify the sender immediately by e-mail if you have received
this e-mail by mistake and delete this e-mail from your system.
E-mail transmission cannot be guaranteed to be secure or
error-free as information could be intercepted, corrupted, lost,
destroyed, arrive late or incomplete, or contain viruses. The
sender therefore does not accept liability for any errors or
omissions in the contents of this message, which arise as a
result of e-mail transmission.
****************************************************************