performance decrease after reboot - Mailing list pgsql-performance
From | John Mendenhall |
---|---|
Subject | performance decrease after reboot |
Date | |
Msg-id | 20050719210557.GA30794@calvin.surfutopia.net Whole thread Raw |
Responses |
Re: performance decrease after reboot
|
List | pgsql-performance |
I tuned a query last week to obtain acceptable performance. Here is my recorded explain analyze results: ----- LOG: duration: 826.505 ms statement: explain analyze SELECT c.id AS contact_id, sr.id AS sales_rep_id, LTRIM(RTRIM(sr.firstname || ' ' || sr.lastname)) AS sales_rep_name, p.id AS partner_id, p.company AS partner_company, coalesce(LTRIM(RTRIM(c.company)), LTRIM(RTRIM(c.firstname || ' ' || c.lastname))) AS contact_company, LTRIM(RTRIM(c.city || ' ' || c.state || ' ' || c.postalcode || ' ' || c.country)) AS contact_location, c.phone AS contact_phone, c.email AS contact_email, co.name AS contact_country, TO_CHAR(c.request_status_last_modified, 'mm/dd/yy hh12:mi pm') AS request_status_last_modified, TO_CHAR(c.request_status_last_modified, 'yyyymmddhh24miss') AS rqst_stat_last_mdfd_sortable, c.token_id FROM sales_reps sr JOIN partners p ON (sr.id = p.sales_rep_id) JOIN contacts c ON (p.id = c.partner_id) JOIN countries co ON (LOWER(c.country) = LOWER(co.code)) JOIN partner_classification pc ON (p.classification_id = pc.id AND pc.classification != 'Sales Rep') WHERE c.lead_deleted IS NULL AND EXISTS ( SELECT lr.id FROM lead_requests lr, lead_request_status lrs WHERE c.id = lr.contact_id AND lr.status_id = lrs.id AND lrs.is_closed = 0 ) ORDER BY contact_company, contact_id QUERY PLAN ------------------------------------------------------------------------------------------------------------------------------- Sort (cost=18266.77..18266.80 rows=11 width=219) (actual time=795.502..795.763 rows=246 loops=1) Sort Key: COALESCE(ltrim(rtrim((c.company)::text)), ltrim(rtrim((((c.firstname)::text || ' '::text) || (c.lastname)::text)))),c.id -> Hash Join (cost=18258.48..18266.58 rows=11 width=219) (actual time=747.551..788.095 rows=246 loops=1) Hash Cond: (lower(("outer".code)::text) = lower(("inner".country)::text)) -> Seq Scan on countries co (cost=0.00..4.42 rows=242 width=19) (actual time=0.040..2.128 rows=242 loops=1) -> Hash (cost=18258.45..18258.45 rows=9 width=206) (actual time=746.653..746.653 rows=0 loops=1) -> Merge Join (cost=18258.12..18258.45 rows=9 width=206) (actual time=729.412..743.691 rows=246 loops=1) Merge Cond: ("outer".sales_rep_id = "inner".id) -> Sort (cost=18255.70..18255.73 rows=9 width=185) (actual time=727.948..728.274 rows=249 loops=1) Sort Key: p.sales_rep_id -> Merge Join (cost=18255.39..18255.56 rows=9 width=185) (actual time=712.747..723.095 rows=249loops=1) Merge Cond: ("outer".id = "inner".classification_id) -> Sort (cost=1.05..1.05 rows=2 width=10) (actual time=0.192..0.195 rows=2 loops=1) Sort Key: pc.id -> Seq Scan on partner_classification pc (cost=0.00..1.04 rows=2 width=10) (actualtime=0.100..0.142 rows=2 loops=1) Filter: ((classification)::text <> 'Sales Rep'::text) -> Sort (cost=18254.35..18254.38 rows=13 width=195) (actual time=712.401..712.675 rows=250loops=1) Sort Key: p.classification_id -> Merge Join (cost=0.00..18254.11 rows=13 width=195) (actual time=47.844..705.517rows=448 loops=1) Merge Cond: ("outer".id = "inner".partner_id) -> Index Scan using partners_pkey on partners p (cost=0.00..30.80 rows=395width=53) (actual time=0.066..5.746 rows=395 loops=1) -> Index Scan using contacts_partner_id_idx on contacts c (cost=0.00..130358.50rows=93 width=152) (actual time=0.351..662.576 rows=452 loops=1) Filter: ((lead_deleted IS NULL) AND (subplan)) SubPlan -> Nested Loop (cost=0.00..6.76 rows=2 width=10) (actual time=0.094..0.094rows=0 loops=5573) Join Filter: ("outer".status_id = "inner".id) -> Index Scan using lead_requests_contact_id_idx on lead_requestslr (cost=0.00..4.23 rows=2 width=20) (actual time=0.068..0.069 rows=0 loops=5573) Index Cond: ($0 = contact_id) -> Seq Scan on lead_request_status lrs (cost=0.00..1.16 rows=8width=10) (actual time=0.030..0.094 rows=4 loops=519) Filter: (is_closed = 0::numeric) -> Sort (cost=2.42..2.52 rows=39 width=31) (actual time=1.334..1.665 rows=267 loops=1) Sort Key: sr.id -> Seq Scan on sales_reps sr (cost=0.00..1.39 rows=39 width=31) (actual time=0.064..0.533 rows=39loops=1) Total runtime: 798.494 ms (34 rows) ----- I rebooted the database machine later that night. Now, when I run the same query, I get the following results: ----- QUERY PLAN ------------------------------------------------------------------------------------------------------------------------------- Sort (cost=17415.32..17415.35 rows=11 width=219) (actual time=6880.583..6880.738 rows=246 loops=1) Sort Key: COALESCE(ltrim(rtrim((c.company)::text)), ltrim(rtrim((((c.firstname)::text || ' '::text) || (c.lastname)::text)))),c.id -> Merge Join (cost=17414.22..17415.13 rows=11 width=219) (actual time=6828.441..6871.894 rows=246 loops=1) Merge Cond: ("outer".sales_rep_id = "inner".id) -> Sort (cost=17411.80..17411.83 rows=11 width=198) (actual time=6825.227..6825.652 rows=249 loops=1) Sort Key: p.sales_rep_id -> Merge Join (cost=17411.42..17411.61 rows=11 width=198) (actual time=6805.894..6818.717 rows=249 loops=1) Merge Cond: ("outer".id = "inner".classification_id) -> Sort (cost=1.05..1.05 rows=2 width=10) (actual time=0.788..0.792 rows=2 loops=1) Sort Key: pc.id -> Seq Scan on partner_classification pc (cost=0.00..1.04 rows=2 width=10) (actual time=0.094..0.554rows=2 loops=1) Filter: ((classification)::text <> 'Sales Rep'::text) -> Sort (cost=17410.38..17410.41 rows=15 width=208) (actual time=6804.649..6804.923 rows=250 loops=1) Sort Key: p.classification_id -> Merge Join (cost=4.42..17410.08 rows=15 width=208) (actual time=62.598..6795.704 rows=448loops=1) Merge Cond: ("outer".partner_id = "inner".id) -> Nested Loop (cost=4.42..130886.19 rows=113 width=165) (actual time=8.807..6712.529rows=739 loops=1) Join Filter: (lower(("outer".country)::text) = lower(("inner".code)::text)) -> Index Scan using contacts_partner_id_idx on contacts c (cost=0.00..130206.59rows=93 width=152) (actual time=0.793..4082.343 rows=739 loops=1) Filter: ((lead_deleted IS NULL) AND (subplan)) SubPlan -> Nested Loop (cost=0.00..6.76 rows=2 width=10) (actual time=0.084..0.084rows=0 loops=37077) Join Filter: ("outer".status_id = "inner".id) -> Index Scan using lead_requests_contact_id_idx on lead_requests lr (cost=0.00..4.23 rows=2 width=20) (actual time=0.066..0.066 rows=0 loops=37077) Index Cond: ($0 = contact_id) -> Seq Scan on lead_request_status lrs (cost=0.00..1.16 rows=8 width=10)(actual time=0.031..0.140 rows=4 loops=1195) Filter: (is_closed = 0::numeric) -> Materialize (cost=4.42..6.84 rows=242 width=19) (actual time=0.003..0.347 rows=242loops=739) -> Seq Scan on countries co (cost=0.00..4.42 rows=242 width=19) (actual time=0.038..3.162rows=242 loops=1) -> Index Scan using partners_pkey on partners p (cost=0.00..30.80 rows=395 width=53) (actualtime=0.062..15.152 rows=787 loops=1) -> Sort (cost=2.42..2.52 rows=39 width=31) (actual time=1.916..2.723 rows=267 loops=1) Sort Key: sr.id -> Seq Scan on sales_reps sr (cost=0.00..1.39 rows=39 width=31) (actual time=0.065..0.723 rows=39 loops=1) Total runtime: 6886.307 ms (34 rows) ----- There is definitely a difference in the query plans. I am guessing this difference in the performance decrease. However, nothing was changed in the postgresql.conf file. I may have run something in the psql explain analyze session a week ago, but I can't figure out what I changed. So, the bottom line is this: What do I need to do to get back to the better performance? Is it possible to determine what options may have changed from the above query plan differences? And, also, What is the "Materialize" query plan item in the second query plan, the slower plan? If you need any additional configurations, please let me know. Thank you very much in advance for any pointers you can provide. JohnM -- John Mendenhall john@surfutopia.net surf utopia internet services
pgsql-performance by date: