performance decrease after reboot

From: John Mendenhall <john(at)surfutopia(dot)net>
To: pgsql-performance list <pgsql-performance(at)postgresql(dot)org>
Subject: performance decrease after reboot
Date: 2005-07-19 21:05:57
Message-ID: 20050719210557.GA30794@calvin.surfutopia.net
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: 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=249 loops=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) (actual time=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=250 loops=1)
Sort Key: p.classification_id
-> Merge Join (cost=0.00..18254.11 rows=13 width=195) (actual time=47.844..705.517 rows=448 loops=1)
Merge Cond: ("outer".id = "inner".partner_id)
-> Index Scan using partners_pkey on partners p (cost=0.00..30.80 rows=395 width=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.50 rows=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.094 rows=0 loops=5573)
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.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=8 width=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=39 loops=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.554 rows=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=448 loops=1)
Merge Cond: ("outer".partner_id = "inner".id)
-> Nested Loop (cost=4.42..130886.19 rows=113 width=165) (actual time=8.807..6712.529 rows=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.59 rows=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.084 rows=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=242 loops=739)
-> Seq Scan on countries co (cost=0.00..4.42 rows=242 width=19) (actual time=0.038..3.162 rows=242 loops=1)
-> Index Scan using partners_pkey on partners p (cost=0.00..30.80 rows=395 width=53) (actual time=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(at)surfutopia(dot)net
surf utopia
internet services

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Sven Willenberger 2005-07-19 21:15:08 Re: Looking for tips
Previous Message Alon Goldshuv 2005-07-19 21:05:56 Re: COPY FROM performance improvements