pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feedmis-estimate in nested query causes slow runtimes
6+ messages / 2 participants
[nested] [flat]
* mis-estimate in nested query causes slow runtimes
@ 2008-02-11 22:24 Chris Kratz <chris.kratz@vistashare.com>
0 siblings, 1 reply; 6+ messages in thread
From: Chris Kratz @ 2008-02-11 22:24 UTC (permalink / raw)
To: pgsql-performance
Hello,
I've been wrestling w/ a complex query for another developer for
awhile today. The problem consistently seems to a mis-estimation of
the number of rows resulting from a join. This causes the query early
on to think it's only going to be processing 1 row and so it chooses
nested loops much of the way up the chain. I've messed w/ statistics
targets on some of the columns w/ no increase in the accuracy of the
estimates. I've analyzed the tables in question (autovac is
running). If I turn off nested loops, the query runs in 1.5 seconds.
Otherwise it takes about 37s. With other criteria in the where clause
it can take many minutes to return. Here is a subset of the explain
analyze that I'm wrestling with. The entire explain is at the end of
the email.
-> Nested Loop (cost=42.74..161.76 rows=1 width=38) (actual
time=2.932..27.772 rows=20153 loops=1)
-> Hash Join (cost=10.89..22.58 rows=1 width=24) (actual
time=0.065..0.134 rows=1 loops=1)
Hash Cond: (mtchsrcprj3.funding_source_id =
mtchsrcprjfs3.nameid)
-> Seq Scan on project mtchsrcprj3 (cost=0.00..11.22
rows=122 width=8) (actual time=0.002..0.054 rows=122 loops=1)
-> Hash (cost=10.83..10.83 rows=5 width=24) (actual
time=0.017..0.017 rows=1 loops=1)
-> Index Scan using name_float_lfm_idx on
namemaster mtchsrcprjfs3 (cost=0.00..10.83 rows=5 width=24) (actual
time=0.012..0.013 rows=1 loops=1)
Index Cond: (name_float_lfm = 'DWS'::text)
-> Bitmap Heap Scan on transaction_details idatrndtl
(cost=31.85..121.60 rows=1407 width=22) (actual time=2.864..12.060
rows=20153 loops=1)
Recheck Cond: (idatrndtl.ida_trans_match_source_id =
mtchsrcprj3.id)
-> Bitmap Index Scan on
transaction_details_ida_trans_match_source_id (cost=0.00..31.50
rows=1407 width=0) (actual time=2.696..2.696 rows=20153 loops=1)
Index Cond: (idatrndtl.ida_trans_match_source_id =
mtchsrcprj3.id)
The first frustration is that I can't get the transaction details scan
to get any more accurate. It thinks it will find 1407 records,
instead it finds 20,153. Then for whatever reason it thinks that a
join between 1 record and 1407 records will return 1 record. This is
mainly what I can't understand. Why does it think it will only get
one record in response when it's a left join?
The thing is that we've had this happen a number of times recently
with complex nested queries. Most of the time things will run very
quickly, but an early mis-estimation by the planner causes it to use
nested loops exclusively when hash joins would be more appropriate.
Is there anything I can do to improve this short of the set
enable_nestloop=off?
PG 8.2.4 on Linux kernel 2.6.9 x64
-Chris
------- Full explain analyze -----
Group (cost=336.76..336.82 rows=1 width=328) (actual
time=36620.831..36621.176 rows=248 loops=1)
-> Sort (cost=336.76..336.76 rows=1 width=328) (actual
time=36620.828..36620.888 rows=248 loops=1)
Sort Key: county, fullname_last_first_mdl, ((((CASE WHEN
(COALESCE(fullname_last_first_mdl, '0'::text) = '0'::text) THEN
''::text ELSE COALESCE(fullname_last_first_mdl, '0'::text) END || '
'::text) || '-'::text) || ' '::text) || CASE WHEN (COALESCE(ssn,
'0'::text) = '0'::text) THEN ''::text ELSE COALESCE(ssn, '0'::text)
END), system_name_id, ssn, ida_account_id,
ida_account_match_source_funding_source_name_float_lfm,
ida_account_status, vs_query_27453_212267, vs_query_27453_212252,
vs_query_27453_212253, vs_query_27453_212254, vs_query_27453_212255,
(COALESCE(vs_query_27453_212267, 0::numeric) +
COALESCE(vs_query_27453_212255, 0::numeric))
-> Subquery Scan foo (cost=336.72..336.75 rows=1
width=328) (actual time=36614.750..36615.319 rows=248 loops=1)
-> Sort (cost=336.72..336.72 rows=1 width=255)
(actual time=36614.737..36614.798 rows=248 loops=1)
Sort Key: cou.validvalue, dem.name_float_lfm
-> Nested Loop Left Join (cost=194.80..336.71
rows=1 width=255) (actual time=506.599..36611.702 rows=248 loops=1)
-> Nested Loop Left Join
(cost=194.80..332.90 rows=1 width=242) (actual time=506.566..36606.528
rows=248 loops=1)
Join Filter: (acc.id =
qry27453.ida_account_id)
-> Nested Loop (cost=30.16..168.13
rows=1 width=82) (actual time=0.461..27.079 rows=248 loops=1)
-> Nested Loop
(cost=30.16..167.85 rows=1 width=90) (actual time=0.453..25.133
rows=248 loops=1)
-> Nested Loop
(cost=30.16..165.94 rows=1 width=77) (actual time=0.441..19.687
rows=970 loops=1)
-> Nested Loop
(cost=30.16..162.90 rows=1 width=40) (actual time=0.429..11.405
rows=970 loops=1)
-> Hash
Join (cost=30.16..162.48 rows=1 width=32) (actual time=0.417..4.524
rows=970 loops=1)
Hash
Cond: (accmtchgrp.match_group_id = mtchsrc2.match_group_id)
->
Seq Scan on ida_account_match_sources accmtchgrp (cost=0.00..117.26
rows=3926 width=8) (actual time=0.010..1.597 rows=3933 loops=1)
->
Hash (cost=30.15..30.15 rows=1 width=24) (actual time=0.315..0.315
rows=1 loops=1)
-
> Hash Join (cost=22.59..30.15 rows=1 width=24) (actual
time=0.228..0.309 rows=1 loops=1)
Hash
Cond: (mtchsrc2.project_id = mtchsrcprj2.id)
->
Seq Scan on ida_match_sources mtchsrc2 (cost=0.00..6.85 rows=185
width=8) (actual time=0.004..0.065 rows=185 loops=1)
->
Hash (cost=22.58..22.58 rows=1 width=24) (actual time=0.162..0.162
rows=1 loops=1)
->
Hash Join (cost=10.89..22.58 rows=1 width=24) (actual
time=0.091..0.155 rows=1 loops=1)
Hash
Cond: (mtchsrcprj2.funding_source_id = mtchsrcprjfs2.nameid)
->
Seq Scan on project mtchsrcprj2 (cost=0.00..11.22 rows=122
width=8) (actual time=0.005..0.060 rows=122 loops=1)
->
Hash (cost=10.83..10.83 rows=5 width=24) (actual time=0.039..0.039
rows=1 loops=1)
->
Index Scan using name_float_lfm_idx on namemaster mtchsrcprjfs2
(cost=0.00..10.83 rows=5 width=24) (actual time=0.028..0.030 rows=1
loops=1)
Index
Cond: (name_float_lfm = 'DWS'::text)
-> Index
Scan using accounts_pkey on accounts acc (cost=0.00..0.41 rows=1
width=12) (actual time=0.005..0.005 rows=1 loops=970)
Index
Cond: (acc.id = accmtchgrp.account_id)
Filter: (program_id = 221)
-> Index Scan
using nameid_pk on namemaster dem (cost=0.00..3.02 rows=1 width=41)
(actual time=0.006..0.007 rows=1 loops=970)
Index Cond:
(acc.owner_id = dem.nameid)
Filter:
(programid = 221)
-> Index Scan using
validanswerid_pk on validanswer accsts (cost=0.00..1.91 rows=1
width=21) (actual time=0.004..0.005 rows=0 loops=970)
Index Cond:
(acc.ida_account_status_id = accsts.validanswerid)
Filter:
(validvalue = 'Open'::text)
-> Index Scan using
ida_match_groups_pkey on ida_match_groups mtchgrp2 (cost=0.00..0.27
rows=1 width=4) (actual time=0.003..0.006 rows=1 loops=248)
Index Cond:
(accmtchgrp.match_group_id = mtchgrp2.id)
-> GroupAggregate
(cost=164.63..164.75 rows=1 width=129) (actual time=1.635..147.391
rows=230 loops=248)
-> Sort (cost=164.63..164.64
rows=1 width=129) (actual time=1.407..3.160 rows=4715 loops=248)
Sort Key:
foo.ida_account_id, foo.ida_account_status, foo.ida_match_rate
-> Sort
(cost=164.61..164.61 rows=1 width=82) (actual time=340.444..341.726
rows=4715 loops=1)
Sort Key: acc.id
-> Nested Loop
(cost=42.74..164.60 rows=1 width=82) (actual time=3.069..333.866
rows=4715 loops=1)
-> Nested
Loop (cost=42.74..164.29 rows=1 width=69) (actual time=3.062..310.340
rows=4715 loops=1)
->
Nested Loop (cost=42.74..162.38 rows=1 width=56) (actual
time=2.955..224.985 rows=20048 loops=1)
-
> Nested Loop (cost=42.74..162.09 rows=1 width=42) (actual
time=2.947..135.616 rows=20048 loops=1)
->
Nested Loop (cost=42.74..161.76 rows=1 width=38) (actual
time=2.932..27.772 rows=20153 loops=1)
->
Hash Join (cost=10.89..22.58 rows=1 width=24) (actual
time=0.065..0.134 rows=1 loops=1)
Hash
Cond: (mtchsrcprj3.funding_source_id = mtchsrcprjfs3.nameid)
->
Seq Scan on project mtchsrcprj3 (cost=0.00..11.22 rows=122
width=8) (actual time=0.002..0.054 rows=122 loops=1)
->
Hash (cost=10.83..10.83 rows=5 width=24) (actual time=0.017..0.017
rows=1 loops=1)
->
Index Scan using name_float_lfm_idx on namemaster mtchsrcprjfs3
(cost=0.00..10.83 rows=5 width=24) (actual time=0.012..0.013 rows=1
loops=1)
Index
Cond: (name_float_lfm = 'DWS'::text)
->
Bitmap Heap Scan on transaction_details idatrndtl
(cost=31.85..121.60 rows=1407 width=22) (actual time=2.864..12.060
rows=20153 loops=1)
Recheck
Cond: (idatrndtl.ida_trans_match_source_id = mtchsrcprj3.id)
->
Bitmap Index Scan on transaction_details_ida_trans_match_source_id
(cost=0.00..31.50 rows=1407 width=0) (actual time=2.696..2.696
rows=20153 loops=1)
Index
Cond: (idatrndtl.ida_trans_match_source_id = mtchsrcprj3.id)
->
Index Scan using transactions_pkey on transactions idatrn
(cost=0.00..0.31 rows=1 width=12) (actual time=0.003..0.004 rows=1
loops=20153)
Index
Cond: (idatrn.id = idatrndtl.transaction_id)
Filter
: (((transaction_date >= '2007-10-01'::date) OR (transaction_date <=
'2007-10-01'::date)) AND (transaction_date <= '2007-12-31'::date))
-
> Index Scan using accounts_pkey on accounts acc (cost=0.00..0.28
rows=1 width=18) (actual time=0.003..0.003 rows=1 loops=20048)
Index
Cond: (acc.id = idatrn.account_id)
Filter
: (program_id = 221)
->
Index Scan using validanswerid_pk on validanswer accsts
(cost=0.00..1.91 rows=1 width=21) (actual time=0.003..0.003 rows=0
loops=20048)
Index Cond: (acc.ida_account_status_id = accsts.validanswerid)
Filter: (validvalue = 'Open'::text)
-> Index
Scan using validanswerid_pk on validanswer trndtlcat (cost=0.00..0.29
rows=1 width=21) (actual time=0.003..0.004 rows=1 loops=4715)
Index
Cond: (idatrndtl.ida_trans_detail_category_id = trndtlcat.validanswerid)
Filter: (validvalue = ANY ('{"Match Withdrawal","Match Earned","Match
Interest"}'::text[]))
-> Index Scan using validanswerid_pk on
validanswer cou (cost=0.00..3.77 rows=1 width=21) (actual
time=0.011..0.012 rows=1 loops=248)
Index Cond: (cou.validanswerid =
dem.county)
Total runtime: 36622.135 ms
(73 rows)
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: mis-estimate in nested query causes slow runtimes
@ 2008-02-11 23:07 Tom Lane <tgl@sss.pgh.pa.us>
parent: Chris Kratz <chris.kratz@vistashare.com>
0 siblings, 3 replies; 6+ messages in thread
From: Tom Lane @ 2008-02-11 23:07 UTC (permalink / raw)
To: Chris Kratz <chris.kratz@vistashare.com>; +Cc: pgsql-performance
Chris Kratz <chris.kratz@vistashare.com> writes:
> -> Nested Loop (cost=42.74..161.76 rows=1 width=38) (actual
> time=2.932..27.772 rows=20153 loops=1)
> -> Hash Join (cost=10.89..22.58 rows=1 width=24) (actual
> time=0.065..0.134 rows=1 loops=1)
> Hash Cond: (mtchsrcprj3.funding_source_id =
> mtchsrcprjfs3.nameid)
> -> Seq Scan on project mtchsrcprj3 (cost=0.00..11.22
> rows=122 width=8) (actual time=0.002..0.054 rows=122 loops=1)
> -> Hash (cost=10.83..10.83 rows=5 width=24) (actual
> time=0.017..0.017 rows=1 loops=1)
> -> Index Scan using name_float_lfm_idx on
> namemaster mtchsrcprjfs3 (cost=0.00..10.83 rows=5 width=24) (actual
> time=0.012..0.013 rows=1 loops=1)
> Index Cond: (name_float_lfm = 'DWS'::text)
> -> Bitmap Heap Scan on transaction_details idatrndtl
> (cost=31.85..121.60 rows=1407 width=22) (actual time=2.864..12.060
> rows=20153 loops=1)
> Recheck Cond: (idatrndtl.ida_trans_match_source_id =
> mtchsrcprj3.id)
> -> Bitmap Index Scan on
> transaction_details_ida_trans_match_source_id (cost=0.00..31.50
> rows=1407 width=0) (actual time=2.696..2.696 rows=20153 loops=1)
> Index Cond: (idatrndtl.ida_trans_match_source_id =
> mtchsrcprj3.id)
> The first frustration is that I can't get the transaction details scan
> to get any more accurate. It thinks it will find 1407 records,
> instead it finds 20,153. Then for whatever reason it thinks that a
> join between 1 record and 1407 records will return 1 record. This is
> mainly what I can't understand. Why does it think it will only get
> one record in response when it's a left join?
I don't see any left join there ...
> PG 8.2.4 on Linux kernel 2.6.9 x64
The first thing you should do is update to 8.2.6; we've fixed a fair
number of problems since then that were fallout from the outer-join
planning rewrite in 8.2.
If it still doesn't work very well, please post the pg_stats rows for
the join columns involved (idatrndtl.ida_trans_match_source_id and
mtchsrcprj3.id). (You do have up-to-date ANALYZE stats for both
of those tables, right?)
regards, tom lane
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: mis-estimate in nested query causes slow runtimes
@ 2008-02-12 14:02 Chris Kratz <chris.kratz@vistashare.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
2 siblings, 0 replies; 6+ messages in thread
From: Chris Kratz @ 2008-02-12 14:02 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance
On 2/11/08, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> Chris Kratz <chris.kratz@vistashare.com> writes:
> > -> Nested Loop (cost=42.74..161.76 rows=1 width=38) (actual
> > time=2.932..27.772 rows=20153 loops=1)
> > -> Hash Join (cost=10.89..22.58 rows=1 width=24) (actual
> > time=0.065..0.134 rows=1 loops=1)
> > Hash Cond: (mtchsrcprj3.funding_source_id =
> > mtchsrcprjfs3.nameid)
> > -> Seq Scan on project mtchsrcprj3 (cost=0.00..11.22
> > rows=122 width=8) (actual time=0.002..0.054 rows=122 loops=1)
> > -> Hash (cost=10.83..10.83 rows=5 width=24) (actual
> > time=0.017..0.017 rows=1 loops=1)
> > -> Index Scan using name_float_lfm_idx on
> > namemaster mtchsrcprjfs3 (cost=0.00..10.83 rows=5 width=24) (actual
> > time=0.012..0.013 rows=1 loops=1)
> > Index Cond: (name_float_lfm = 'DWS'::text)
> > -> Bitmap Heap Scan on transaction_details idatrndtl
> > (cost=31.85..121.60 rows=1407 width=22) (actual time=2.864..12.060
> > rows=20153 loops=1)
> > Recheck Cond: (idatrndtl.ida_trans_match_source_id =
> > mtchsrcprj3.id)
> > -> Bitmap Index Scan on
> > transaction_details_ida_trans_match_source_id (cost=0.00..31.50
> > rows=1407 width=0) (actual time=2.696..2.696 rows=20153 loops=1)
> > Index Cond: (idatrndtl.ida_trans_match_source_id =
> > mtchsrcprj3.id)
>
> > The first frustration is that I can't get the transaction details scan
> > to get any more accurate. It thinks it will find 1407 records,
> > instead it finds 20,153. Then for whatever reason it thinks that a
> > join between 1 record and 1407 records will return 1 record. This is
> > mainly what I can't understand. Why does it think it will only get
> > one record in response when it's a left join?
>
> I don't see any left join there ...
>
> > PG 8.2.4 on Linux kernel 2.6.9 x64
>
> The first thing you should do is update to 8.2.6; we've fixed a fair
> number of problems since then that were fallout from the outer-join
> planning rewrite in 8.2.
>
> If it still doesn't work very well, please post the pg_stats rows for
> the join columns involved (idatrndtl.ida_trans_match_source_id and
> mtchsrcprj3.id). (You do have up-to-date ANALYZE stats for both
> of those tables, right?)
>
> regards, tom lane
>
Thanks Tom, we will try the upgrade and see if that makes a difference.
-Chris
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: mis-estimate in nested query causes slow runtimes
@ 2008-02-12 15:09 Chris Kratz <chris.kratz@vistashare.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
2 siblings, 0 replies; 6+ messages in thread
From: Chris Kratz @ 2008-02-12 15:09 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance
On 2/11/08, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> Chris Kratz <chris.kratz@vistashare.com> writes:
> > -> Nested Loop (cost=42.74..161.76 rows=1 width=38) (actual
> > time=2.932..27.772 rows=20153 loops=1)
> > -> Hash Join (cost=10.89..22.58 rows=1 width=24) (actual
> > time=0.065..0.134 rows=1 loops=1)
> > Hash Cond: (mtchsrcprj3.funding_source_id =
> > mtchsrcprjfs3.nameid)
> > -> Seq Scan on project mtchsrcprj3 (cost=0.00..11.22
> > rows=122 width=8) (actual time=0.002..0.054 rows=122 loops=1)
> > -> Hash (cost=10.83..10.83 rows=5 width=24) (actual
> > time=0.017..0.017 rows=1 loops=1)
> > -> Index Scan using name_float_lfm_idx on
> > namemaster mtchsrcprjfs3 (cost=0.00..10.83 rows=5 width=24) (actual
> > time=0.012..0.013 rows=1 loops=1)
> > Index Cond: (name_float_lfm = 'DWS'::text)
> > -> Bitmap Heap Scan on transaction_details idatrndtl
> > (cost=31.85..121.60 rows=1407 width=22) (actual time=2.864..12.060
> > rows=20153 loops=1)
> > Recheck Cond: (idatrndtl.ida_trans_match_source_id =
> > mtchsrcprj3.id)
> > -> Bitmap Index Scan on
> > transaction_details_ida_trans_match_source_id (cost=0.00..31.50
> > rows=1407 width=0) (actual time=2.696..2.696 rows=20153 loops=1)
> > Index Cond: (idatrndtl.ida_trans_match_source_id =
> > mtchsrcprj3.id)
>
> > The first frustration is that I can't get the transaction details scan
> > to get any more accurate. It thinks it will find 1407 records,
> > instead it finds 20,153. Then for whatever reason it thinks that a
> > join between 1 record and 1407 records will return 1 record. This is
> > mainly what I can't understand. Why does it think it will only get
> > one record in response when it's a left join?
>
> I don't see any left join there ...
>
> > PG 8.2.4 on Linux kernel 2.6.9 x64
>
> The first thing you should do is update to 8.2.6; we've fixed a fair
> number of problems since then that were fallout from the outer-join
> planning rewrite in 8.2.
>
> If it still doesn't work very well, please post the pg_stats rows for
> the join columns involved (idatrndtl.ida_trans_match_source_id and
> mtchsrcprj3.id). (You do have up-to-date ANALYZE stats for both
> of those tables, right?)
>
> regards, tom lane
I know it's somewhat premature as we haven't had a chance to do the update
yet, but here is what I did w/ the statistics with the current version for
chuckles and grins just to see if it would make a difference in the plan.
# alter table project alter column id set statistics 1000;
ALTER TABLE
# analyze project;
ANALYZE
# alter table transaction_details alter column ida_trans_match_source_id set
statistics 1000;
ALTER TABLE
# analyze transaction_details;
ANALYZE
# select * from pg_stats where (tablename='project' and attname='id') or
(tablename='transaction_details' and attname='ida_trans_match_source_id');
schemaname | tablename | attname | null_frac |
avg_width | n_distinct |
most_common_vals
|
most_common_freqs
|
histogram_bounds
| correlation
------------+---------------------+---------------------------+-----------+-----------+------------+------------------------------------------------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------
public | project | id | 0 |
4 | -1 |
|
|
{6,7,8,12,13,14,15,17,18,19,24,25,26,27,28,29,30,31,32,33,34,35,36,37,41,42,71,72,797,802,803,809,812,813,814,815,816,817,818,822,823,824,825,826,827,828,829,830,831,832,833,834,835,836,837,838,839,840,841,842,843,844,845,846,847,848,849,920,921,922,923,924,925,926,927,928,929,930,931,932,933,934,935,936,937,938,939,940,941,942,946,947,948,949,950,951,952,953,954,955,956,957,958,959,960,961,962,963,964,965,966,967,968,969,970,971,972,973,974,975,977,978}
| 0.939317
public | transaction_details | ida_trans_match_source_id | 0.480469 |
4 | 74 |
{832,818,930,937,923,812,931,829,837,830,836,14,809,838,936,924,921,922,814,816,817,827,815,941,835,967,926,813,968,928,920,939,925,974,833,965,933}
| {0.100562,0.100233,0.0412866,0.0245354,0.0223948,0.021277,0.0198998,
0.018817,0.0182431,0.0181583,0.0180236,0.0141714,0.0107633,0.00955071,
0.00917646,0.00639708,0.00562364,0.00491507,0.00453584,0.0037624,0.00332828,
0.00332828,0.00323846,0.00309874,0.00295403,0.00267959,0.00234526,0.00227041
,0.00221552,0.00220055,0.00215565,0.00207581,0.00179138,0.00136225,
0.00114269,0.00113271,0.00100796} |
{6,6,7,8,15,802,802,802,802,803,803,839,841,844,844,845,845,846,927,927,934,934,935,935,938,938,940,942,952,954,955,955,957,972,972,972,978}
| 0.218267
(2 rows)
This had no appreciable difference in the plan. Here is the part that seems
to be causing the problem again after the increase in stats. It still
thinks there is only one row in the result.
-> Nested Loop (cost=42.75..161.78 rows=1 width=38) (actual time=
391.797..425.337 rows=20153 loops=1)
-> Hash Join (cost=10.89..22.58 rows=1 width=24) (actual time=
0.069..0.139 rows=1 loops=1)
Hash Cond: (mtchsrcprj3.funding_source_id =
mtchsrcprjfs3.nameid)
-> Seq Scan on project mtchsrcprj3 (cost=0.00..11.22 rows=122
width=8) (actual time=0.002..0.054 rows=122 loops=1)
-> Hash (cost=10.83..10.83 rows=5 width=24) (actual time=
0.022..0.022 rows=1 loops=1)
-> Index Scan using name_float_lfm_idx on namemaster
mtchsrcprjfs3 (cost=0.00..10.83 rows=5 width=24) (actual
time=0.013..0.014rows=1 loops=1)
Index Cond: (name_float_lfm = 'DWS'::text)
-> Bitmap Heap Scan on transaction_details idatrndtl (cost=
31.87..121.61 rows=1407 width=22) (actual time=391.722..410.129 rows=20153
loops=1)
Recheck Cond: (idatrndtl.ida_trans_match_source_id =
mtchsrcprj3.id)
-> Bitmap Index Scan on
transaction_details_ida_trans_match_source_id (cost=0.00..31.51 rows=1407
width=0) (actual time=391.523..391.523 rows=20153 loops=1)
Index Cond: (idatrndtl.ida_trans_match_source_id =
mtchsrcprj3.id)
Here is the relevant snippet from the query
<-- snip -->
FROM
accounts acc
left join transactions idatrn on (acc.id = idatrn.account_id)
left join transaction_details idatrndtl on (idatrn.id =
idatrndtl.transaction_id)
left join project mtchsrcprj3 on (idatrndtl.ida_trans_match_source_id =
mtchsrcprj3.id)
left join namemaster mtchsrcprjfs3 on ( mtchsrcprj3.funding_source_id =
mtchsrcprjfs3.nameid)
<-- snip -->
I'll update again once we've had a chance to do the update.
-Chris
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: mis-estimate in nested query causes slow runtimes
@ 2008-02-18 19:32 Chris Kratz <chris.kratz@vistashare.com>
parent: Tom Lane <tgl@sss.pgh.pa.us>
2 siblings, 1 reply; 6+ messages in thread
From: Chris Kratz @ 2008-02-18 19:32 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance
On 2/11/08, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> Chris Kratz <chris.kratz@vistashare.com> writes:
> > The first frustration is that I can't get the transaction details scan
> > to get any more accurate. It thinks it will find 1407 records,
> > instead it finds 20,153. Then for whatever reason it thinks that a
> > join between 1 record and 1407 records will return 1 record. This is
> > mainly what I can't understand. Why does it think it will only get
> > one record in response when it's a left join?
>
> I don't see any left join there ...
>
> > PG 8.2.4 on Linux kernel 2.6.9 x64
>
> The first thing you should do is update to 8.2.6; we've fixed a fair
> number of problems since then that were fallout from the outer-join
> planning rewrite in 8.2.
>
> If it still doesn't work very well, please post the pg_stats rows for
> the join columns involved (idatrndtl.ida_trans_match_source_id and
> mtchsrcprj3.id). (You do have up-to-date ANALYZE stats for both
> of those tables, right?)
>
> regards, tom lane
>
Hello Tom,
We've updated to Postgres 8.2.6 on our production database over the weekend.
Unfortunately, the estimates on this query are no better after the upgrade.
Here is just the part of the estimate that is incorrect. (2 vs 20153)
-> Nested Loop (cost=12.68..165.69 rows=2 width=38) (actual time=
0.089..29.792 rows=20153 loops=1)
-> Hash Join (cost=12.68..24.37 rows=1 width=24) (actual time=
0.064..0.135 rows=1 loops=1)
Hash Cond: (mtchsrcprj3.funding_source_id = mtchsrcprjfs3.nameid
)
-> Seq Scan on project mtchsrcprj3 (cost=0.00..11.22 rows=122
width=8) (actual time=0.002..0.053 rows=122 loops=1)
-> Hash (cost=12.61..12.61 rows=6 width=24) (actual time=
0.017..0.017 rows=1 loops=1)
-> Index Scan using name_float_lfm_idx on namemaster
mtchsrcprjfs3 (cost=0.00..12.61 rows=6 width=24) (actual
time=0.012..0.013rows=1 loops=1)
Index Cond: (name_float_lfm = 'DWS'::text)
-> Index Scan using transaction_details_ida_trans_match_source_id on
transaction_details idatrndtl (cost=0.00..123.72 rows=1408 width=22)
(actual time=0.023..17.128 rows=20153 loops=1)
(Entire explain analyze posted earlier in thread)
Total Query runtime: 35309.298 ms
Same w/ enable_nestloop off: 761.715 ms
I've tried the stats up to 1000 on both columns which causes no differences.
Currently the stats are at 100.
test=# alter table transaction_details alter column
ida_trans_match_source_id set statistics 100;
ALTER TABLE
test=# analyze transaction_details;
ANALYZE
test=# alter table project alter column id set statistics 100;
ALTER TABLE
test=# analyze project;
ANALYZE
Stats rows in pg_stats for these two columns:
test=# select * from pg_stats where tablename = 'transaction_details' and
attname='ida_trans_match_source_id';
schemaname | tablename | attname | null_frac |
avg_width | n_distinct | most_common_vals
| most_common_freqs
|
histogram_bounds
| correlation
------------+---------------------+---------------------------+-----------+-----------+------------+------------------------------------------------------+-------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------
public | transaction_details | ida_trans_match_source_id | 0.479533 |
4 | 69 |
{818,832,930,937,923,812,931,836,837,829,830,14,809} | {0.1024,0.0991333,
0.0408,0.0232,0.0221,0.0219,0.0207,0.0188667,0.0186667,0.0177667,0.0176667,
0.0130333,0.0118667} |
{6,802,813,813,814,814,815,815,816,816,817,817,827,827,833,835,835,838,838,838,838,838,843,920,921,921,921,921,922,922,924,924,924,924,925,926,926,928,928,934,936,936,936,936,936,938,939,941,941,955,965,967,968,968,974,980}
| 0.178655
(1 row)
test=# select * from pg_stats where tablename = 'project' and attname='id';
schemaname | tablename | attname | null_frac | avg_width | n_distinct |
most_common_vals | most_common_freqs |
histogram_bounds
| correlation
------------+-----------+---------+-----------+-----------+------------+------------------+-------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------
public | project | id | 0 | 4 | -1 |
| |
{6,7,8,12,13,15,17,18,19,24,26,27,28,29,30,32,33,34,35,36,41,42,71,72,802,803,809,812,813,815,816,817,818,822,824,825,826,827,828,830,831,832,833,835,836,837,838,839,841,842,843,844,845,847,848,849,920,921,923,924,925,926,928,929,930,931,932,934,935,936,937,938,940,941,942,946,947,949,950,951,952,954,955,956,957,958,960,961,962,963,964,966,967,968,969,970,973,974,975,977,980}
| 0.937228
(1 row)
PG 8.2.6 on linux x86_64, 8G ram, 4x15k->db, 2x10k-> OS & WAL
postgresql.conf settings of note:
shared_buffers = 1024MB
work_mem = 246MB
maintenance_work_mem = 256MB
random_page_cost = 1.75
effective_cache_size=2048MB
Any ideas how we can get the query to run faster?
Thanks,
-Chris
^ permalink raw reply [nested|flat] 6+ messages in thread
* Re: mis-estimate in nested query causes slow runtimes
@ 2008-02-20 11:07 Chris Kratz <chris.kratz@vistashare.com>
parent: Chris Kratz <chris.kratz@vistashare.com>
0 siblings, 0 replies; 6+ messages in thread
From: Chris Kratz @ 2008-02-20 11:07 UTC (permalink / raw)
To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: pgsql-performance
On 2/18/08, Chris Kratz <chris.kratz@vistashare.com> wrote:
>
> On 2/11/08, Tom Lane <tgl@sss.pgh.pa.us> wrote:
> >
> > Chris Kratz <chris.kratz@vistashare.com> writes:
> > > The first frustration is that I can't get the transaction details scan
> > > to get any more accurate. It thinks it will find 1407 records,
> > > instead it finds 20,153. Then for whatever reason it thinks that a
> > > join between 1 record and 1407 records will return 1 record. This is
> > > mainly what I can't understand. Why does it think it will only get
> > > one record in response when it's a left join?
> >
> > I don't see any left join there ...
> >
> > > PG 8.2.4 on Linux kernel 2.6.9 x64
> >
> > The first thing you should do is update to 8.2.6; we've fixed a fair
> > number of problems since then that were fallout from the outer-join
> > planning rewrite in 8.2.
> >
> > If it still doesn't work very well, please post the pg_stats rows for
> > the join columns involved (idatrndtl.ida_trans_match_source_id and
> > mtchsrcprj3.id). (You do have up-to-date ANALYZE stats for both
> > of those tables, right?)
> >
> > regards, tom lane
> >
>
> Hello Tom,
>
>
> We've updated to Postgres 8.2.6 on our production database over the
> weekend. Unfortunately, the estimates on this query are no better after the
> upgrade. Here is just the part of the estimate that is incorrect. (2 vs
> 20153)
>
>
> -> Nested Loop (cost=12.68..165.69 rows=2 width=38) (actual time=
> 0.089..29.792 rows=20153 loops=1)
> -> Hash Join (cost=12.68..24.37 rows=1 width=24) (actual time=
> 0.064..0.135 rows=1 loops=1)
> Hash Cond: (mtchsrcprj3.funding_source_id =
> mtchsrcprjfs3.nameid)
> -> Seq Scan on project mtchsrcprj3 (cost=0.00..11.22rows=122 width=8) (actual time=
> 0.002..0.053 rows=122 loops=1)
> -> Hash (cost=12.61..12.61 rows=6 width=24) (actual time=
> 0.017..0.017 rows=1 loops=1)
> -> Index Scan using name_float_lfm_idx on namemaster
> mtchsrcprjfs3 (cost=0.00..12.61 rows=6 width=24) (actual time=
> 0.012..0.013 rows=1 loops=1)
> Index Cond: (name_float_lfm = 'DWS'::text)
> -> Index Scan using transaction_details_ida_trans_match_source_id
> on transaction_details idatrndtl (cost=0.00..123.72 rows=1408 width=22)
> (actual time=0.023..17.128 rows=20153 loops=1)
>
>
> (Entire explain analyze posted earlier in thread)
>
>
> Total Query runtime: 35309.298 ms
> Same w/ enable_nestloop off: 761.715 ms
>
>
> I've tried the stats up to 1000 on both columns which causes no
> differences. Currently the stats are at 100.
>
>
> test=# alter table transaction_details alter column
> ida_trans_match_source_id set statistics 100;
> ALTER TABLE
> test=# analyze transaction_details;
> ANALYZE
> test=# alter table project alter column id set statistics 100;
> ALTER TABLE
> test=# analyze project;
> ANALYZE
>
>
> Stats rows in pg_stats for these two columns:
>
>
> test=# select * from pg_stats where tablename = 'transaction_details' and
> attname='ida_trans_match_source_id';
> schemaname | tablename | attname | null_frac
> | avg_width | n_distinct | most_common_vals
> | most_common_freqs
> |
>
> histogram_bounds
> | correlation
>
> ------------+---------------------+---------------------------+-----------+-----------+------------+------------------------------------------------------+-------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------
> public | transaction_details | ida_trans_match_source_id | 0.479533| 4 | 69 |
> {818,832,930,937,923,812,931,836,837,829,830,14,809} | {0.1024,0.0991333,
> 0.0408,0.0232,0.0221,0.0219,0.0207,0.0188667,0.0186667,0.0177667,0.0176667
> ,0.0130333,0.0118667} |
> {6,802,813,813,814,814,815,815,816,816,817,817,827,827,833,835,835,838,838,838,838,838,843,920,921,921,921,921,922,922,924,924,924,924,925,926,926,928,928,934,936,936,936,936,936,938,939,941,941,955,965,967,968,968,974,980}
> | 0.178655
> (1 row)
>
>
> test=# select * from pg_stats where tablename = 'project' and
> attname='id';
> schemaname | tablename | attname | null_frac | avg_width | n_distinct |
> most_common_vals | most_common_freqs |
>
>
> histogram_bounds
>
> | correlation
>
> ------------+-----------+---------+-----------+-----------+------------+------------------+-------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------
> public | project | id | 0 | 4 | -1 |
> | |
> {6,7,8,12,13,15,17,18,19,24,26,27,28,29,30,32,33,34,35,36,41,42,71,72,802,803,809,812,813,815,816,817,818,822,824,825,826,827,828,830,831,832,833,835,836,837,838,839,841,842,843,844,845,847,848,849,920,921,923,924,925,926,928,929,930,931,932,934,935,936,937,938,940,941,942,946,947,949,950,951,952,954,955,956,957,958,960,961,962,963,964,966,967,968,969,970,973,974,975,977,980}
> | 0.937228
> (1 row)
>
>
> PG 8.2.6 on linux x86_64, 8G ram, 4x15k->db, 2x10k-> OS & WAL
>
>
> postgresql.conf settings of note:
>
>
> shared_buffers = 1024MB
> work_mem = 246MB
> maintenance_work_mem = 256MB
> random_page_cost = 1.75
> effective_cache_size=2048MB
>
>
> Any ideas how we can get the query to run faster?
>
>
> Thanks,
>
>
> -Chris
>
>
>
>
>
>
>
Tom, any further ideas? I appreciate your help so far, but we are still
stuck after the update to 8.2.6. Our only real solution at this point is to
add code to our application that turns off nested loops for specific reports
since the planner isn't getting correct estimates. I posted the pg_stat
rows as requested above.
Thanks,
-Chris
^ permalink raw reply [nested|flat] 6+ messages in thread
end of thread, other threads:[~2008-02-20 11:07 UTC | newest]
Thread overview: 6+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2008-02-11 22:24 mis-estimate in nested query causes slow runtimes Chris Kratz <chris.kratz@vistashare.com>
2008-02-11 23:07 ` Tom Lane <tgl@sss.pgh.pa.us>
2008-02-12 14:02 ` Chris Kratz <chris.kratz@vistashare.com>
2008-02-12 15:09 ` Chris Kratz <chris.kratz@vistashare.com>
2008-02-18 19:32 ` Chris Kratz <chris.kratz@vistashare.com>
2008-02-20 11:07 ` Chris Kratz <chris.kratz@vistashare.com>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox