Thread: Upgraded from 7.4 to 8.1.4 QUERIES NOW SLOW!!!
Hello all, Old servers that housed 7.4 performed better than 8.1.4 version...are there any MAJOR performance hits with this version??? I set the postgresql.conf setting to equal that of 7.4 and queries still run SLOW on 8.1.4... I have perform maintenance tonight on the 8.1.4 server - any ideas what actions I should take??? default stats set to 50 (in postgresql.conf) 1) Restart instance 2) Dump \ reload database 3) vacuum analyze 4) rebuild index database I keep doing these same steps and nothing seems to work...I've read where some are saying to VACUUM several times - then reindex (???) Can someone tell me what they do during a NORMAL maintenance window on their servers??? All this is NEW to me. Thanks, Michelle. -- 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#a12803859 Sent from the PostgreSQL - performance mailing list archive at Nabble.com.
smiley2211 wrote: > Hello all, > > Old servers that housed 7.4 performed better than 8.1.4 version...are there > any MAJOR performance hits with this version??? > Are you using the default UNICODE encoding for your databases?? This could potentially translate into a performance hit (considerable? Maybe, depending on what your applications do) A related question: why not update to the latest, 8.2.x ?? > I set the postgresql.conf setting to equal that of 7.4 and queries still run > SLOW on 8.1.4... > Hmmm, I don't think the settings should be the same --- search the archives for discussions on performance tuning and an informal documentation of the postgresql.conf file. > 3) vacuum analyze > Am I understanding correctly that you did this?? Just to double check, yes, it is *very* important that you analyze the database *after loading it*. You could probably check the postgres log file to see if there are any obvious red flags in there. HTH, Carlos --
No, I didn't UPGRADE it but that's what I inherited :( ...not sure of the code page stuff because I am not the one who did the upgrade...I'm not sure I know ENOUGH about POSTGRESQL to mess around with the codepage... Yes, I use vacuum analyze... Yes, I used the postgresql.conf of 7.4 and tried to match the 8.1.4 to that...I didn't know where else to start...The users have been complaining since DAY1 as I am told... Thanks, Michelle -- 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#a12805270 Sent from the PostgreSQL - performance mailing list archive at Nabble.com.
On 9/20/07, smiley2211 <smiley2211@yahoo.com> wrote: > > No, I didn't UPGRADE it but that's what I inherited :( ...not sure of the > code page stuff because I am not the one who did the upgrade...I'm not sure > I know ENOUGH about POSTGRESQL to mess around with the codepage... > > Yes, I use vacuum analyze... > > Yes, I used the postgresql.conf of 7.4 and tried to match the 8.1.4 to > that...I didn't know where else to start...The users have been complaining > since DAY1 as I am told... OK, a few things you need to look into. Do you have horrendous bloating in the db. run vacuum verbose on your db and see what it says. You should probably turn on the autovacuum daemon either way. If your database has gotten bloated you may need to vacuum full / reindex to get your space back. What queries are slow, specifically. you can set the server to log long running servers in postgresql.conf. Find the longest running ones and run them by hand with explain analyze at the front, like: explain analyze select ..... lastly, run vmstat 10 from the command line while the machine is running slow and see where effort is going. I'm guessing you'll see a lot of id in there.
On 9/20/07, Scott Marlowe <scott.marlowe@gmail.com> wrote: > effort is going. I'm guessing you'll see a lot of id in there. sorry, meant wa (wait)
How do I know if there is BLOATING??? I just ran vacuum verbose; Yes, autovacuum is on. Thanks...Michelle -- 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#a12807959 Sent from the PostgreSQL - performance mailing list archive at Nabble.com.
On 9/20/07, smiley2211 <smiley2211@yahoo.com> wrote: > > How do I know if there is BLOATING??? I just ran vacuum verbose; > > Yes, autovacuum is on. Post the last 4 or 5 lines from vacuum verbose.
Here are the requested lines... There were 0 unused item pointers. 0 pages are entirely empty. CPU 0.00s/0.00u sec elapsed 0.00 sec. INFO: free space map contains 786 pages in 297 relations DETAIL: A total of 5408 page slots are in use (including overhead). 5408 page slots are required to track all free space. Current limits are: 40000 page slots, 1000 relations, using 341 KB. VACUUM -- 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#a12810028 Sent from the PostgreSQL - performance mailing list archive at Nabble.com.
> Old servers that housed 7.4 performed better than 8.1.4 version...are > there any MAJOR performance hits with this version??? > > I set the postgresql.conf setting to equal that of 7.4 and queries still > run > SLOW on 8.1.4... We need to find a specific query that is slow now that was fast before, and see the EXPLAIN ANALYZE of that query. If you have the old server still around then showing the EXPLAIN ANALYZE of the same query on that server would be a lot of help. /Dennis
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.
In response to smiley2211 <smiley2211@yahoo.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@collaborativefusion.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.
****************************************************************
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@yahoo.com]
Sent: Friday, September 21, 2007 8:14 AM
To: pgsql-performance@postgresql.org
Subject: Re: [PERFORM] 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
>From: smiley2211 >Subject: Re: [PERFORM] Upgraded from 7.4 to 8.1.4 QUERIES NOW SLOW!!! > >-> 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) It looks like enable_seqscan is set to false. For some reason that might have worked on 7.4, but I would try turning that back on for 8.1. Sequential scans aren't always bad, sometimes they are faster than index scans. I would first try running the system with all the enable_* settings on. If you can't turn on logging its going to be very hard to track down the problem. The easiest way to track down a problem normally is to set log_min_duration to something like 2000ms. Then Postgres will log all slow queries. Then you can run EXPLAIN ANALYZE on the slow queries to find the problem. I think Carlos had a good idea when he asked about the encoding on the new server vs the old. Does your application use the like keyword to compare text fields? If so, you might need to create indexes which use the text_pattern_ops operator classes. With unicode postgres cannot use an index scan for a query like SELECT * FROM foo WHERE name LIKE 'Bob%' unless there is an index like CREATE INDEX name_index ON foo (name text_pattern_ops). However if you are not using like queries, then this is not your problem. More on operator classes: http://www.postgresql.org/docs/8.1/interactive/indexes-opclass.html Dave