Thread: optimizer bent on full table scan
I have a strange problem with the optimizer from CVS checked out as of about a
week ago. It seems to be insisting on using a full table scan for a table
lookup where the full table scan is about 20x slower than an index lookup.
I think somehow it's being confused by the fact that some values of the index
are populated and others haven't been so the distribution is odd. But I've
tried various things, including analyze, vacuum analyze, setting the
statistics very high for that column. random_page_cost is set to 2 currently.
slo=> alter table foobartab alter foobar_id set statistics 1000;
ALTER TABLE
Time: 73.76 ms
slo=> vacuum analyze foobartab;
VACUUM
Time: 53054.77 ms
slo=> explain analyze select count(*) from foobartab where foobar_id = 900;
2003-02-21 23:58:44 [17296] LOG: query: explain analyze select count(*) from foobartab where foobar_id = 900;
2003-02-21 23:58:47 [17296] LOG: duration: 2.570358 sec
QUERY PLAN
---------------------------------------------------------------------------------------------------------------------
Aggregate (cost=15815.51..15815.51 rows=1 width=0) (actual time=2558.09..2558.09 rows=1 loops=1)
-> Seq Scan on foobartab (cost=0.00..15793.61 rows=8757 width=0) (actual time=76.76..2528.03 rows=8721 loops=1)
Filter: (foobar_id = 900)
Total runtime: 2558.34 msec
(4 rows)
Time: 2579.09 ms
slo=> set enable_seqscan = off;
SET
Time: 3.98 ms
slo=> explain analyze select count(*) from foobartab where foobar_id = 900;
QUERY PLAN
----------------------------------------------------------------------------------------------------------------------------------------
Aggregate (cost=16136.09..16136.09 rows=1 width=0) (actual time=123.86..123.86 rows=1 loops=1)
-> Index Scan using idx_foobartab on foobartab (cost=0.00..16114.20 rows=8757 width=0) (actual time=0.09..87.33
rows=8721loops=1)
Index Cond: (foobar_id = 900)
Total runtime: 124.11 msec
(4 rows)
Time: 147.74 ms
slo=> select * from pg_stats where tablename = 'foobartab' and attname = 'foobar_id';
schemaname | tablename | attname | null_frac | avg_width | n_distinct |
most_common_vals
|
most_common_freqs
|
histogram_bounds
| correlation
------------+-----------+-----------+-----------+-----------+------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------
public | foobartab | foobar_id | 0 | 4 | 149 |
{940,920,870,860,990,800,900,840,780,820,2260,750,2200,730,830,720,680,700,760,570,660,620,710,690,640,740,590,610,560,2350,600,510,1000,480,540,580,2130,520,2010,2090,400,410,1960,630,390,370,380,2060,500,1010,1900,360,1750,250,200,1950,1020,190,260,550,210,230,220,1700,100,470,1030,90,80,70,350,240,1200,1220,1240,1230,1250,810,2300,1190,1260,2700,1270,1180,790,2660,2680,2230,1280,1510,910}
|
{0.0223267,0.02197,0.0217533,0.02146,0.0213167,0.0212,0.0211733,0.02111,0.02108,0.0210733,0.0209567,0.0209067,0.0206933,0.0206867,0.0205167,0.0204633,0.0204,0.0203233,0.0201267,0.0199433,0.0198867,0.01987,0.0198633,0.01986,0.0197667,0.0197633,0.0197133,0.01971,0.0194167,0.01864,0.0181433,0.0179767,0.01752,0.0161333,0.0157767,0.0129333,0.0128533,0.0124233,0.0120933,0.0115933,0.0107133,0.00932667,0.00915,0.00839667,0.00826667,0.00809,0.008,0.00685667,0.00684667,0.00636667,0.00592667,0.00586667,0.00586333,0.00574667
,0.00567333,0.00547,0.00527,0.00518333,0.00498,0.00496667,0.00493667,0.00487333,0.00472,0.00419,0.00394667,0.00386333,0.00362667,0.00353,0.00352333,0.00326,0.0032,0.00247,0.00246,0.00238333,0.00235,0.00233667,0.00233667,0.00232,0.00226667,0.00217667,0.00217667,0.00210667,0.00184667,0.00173,0.00165,0.00129333,0.00123667,0.00118667,0.00106,0.00103333,0.00102333}
|
{30,30,40,40,270,270,280,290,300,300,330,340,420,420,420,650,650,890,890,930,950,950,970,970,980,980,1040,1040,1060,1170,1170,1690,1690,1740,1760,1760,1770,1770,1770,1790,1790,1800,1810,1820,1830,1850,1850,1890,1890,2120,2140,2270,2270,2330,2360,2380,2490,2760}
| -0.0691708
(1 row)
--
greg
Greg Stark <gsstark@mit.edu> writes:
> I have a strange problem with the optimizer from CVS checked out as of about a
> week ago. It seems to be insisting on using a full table scan for a table
> lookup where the full table scan is about 20x slower than an index lookup.
> I think somehow it's being confused by the fact that some values of the index
> are populated and others haven't been so the distribution is odd.
Well, it's doing a heck of a good job of estimating the number of
matching rows --- can't complain about 8757 vs 8721. So there's some
other failure of modeling here. The only idea that comes to mind is
that maybe the rows matching foobar_id = 900 are tightly clustered in
the table, so that the planner's assumption of random fetches is overly
pessimistic. But the small correlation value says that there's not much
overall structure in the table's ordering. Can you shed any light on
that?
regards, tom lane
Your results do not necessarily demonstrate that the table scan is
indeed slower in this case then an index scan. It may be that the time
difference you see has to do with caching - after the first explain
analyze the entire table gets cached, so the second query is much faster
because it does not need much disk access.
Try running those two explains in the opposite order - first without
seqscan, and then with seqscan - you may get opposite results then...
Dima
P.S. How many rows are in that table?
Greg Stark wrote:
> I have a strange problem with the optimizer from CVS checked out as of about a
> week ago. It seems to be insisting on using a full table scan for a table
> lookup where the full table scan is about 20x slower than an index lookup.
>
> I think somehow it's being confused by the fact that some values of the index
> are populated and others haven't been so the distribution is odd. But I've
> tried various things, including analyze, vacuum analyze, setting the
> statistics very high for that column. random_page_cost is set to 2 currently.
>
>
> slo=> alter table foobartab alter foobar_id set statistics 1000;
> ALTER TABLE
> Time: 73.76 ms
>
>
> slo=> vacuum analyze foobartab;
> VACUUM
> Time: 53054.77 ms
>
>
> slo=> explain analyze select count(*) from foobartab where foobar_id = 900;
> 2003-02-21 23:58:44 [17296] LOG: query: explain analyze select count(*) from foobartab where foobar_id = 900;
> 2003-02-21 23:58:47 [17296] LOG: duration: 2.570358 sec
> QUERY PLAN
> ---------------------------------------------------------------------------------------------------------------------
> Aggregate (cost=15815.51..15815.51 rows=1 width=0) (actual time=2558.09..2558.09 rows=1 loops=1)
> -> Seq Scan on foobartab (cost=0.00..15793.61 rows=8757 width=0) (actual time=76.76..2528.03 rows=8721 loops=1)
> Filter: (foobar_id = 900)
> Total runtime: 2558.34 msec
> (4 rows)
>
> Time: 2579.09 ms
>
>
> slo=> set enable_seqscan = off;
> SET
> Time: 3.98 ms
>
>
> slo=> explain analyze select count(*) from foobartab where foobar_id = 900;
> QUERY PLAN
>
----------------------------------------------------------------------------------------------------------------------------------------
> Aggregate (cost=16136.09..16136.09 rows=1 width=0) (actual time=123.86..123.86 rows=1 loops=1)
> -> Index Scan using idx_foobartab on foobartab (cost=0.00..16114.20 rows=8757 width=0) (actual time=0.09..87.33
rows=8721loops=1)
> Index Cond: (foobar_id = 900)
> Total runtime: 124.11 msec
> (4 rows)
>
> Time: 147.74 ms
>
>
> slo=> select * from pg_stats where tablename = 'foobartab' and attname = 'foobar_id';
> schemaname | tablename | attname | null_frac | avg_width | n_distinct |
most_common_vals
|
most_common_freqs
>
|
histogram_bounds
| correlation
>
------------+-----------+-----------+-----------+-----------+------------+------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
--
>
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-------------
> public | foobartab | foobar_id | 0 | 4 | 149 |
{940,920,870,860,990,800,900,840,780,820,2260,750,2200,730,830,720,680,700,760,570,660,620,710,690,640,740,590,610,560,2350,600,510,1000,480,540,580,2130,520,2010,2090,400,410,1960,630,390,370,380,2060,500,1010,1900,360,1750,250,200,1950,1020,190,260,550,210,230,220,1700,100,470,1030,90,80,70,350,240,1200,1220,1240,1230,1250,810,2300,1190,1260,2700,1270,1180,790,2660,2680,2230,1280,1510,910}
|
{0.0223267,0.02197,0.0217533,0.02146,0.0213167,0.0212,0.0211733,0.02111,0.02108,0.0210733,0.0209567,0.0209067,0.0206933,0.0206867,0.0205167,0.0204633,0.0204,0.0203233,0.0201267,0.0199433,0.0198867,0.01987,0.0198633,0.01986,0.0197667,0.0197633,0.0197133,0.01971,0.0194167,0.01864,0.0181433,0.0179767,0.01752,0.0161333,0.0157767,0.0129333,0.0128533,0.0124233,0.0120933,0.0115933,0.0107133,0.00932667,0.00915,0.00839667,0.00826667,0.00809,0.008,0.00685667,0.00684667,0.00636667,0.00592667,0.00586667,0.00586333,0.005746
67
>
,0.00567333,0.00547,0.00527,0.00518333,0.00498,0.00496667,0.00493667,0.00487333,0.00472,0.00419,0.00394667,0.00386333,0.00362667,0.00353,0.00352333,0.00326,0.0032,0.00247,0.00246,0.00238333,0.00235,0.00233667,0.00233667,0.00232,0.00226667,0.00217667,0.00217667,0.00210667,0.00184667,0.00173,0.00165,0.00129333,0.00123667,0.00118667,0.00106,0.00103333,0.00102333}
|
{30,30,40,40,270,270,280,290,300,300,330,340,420,420,420,650,650,890,890,930,950,950,970,970,980,980,1040,1040,1060,1170,1170,1690,1690,1740,1760,1760,1770,1770,1770,1790,1790,1800,1810,1820,1830,1850,1850,1890,1890,2120,2140,2270,2270,2330,2360,2380,2490,2760}
| -0.0691708
> (1 row)
Tom Lane <tgl@sss.pgh.pa.us> writes: > Greg Stark <gsstark@mit.edu> writes: > > I have a strange problem with the optimizer from CVS checked out as of about a > > week ago. It seems to be insisting on using a full table scan for a table > > lookup where the full table scan is about 20x slower than an index lookup. > > > I think somehow it's being confused by the fact that some values of the index > > are populated and others haven't been so the distribution is odd. > > Well, it's doing a heck of a good job of estimating the number of > matching rows --- can't complain about 8757 vs 8721. So there's some > other failure of modeling here. The only idea that comes to mind is > that maybe the rows matching foobar_id = 900 are tightly clustered in > the table, so that the planner's assumption of random fetches is overly > pessimistic. But the small correlation value says that there's not much > overall structure in the table's ordering. Can you shed any light on > that? Hm, that's hard to say. The table was originally populated by a job that loops through a sequential scan of the parent table around and inserts all the records for a given foobar_id in a single insert. So presumably those records would end up together though the foobar_id's might not be in sequential order which might skew the correlation. I guess correlation works well for range scans but isn't really a good substitute for measuring the "clustering" that's relevant for scans on =. But even so I'm surprised it's even close. The selectivity is about 2% and I've even lowered random_page_cost from the default, so it seems like even with very scattered records it would still be worthwhile using an index. slo=> select count(*) from foobartab; count -------- 406849 (1 row) Time: 31650.87 ms slo=> select count(*) from foobartab where foobar_id = 900; count ------- 8721 (1 row) Time: 5213.82 ms -- greg