X-Original-To: pgsql-performance-postgresql.org@localhost.postgresql.org
Received: from localhost (unknown [200.46.204.144]) by svr1.postgresql.org
(Postfix) with ESMTP id C289052A57 for
<pgsql-performance-postgresql.org@localhost.postgresql.org>; Sat, 5 Mar 2005
18:38:59 +0000 (GMT)
Received: from svr1.postgresql.org ([200.46.204.71]) by localhost (av.hub.org
[200.46.204.144]) (amavisd-new, port 10024) with ESMTP id 15845-02 for
<pgsql-performance-postgresql.org@localhost.postgresql.org>; Sat, 5 Mar 2005
18:38:39 +0000 (GMT)
Received: from smtpout02-03.prod.mesa1.secureserver.net
(smtpout02-03.prod.mesa1.secureserver.net [64.202.165.193]) by
svr1.postgresql.org (Postfix) with SMTP id 3924C52A6F for
<pgsql-performance@postgresql.org>; Sat, 5 Mar 2005 18:38:35 +0000 (GMT)
Received: (qmail 8138 invoked from network); 5 Mar 2005 18:38:35 -0000
Received: from unknown (HELO webmail02.mesa1.secureserver.net)
(64.202.166.81) by smtpout02-03.prod.mesa1.secureserver.net with SMTP; 5 Mar
2005 18:38:35 -0000
Received: (qmail 17458 invoked by uid 99); 5 Mar 2005 18:38:35 -0000
Message-ID: <20050305183835.17457.qmail@webmail02.mesa1.secureserver.net>
Date: Sat, 5 Mar 2005 11:38:35 -0700
From: mark.lubratt@indeq.com
Subject: Query Optimization - Hash Join estimate off?
To: pgsql-performance@postgresql.org
MIME-Version: 1.0
Content-Type: TEXT/html; CHARSET=US-ASCII
X-Virus-Scanned: by amavisd-new at hub.org
X-Archive-Number: 200503/87
X-Sequence-Number: 10792
<div>Hello!</div>
<div> </div>
<div>First off, I'm a real newbie at trying to read the output of explain
analyze.</div>
<div> </div>
<div>I have several similar queries in my application that I've got
incorporated into views. When they run sub 300ms, the users don't
seem to mind. However, one of them (query is below along with some
relevant table information) is running about 800ms and my users are
starting to grumble.</div>
<div> </div>
<div>I ran explain analyze on it (explain analyze results are
below). I noticed that the biggest chunk of time is being taken
by a Hash Join near the top of the output (I'm still not sure what the
indentation means and what the order means). If I look at the
estimate, it is comparable to several other hash join estimates in the
query; however, the actual cost in time is significantly higher than
those other hash joins. Is this significant?</div>
<div> </div>
<div>I tried optimizing according to "SQL Tuning" by Tow, but this
actually seemed to slow things down. It also seemed that the
query optimizer in PostgreSQL reordered things on its own according to
its own plan anyway. Is this correct?</div>
<div> </div>
<div>I'd appreciate any help I can get to try to get this query below
300ms.</div>
<div> </div>
<div>Thanks!</div>
<div>Mark</div>
<div> </div>
<div>The platform is a dual 2.2GHz Xeon 1.2GB RAM with mirrored drives
(raid 1) running Win2000 Pro. I run "vacuum analyze" every
night. The postgresql.conf is basically standard except that I've
opened it up to listen to the external network. Other changes:</div>
<div> </div>
<div>max_connections = 100</div>
<div>shared_buffers = 10000</div>
<div> </div>
<div>query (the person_id = 1 in the where clause is changed on a case by
case basis - depending upon who's running the query):</div>
<div> </div>
<div>explain analyze<BR> SELECT DISTINCT c.job_id, g.person_id,
c.job_no, b.deadline, c.name, bid_date(c.job_id) AS bid_date, c.miscq,
c.city, c.st, j.name AS eng, c.s_team AS salesteam,
<BR>
CASE<BR>
WHEN c.file_loc = 0 THEN 'No Bid'::character
varying<BR>
WHEN c.file_loc = -1 THEN 'Bid Board'::character
varying<BR>
WHEN c.file_loc = -2 THEN 'Lost Job'::character
varying<BR>
WHEN c.file_loc = -3 THEN 'See Job Notes'::character
varying<BR>
WHEN c.file_loc < -3 OR c.file_loc IS NULL THEN ''::character
varying<BR>
WHEN h.initials IS NOT NULL THEN
h.initials<BR>
ELSE 'Unknown person'::character
varying<BR> END AS file_loc,
COALESCE(c.city::text || COALESCE(', '::text || c.st::text, ''::text),
COALESCE(c.st, ''::character varying)::text) AS "location", c.file_loc
AS file_loc_id<BR> FROM status a<BR> LEFT JOIN
status_list b ON a.status_id = b.status_id AND b.active<BR>
LEFT JOIN job c ON c.job_id = b.job_id<BR> LEFT JOIN
builder_list d ON c.job_id = d.job_id AND (d.won_heat OR d.won_vent OR
d.won_tc OR c.heat AND d.bid_heat AND d.won_heat IS NULL OR c.vent AND
d.bid_vent AND d.won_vent IS NULL OR c.tc AND d.bid_tc AND d.won_tc IS
NULL) AND d.role = 'C'::bpchar<BR> LEFT JOIN company e ON
d.company_id = e.company_id<BR> LEFT JOIN call_list f ON
e.company_id = f.company_id<BR> LEFT JOIN person g ON
f.person_id = g.person_id OR "position"(c.s_team::text,
g.initials::text) > 0<BR> LEFT JOIN person h ON
c.file_loc = h.person_id<BR> LEFT JOIN builder_list i ON
c.job_id = i.job_id AND i.role = 'E'::bpchar<BR> LEFT JOIN
company j ON i.company_id = j.company_id<BR> WHERE a.name::text =
'Awaiting Award'::character varying::text and g.person_id = 1<BR>
ORDER BY c.job_id, g.person_id, c.job_no, b.deadline, c.name,
bid_date(c.job_id), c.miscq, c.city, COALESCE(c.city::text ||
COALESCE(', '::text || c.st::text, ''::text), COALESCE(c.st,
''::character varying)::text), c.st, <BR>CASE<BR>
WHEN c.file_loc = 0 THEN 'No Bid'::character
varying<BR> WHEN c.file_loc = -1 THEN 'Bid
Board'::character varying<BR> WHEN c.file_loc = -2
THEN 'Lost Job'::character varying<BR> WHEN
c.file_loc = -3 THEN 'See Job Notes'::character
varying<BR> WHEN c.file_loc < -3 OR c.file_loc IS
NULL THEN ''::character varying<BR> WHEN h.initials
IS NOT NULL THEN h.initials<BR> ELSE 'Unknown
person'::character varying<BR>END, j.name, c.s_team,
c.file_loc;<BR></div>
<div>Tables:</div>
<div>status - 14 rows</div>
<div>status_list - 6566 rows</div>
<div>job - 2210 rows</div>
<div>builder_list - 9670 rows</div>
<div>company - 1249 rows</div>
<div>call_list - 4731 rows</div>
<div>person - 27 rows</div>
<div> </div>
<div>Primary keys:</div>
<div>any field with a "_id" suffix is a primary key; and thus is
implicitly indexed.</div>
<div> </div>
<div>Other indexes:</div>
<div>status_list(job_id) btree</div>
<div>status_list(status_id) btree</div>
<div>job(file_loc) btree</div>
<div>builder_list(company_id) btree</div>
<div>call_list(company_id) btree</div>
<div>call_list(person_id) btree</div>
<div>call_list(company_id) btree</div>
<div>person(company_id) btree</div>
<div> </div>
<div>explain analyze:</div>
<div>Unique (cost=1798.47..1809.38 rows=291 width=114) (actual
time=766.000..781.000 rows=566 loops=1)<BR> ->
Sort (cost=1798.47..1799.19 rows=291 width=114) (actual
time=766.000..766.000 rows=1473
loops=1)<BR> Sort Key:
c.job_id, g.person_id, c.job_no, b.deadline, c.name,
bid_date(c.job_id), c.miscq, c.city, COALESCE(((c.city)::text ||
COALESCE((', '::text || (c.st)::text), ''::text)), (COALESCE(c.st,
''::character varying))::text), c.st, CASE WHEN (c.fi
(..)<BR> -> Hash
Left Join (cost=1750.81..1786.56 rows=291 width=114) (actual
time=453.000..750.000 rows=1473
loops=1)<BR>
Hash Cond: ("outer".company_id =
"inner".company_id)<BR>
-> Merge Left Join (cost=1707.20..1722.53 rows=291
width=95) (actual time=437.000..484.000 rows=1473
loops=1)<BR>
Merge Cond: ("outer".job_id =
"inner".job_id)<BR>
-> Sort (cost=1382.44..1383.17 rows=291 width=91) (actual
time=406.000..406.000 rows=1473
loops=1)<BR>
Sort Key:
c.job_id<BR>
-> Hash Left Join (cost=1137.28..1370.53 rows=291
width=91) (actual time=234.000..390.000 rows=1473
loops=1)<BR>
Hash Cond: ("outer".file_loc =
"inner".person_id)<BR>
-> Nested Loop (cost=1135.94..1365.27 rows=291 width=84)
(actual time=234.000..390.000 rows=1473
loops=1)<BR>
Join Filter: (("inner".person_id = "outer".person_id) OR
("position"(("inner".s_team)::text, ("outer".initials)::text) >
0))<BR>
-> Seq Scan on person g (cost=0.00..1.34 rows=1 width=11)
(actual time=0.000..0.000 rows=1
loops=1)<BR>
Filter: (person_id =
1)<BR>
-> Merge Right Join (cost=1135.94..1349.74 rows=811
width=84) (actual time=234.000..297.000 rows=7490
loops=1)<BR>
Merge Cond: ("outer".company_id =
"inner".company_id)<BR>
-> Index Scan using idx_company_id_call_list on call_list
f (cost=0.00..189.80 rows=4731 width=8) (actual
time=0.000..15.000 rows=4731
loops=1)<BR>
-> Sort (cost=1135.94..1136.48 rows=214 width=84) (actual
time=234.000..234.000 rows=7490
loops=1)<BR>
Sort Key:
e.company_id<BR>
-> Merge Right Join (cost=1004.19..1127.66 rows=214
width=84) (actual time=203.000..219.000 rows=1569
loops=1)<BR>
Merge Cond: ("outer".company_id =
"inner".company_id)<BR>
-> Index Scan using company_pkey on company e
(cost=0.00..117.13 rows=1249 width=4) (actual time=0.000..0.000
rows=1249
loops=1)<BR>
-> Sort (cost=1004.19..1004.73 rows=214 width=84) (actual
time=203.000..203.000 rows=1569
loops=1)<BR>
Sort Key:
d.company_id<BR>
-> Hash Left Join (cost=633.74..995.91 rows=214 width=84)
(actual time=156.000..187.000 rows=1569
loops=1)<BR>
Hash Cond: ("outer".job_id =
"inner".job_id)<BR>
Join Filter: ("inner".won_heat OR "inner".won_vent OR "inner".won_tc OR
("outer".heat AND "inner".bid_heat AND ("inner".won_heat IS NULL)) OR
("outer".vent AND "inner".bid_vent AND ("inner
(..)<BR>
-> Merge Left Join (cost=368.17..381.60 rows=159
width=83) (actual time=78.000..93.000 rows=695
loops=1)<BR>
Merge Cond: ("outer".job_id =
"inner".job_id)<BR>
-> Sort (cost=168.31..168.71 rows=159 width=8) (actual
time=31.000..31.000 rows=695
loops=1)<BR>
Sort Key:
b.job_id<BR>
-> Nested Loop Left Join (cost=0.00..162.50 rows=159
width=8) (actual time=0.000..31.000 rows=695
loops=1)<BR>
Join Filter: ("outer".status_id =
"inner".status_id)<BR>
-> Seq Scan on status a (cost=0.00..1.18 rows=1 width=4)
(actual time=0.000..0.000 rows=1
loops=1)<BR>
Filter: ((name)::text = 'Awaiting
Award'::text)<BR>
-> Seq Scan on status_list b (cost=0.00..133.66 rows=2213
width=12) (actual time=0.000..15.000 rows=2210
loops=1)<BR>
Filter:
active<BR>
-> Sort (cost=199.86..205.39 rows=2210 width=79) (actual
time=47.000..47.000 rows=2194
loops=1)<BR>
Sort Key:
c.job_id<BR>
-> Seq Scan on job c (cost=0.00..77.10 rows=2210
width=79) (actual time=0.000..31.000 rows=2210
loops=1)<BR>
-> Hash (cost=202.88..202.88 rows=7475 width=14) (actual
time=78.000..78.000 rows=0
loops=1)<BR>
-> Seq Scan on builder_list d (cost=0.00..202.88
rows=7475 width=14) (actual time=0.000..15.000 rows=7517
loops=1)<BR>
Filter: (role =
'C'::bpchar)<BR>
-> Hash (cost=1.27..1.27 rows=27 width=11) (actual
time=0.000..0.000 rows=0
loops=1)<BR>
-> Seq Scan on person h (cost=0.00..1.27 rows=27
width=11) (actual time=0.000..0.000 rows=27
loops=1)<BR>
-> Sort (cost=324.76..330.25 rows=2196 width=8) (actual
time=31.000..31.000 rows=3044
loops=1)<BR>
Sort Key:
i.job_id<BR>
-> Seq Scan on builder_list i (cost=0.00..202.88
rows=2196 width=8) (actual time=0.000..31.000 rows=2153
loops=1)<BR>
Filter: (role =
'E'::bpchar)<BR>
-> Hash (cost=40.49..40.49 rows=1249 width=27) (actual
time=16.000..16.000 rows=0 loops=1)</div>
<div>
-> Seq Scan on company j (cost=0.00..40.49 rows=1249
width=27) (actual time=0.000..0.000 rows=1249 loops=1)<BR>Total
runtime: 781.000 ms<BR></div>