Thread: Optimizer(?) off by factor of 3 ... ?
Or is this in the planner? Same query, same tables, one with seqscan enabled, one with it disabled (btw, whomever added the ANALYZE to EXPLAIN, pure genius): iwantu=# explain analyze SELECT poc.uid,headline,pictures,voice FROM orient poc JOIN clubs c ON (poc.uid = c.uid AND c.club= 3 ); NOTICE: QUERY PLAN: Nested Loop (cost=0.00..1791417.52 rows=26566 width=72) (actual time=0.55..3345.13 rows=23510 loops=1) -> Index Scan usingclubs_idx on clubs c (cost=0.00..1695474.62 rows=26569 width=64) (actual time=0.48..1936.95 rows=23510 loops=1) -> Index Scan using orient_pkey on orient poc (cost=0.00..3.60 rows=1 width=8) (actual time=0.03..0.03 rows=1 loops=23510) Total runtime: 3474.93 msec iwantu=# set enable_seqscan=true; iwantu=# explain analyze SELECT poc.uid,headline,pictures,voice FROM orient poc JOIN clubs c ON (poc.uid = c.uid AND c.club= 3 ); NOTICE: QUERY PLAN: Hash Join (cost=31693.56..47033.86 rows=26566 width=72) (actual time=1044.41..11450.85 rows=23510 loops=1) -> Seq Scanon orient poc (cost=0.00..7718.69 rows=485969 width=8) (actual time=0.01..3484.00 rows=485969 loops=1) -> Hash (cost=31627.14..31627.14rows=26569 width=64) (actual time=1034.14..1034.14 rows=0 loops=1) -> Seq Scan on clubs c (cost=0.00..31627.14 rows=26569 width=64) (actual time=593.80..836.72 rows=23510 loops=1) Total runtime: 11583.36 msec
"Marc G. Fournier" <scrappy@hub.org> writes: > -> Index Scan using clubs_idx on clubs c (cost=0.00..1695474.62 rows=26569 width=64) (actual time=0.48..1936.95 rows=23510loops=1) This indexscan cost estimate is completely out of whack, it would seem. Have you done an ANALYZE on this table recently? If so, what do you get fromselect * from pg_stats where tablename = 'clubs';select * from pg_class where relname = 'clubs'; regards, tom lane
On Mon, 11 Feb 2002, Tom Lane wrote: > "Marc G. Fournier" <scrappy@hub.org> writes: > > -> Index Scan using clubs_idx on clubs c (cost=0.00..1695474.62 rows=26569 width=64) (actual time=0.48..1936.95 rows=23510loops=1) > > This indexscan cost estimate is completely out of whack, it would seem. > > Have you done an ANALYZE on this table recently? If so, what do you get Yup, been doing ANALYZEs just to make sure that I did them, so have done several since this database/table was populated ... > from > select * from pg_stats where tablename = 'clubs'; > select * from pg_class where relname = 'clubs'; tablename | attname | null_frac | avg_width | n_distinct | most_common_vals | most_common_freqs | ! histogram_bounds ! | correlation -----------+---------------+-----------+-----------+------------+-----------------------------------------------------------------------------------------------------------------+--------------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------! -----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------! ----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------- clubs | uid | 0 | 8 | -1 | | | {13,56847,365368,432334,482114,538111,627969,683193,738091,793220,841391} ! ! | 0.596839 clubs | club | 0 | 4 | 3 | {2,1,3} | {0.754,0.195333,0.0506667} | ! ! | 1 clubs | hide | 0 | 2 | 2 | {1,0} | {0.950667,0.0493333} | ! ! | 0.810325 clubs | last_update | 0 | 8 | 7731 | {1008005872,1009714469,1009688701,1011503100,1011330301,1009256700,1009429504,1011848704,1009885559,1010207101}| {0.735,0.004,0.00266667,0.00233333,0.002,0.00166667,0.00166667,0.00166667,0.00133333,0.00133333}| {1007584989,1008125462,1008569460,1009199787,1009651136,1010099882,1010466300,1010887647,1011224456,1011537512,1011853900} ! ! | 0.691723 clubs | category | 0 | 30 | 7 | {"{1,0,0,0,5}","{0,0,0,4,0}","{0,0,0,0,0}","{0,0,0,4,5}","{1,2,0,0,0}","{1,2,3,4,5}","{1,2,3,4,0}"} | {0.316333,0.268667,0.169,0.139333,0.056,0.0256667,0.025} | ! ! | clubs | club_interest | 0 | 44 | 1 | {"{0,0,0,0,0,0,0,0,0,0,0,0}"} | {1} | ! ! | clubs | headline | 0 | 28 | 27663 | {"","looking for fun",Hello,hi,Hi,hello,Looking,"Lookingfor fun",hey,"Hello Ladies"} | {0.103,0.00566667,0.004,0.004,0.00366667,0.00333333,0.00166667,0.00166667,0.00166667,0.00133333}| {" ANGEL EYES","Cum getsum","Hell-o Iam hear,take me away.","IF YOU LIKE A LAUGH IM YOU MAN THANX","Looking for a man with a Heart","Nice guyjust looking to meet new people","Tall Dark & Handsome","come and say hi","im 6 180 brown brown luv sex makeing girlsfeel good","nice guy looking for a loving relationship with no games","ý looking good friend"} ! ! | -0.0150456 clubs | my_desc | 0 | 230 | 29320 | {""," "} | {0.103,0.001} | {" <BR> <BR> english speaking man searching for partner in norway near oslo <BR> <BR> <BR>are single and miss you <BR> <BR> <BR> lets share the lonely nights ","Drop me a line . U will not regretcoz u just meet a chance of a lifetime ...Still thinking ?still wondering ? stop ! Write to me now and i'll get backto u !","I am 35. I love good sex. I enjoy candle light, showers, baths, oil massages, give and recieve. I don't needintercourse to be satisfied. I think you need to use your imagination if you don't.","I am intelligent,well-read,kind,emotional, have a good sense of humor. I dislike egoism,pettiness and dishonesty.","I'm 23 inNotting Hill, looking for a woman older or younger for an int! imate secret encounter. I'm 5'11, dark hair, blue eyes, slim build. I regularly work out in the gym, and am ready to havea work out in you.","Im a hard working man who would like a very <BR>sexy attractive women to share good times <BR>withhere in South Florida. Walks by the <BR>Ocean, fine dining and just hanging out <BR>together would be nice.","Notinto ego trips or head games. I'm in a comfortable place in my life where I don't have to prove myself personallyor professionally. I just desire to enjoy life and its many different venues.","blue eye red head - thus the namefoxxy ... Looking for you to share whatever your hearts desire might be ...","i am single libyan man , friendship meansmore to me , so i long to do good and wide friendship , i wish all over the world , so if you want to talk with me thisis my email <BR>abdul_zr@yahoo.com","looking for fun and cassual sex with serious ladies 'your pleasure is mine also'ifyou want to get crazy and have real fun in a! safe manner call me ",ÐԸеط½¿ÉÊǼè¿àµ«ÊÇÃDzÅСÁË¿Éû£¬³¤£¬¿É·¢µÄÃÀÀö£¬¿´¼û²Ð¿á·ßÅû£¬´óÅ®³§²Å£¬ÏÂÃæÄÔ½îÀ©´ó·¨¡£Àñò£¬·À¡£nmcjdkf´ó½¼Ü¿É¿¿ÁË£¬½â·ÅµØź½Ú£¬Âí³ÝÜÈÁ½¿Ú×Ó£»µÀ·£»Å®²Ð¿áϲ»¶·ßÅ¿É·¢µÄ¼¸Å¶µÄÁË£»Å®·½´òÆÆ£»} | -0.0011142 clubs | ur_desc | 0 | 4 | 1 | {""} | {1} | ! ! | 1 clubs | pictures | 0 | 26 | 2 | {"{0,0,0}","{1,0,0}"} | {0.889,0.111} | ! ! | clubs | voice | 0 | 2 | 2 | {0,1} | {0.999333,0.000666667} | ! ! | 0.998169 (11 rows) relname | reltype | relowner | relam | relfilenode | relpages | reltuples | reltoastrelid | reltoastidxid | relhasindex| relisshared | relkind | relnatts | relchecks | reltriggers | relukeys | relfkeys | relrefs | relhasoids | relhaspkey| relhasrules | relhassubclass | relacl ---------+---------+----------+-------+-------------+----------+-----------+---------------+---------------+-------------+-------------+---------+----------+-----------+-------------+----------+----------+---------+------------+------------+-------------+----------------+-------- clubs | 5535242 | 1003 | 0 | 5535241 | 25552 | 486011 | 5535243 | 0 | t | f | r | 11 | 0 | 0 | 0 | 0 | 0 | t | f |f | f | (1 row) And just in case it has relevance: iwantu=# \d clubs_idx Index "clubs_idx" Column | Type --------+--------- uid | bigint club | integer btree
I'm trying to work out how the planner arrived at the numbers you're showing; the hashjoin cost estimate seems a little lower than I'd expect. Are you using nonstandard values for any of the planner cost factors? (cpu_operator_cost, etc) How about sort_mem? regards, tom lane
the postgresql.conf file ... for testing, I used 'set enable_seqscan' after the server was live to turn on/off, this is just hte default ... tcpip_socket = true max_connections = 200 # 1-1024 port = 5434 sort_mem = 4024 shared_buffers = 32768 fsync = false wal_buffers = 32 debug_pretty_print = true enable_seqscan = false On Mon, 11 Feb 2002, Tom Lane wrote: > I'm trying to work out how the planner arrived at the numbers you're > showing; the hashjoin cost estimate seems a little lower than I'd > expect. Are you using nonstandard values for any of the planner cost > factors? (cpu_operator_cost, etc) How about sort_mem? > > regards, tom lane >
"Marc G. Fournier" <scrappy@hub.org> writes: > [ bogus optimizer choices in 7.2 ] Well, I guess the good news is we seem to be past the old bugaboo of bad statistics: the estimated row counts are all in the right ballpark. Now we get to have fun with the cost models :-). It looks to me like there are a couple of problems here. One is that the default value of effective_cache_size is way too small --- it's set at 1000, which is probably silly when you have NBuffers set to 32768. (In hindsight maybe we should have expressed it as a multiple of NBuffers rather than an absolute size.) You could tweak that with a postgresql.conf change, but I'm not sure that that alone will help much. The more difficult issue is that nestloops with inner indexscan are being seriously misestimated. We're computing the cost as though each iteration of the inner scan were completely independent and being done from a standing start --- which is wrong, because in practice scans after the first will tend to find buffer cache hits for pages already read in by prior scans. You can bet, for example, that the btree metapage and root page aren't going to need to be re-read on each iteration. I am thinking that the right way to do this is to cost the entire inner indexscan (all iterations put together) as if it were a single indexscan, at least for the purposes of applying the Mackert & Lohman formula embedded in cost_index. That would give us a more realistic result for the total cost of the main-table accesses driven by the index. Not sure how to adjust the cost estimate for reading the index, but clearly we need to make some adjustment for repeated hits on the upper index pages. This is probably a bigger change than we can hope to make in 7.2.* ... BTW, what do you get if you EXPLAIN ANALYZE that orient/clubs join with seqscan enabled and hashjoin disabled? If it's a mergejoin, how about if you also disable mergejoin? It seems to me that a seqscan on clubs would be a much better way to do the nestloop join than an indexscan --- but it's being forced into an indexscan because you disabled seqscan. regards, tom lane
On Mon, 11 Feb 2002, Tom Lane wrote: > "Marc G. Fournier" <scrappy@hub.org> writes: > > [ bogus optimizer choices in 7.2 ] > > Well, I guess the good news is we seem to be past the old bugaboo of bad > statistics: the estimated row counts are all in the right ballpark. Now > we get to have fun with the cost models :-). > > It looks to me like there are a couple of problems here. One is that > the default value of effective_cache_size is way too small --- it's set > at 1000, which is probably silly when you have NBuffers set to 32768. > (In hindsight maybe we should have expressed it as a multiple of > NBuffers rather than an absolute size.) You could tweak that with a > postgresql.conf change, but I'm not sure that that alone will help much. > > The more difficult issue is that nestloops with inner indexscan are > being seriously misestimated. We're computing the cost as though each > iteration of the inner scan were completely independent and being done > from a standing start --- which is wrong, because in practice scans > after the first will tend to find buffer cache hits for pages already > read in by prior scans. You can bet, for example, that the btree > metapage and root page aren't going to need to be re-read on each > iteration. > > I am thinking that the right way to do this is to cost the entire inner > indexscan (all iterations put together) as if it were a single > indexscan, at least for the purposes of applying the Mackert & Lohman > formula embedded in cost_index. That would give us a more realistic > result for the total cost of the main-table accesses driven by the > index. Not sure how to adjust the cost estimate for reading the index, > but clearly we need to make some adjustment for repeated hits on the > upper index pages. > > This is probably a bigger change than we can hope to make in 7.2.* ... > > BTW, what do you get if you EXPLAIN ANALYZE that orient/clubs join > with seqscan enabled and hashjoin disabled? If it's a mergejoin, > how about if you also disable mergejoin? It seems to me that a seqscan > on clubs would be a much better way to do the nestloop join than an > indexscan --- but it's being forced into an indexscan because you > disabled seqscan. iwantu=# set enable_seqscan=true; iwantu=# set enable_hashjoin=false; iwantu=# explain analyze SELECT o.uid,headline,pictures,voice FROM orient o JOIN clubs c ON (o.uid = c.uid AND c.club = 1AND ( c.hide ='1' OR c.hide='2' ) AND (o.female) ); NOTICE: QUERY PLAN: Merge Join (cost=97750.86..100011.74 rows=78391 width=72) (actual time=17041.33..23771.57 rows=50745 loops=1) -> Sort (cost=53412.61..53412.61 rows=422145 width=8) (actual time=12996.56..15563.59 rows=418951 loops=1) -> Seq Scan onorient o (cost=0.00..7718.69 rows=422145 width=8) (actual time=0.02..3237.46 rows=418951 loops=1) -> Sort (cost=44338.25..44338.25rows=90251 width=64) (actual time=4044.65..4531.18 rows=76954 loops=1) -> Seq Scan on clubsc (cost=0.00..34057.19 rows=90251 width=64) (actual time=0.04..1399.83 rows=76954 loops=1) Total runtime: 24082.76 msec iwantu=# set enable_mergejoin=false; iwantu=# explain analyze SELECT o.uid,headline,pictures,voice FROM orient o JOIN clubs c ON (o.uid = c.uid AND c.club = 1AND ( c.hide ='1' OR c.hide='2' ) AND (o.female) ); NOTICE: QUERY PLAN: Nested Loop (cost=0.00..363373.00 rows=78391 width=72) (actual time=0.54..5488.15 rows=50745 loops=1) -> Seq Scan on clubsc (cost=0.00..34057.19 rows=90251 width=64) (actual time=0.03..1434.97 rows=76954 loops=1) -> Index Scan using orient_pkeyon orient o (cost=0.00..3.64 rows=1 width=8) (actual time=0.03..0.03 rows=1 loops=76954) Total runtime: 5769.21 msec
Okay, I've 'saved' the dataset/schema for this if you want me to test/try anything further with it, as I'm going to try and redo teh schema to get around the issues for now ... On Mon, 11 Feb 2002, Tom Lane wrote: > "Marc G. Fournier" <scrappy@hub.org> writes: > > [ bogus optimizer choices in 7.2 ] > > Well, I guess the good news is we seem to be past the old bugaboo of bad > statistics: the estimated row counts are all in the right ballpark. Now > we get to have fun with the cost models :-). > > It looks to me like there are a couple of problems here. One is that > the default value of effective_cache_size is way too small --- it's set > at 1000, which is probably silly when you have NBuffers set to 32768. > (In hindsight maybe we should have expressed it as a multiple of > NBuffers rather than an absolute size.) You could tweak that with a > postgresql.conf change, but I'm not sure that that alone will help much. > > The more difficult issue is that nestloops with inner indexscan are > being seriously misestimated. We're computing the cost as though each > iteration of the inner scan were completely independent and being done > from a standing start --- which is wrong, because in practice scans > after the first will tend to find buffer cache hits for pages already > read in by prior scans. You can bet, for example, that the btree > metapage and root page aren't going to need to be re-read on each > iteration. > > I am thinking that the right way to do this is to cost the entire inner > indexscan (all iterations put together) as if it were a single > indexscan, at least for the purposes of applying the Mackert & Lohman > formula embedded in cost_index. That would give us a more realistic > result for the total cost of the main-table accesses driven by the > index. Not sure how to adjust the cost estimate for reading the index, > but clearly we need to make some adjustment for repeated hits on the > upper index pages. > > This is probably a bigger change than we can hope to make in 7.2.* ... > > BTW, what do you get if you EXPLAIN ANALYZE that orient/clubs join > with seqscan enabled and hashjoin disabled? If it's a mergejoin, > how about if you also disable mergejoin? It seems to me that a seqscan > on clubs would be a much better way to do the nestloop join than an > indexscan --- but it's being forced into an indexscan because you > disabled seqscan. > > regards, tom lane >