Thread: Bad planner decision - bitmap scan instead of index

Bad planner decision - bitmap scan instead of index

From
Frank Schoep
Date:
Hello everyone,

This being my first e-mail to the mailing list, I hope my question is
relevant and on-topic. I'm seeing poor performance on a few queries
where the planner decides to use a bitmap scan instead of using indices.

I'm using a stock PostgreSQL 8.1.9 on Debian 4.0r0 (x86). The
database is vacuumed and analyzed daily ("full") and testing on a
different machine (stock 8.1.9 on Ubuntu 6.06 LTS (x86)) gave the
same results. I've made sure the data for each query was cached.

The (example) query:
SELECT * FROM movies WHERE letter = 'T' ORDER BY name ASC LIMIT 100
OFFSET 1900;
is run on a single table "movies" (~ 250.000 rows) with the following
structure and indices:

                                        Table "public.movies"
   Column  |            Type             |
Modifiers
----------+-----------------------------
+-----------------------------------------------------------
movie_id | integer                     | not null default nextval
('movies_movie_id_seq'::regclass)
name     | character varying(255)      | not null
year     | integer                     | not null
views    | integer                     | not null default 0
lastview | timestamp without time zone |
letter   | character(1)                | not null default 'A'::bpchar
Indexes:
     "movies_pkey" PRIMARY KEY, btree (movie_id)
     "movies_lastview" btree (lastview)
     "movies_letter" btree (letter)
     "movies_letter_name" btree (letter, name)
     "movies_name" btree (name)
     "movies_year" btree ("year")

Running the query using EXPLAIN ANALYZE results in the following
query plan and execution time:

Limit  (cost=4002.04..4002.29 rows=100 width=48) (actual
time=1469.565..1470.097 rows=100 loops=1)
    ->  Sort  (cost=3997.29..4031.18 rows=13556 width=48) (actual
time=1460.958..1467.993 rows=2000 loops=1)
          Sort Key: name
          ->  Bitmap Heap Scan on movies  (cost=86.45..3066.90
rows=13556 width=48) (actual time=20.522..77.889 rows=13640 loops=1)
                Recheck Cond: (letter = 'T'::bpchar)
                ->  Bitmap Index Scan on movies_letter
(cost=0.00..86.45 rows=13556 width=0) (actual time=18.452..18.452
rows=13658 loops=1)
                      Index Cond: (letter = 'T'::bpchar)
Total runtime: 1474.821 ms

Setting enable_bitmapscan to 0 results in the following plan and
execution time:

Limit  (cost=5041.06..5306.38 rows=100 width=48) (actual
time=15.385..16.305 rows=100 loops=1)
    ->  Index Scan using movies_letter_name on movies
(cost=0.00..35966.65 rows=13556 width=48) (actual time=0.121..14.067
rows=2000 loops=1)
          Index Cond: (letter = 'T'::bpchar)
Total runtime: 16.604 ms

Seeing that disabling the bitmap scan speeds up the query about fifty
times, it would be interesting to know what is causing the planner to
decide to not use the appropriate index.

If anyone could comment a bit on my example, that would be great.
There's a few things I'm considering regarding this:
- I could disable bitmap scan altogether, per application or query,
but that does not seem elegant, I'd rather have the query planner
make better decisions
- I could try and test what 8.2 does if someone expects the results
to be different, but I can't yet upgrade my production servers to 8.2
- am I just running into a corner case which falls outside of the
planner's logic?

Thanks in advance for your efforts and replies.

With kind regards,

Frank Schoep


Re: Bad planner decision - bitmap scan instead of index

From
Tom Lane
Date:
Frank Schoep <frank@ffnn.nl> writes:
> Limit  (cost=4002.04..4002.29 rows=100 width=48) (actual
> time=1469.565..1470.097 rows=100 loops=1)
>     ->  Sort  (cost=3997.29..4031.18 rows=13556 width=48) (actual
> time=1460.958..1467.993 rows=2000 loops=1)
>           Sort Key: name
>           ->  Bitmap Heap Scan on movies  (cost=86.45..3066.90
> rows=13556 width=48) (actual time=20.522..77.889 rows=13640 loops=1)
>                 Recheck Cond: (letter = 'T'::bpchar)
>                 ->  Bitmap Index Scan on movies_letter
> (cost=0.00..86.45 rows=13556 width=0) (actual time=18.452..18.452
> rows=13658 loops=1)
>                       Index Cond: (letter = 'T'::bpchar)
> Total runtime: 1474.821 ms

Why is the sort step so slow? Sorting a mere 13k rows shouldn't take
very long.  Maybe you are overrunning work_mem and it's falling back
to a disk sort ... what is work_mem set to?

Another theory is that you are using a locale in which strcoll() is
horridly expensive :-(

            regards, tom lane

Re: Bad planner decision - bitmap scan instead of index

From
Frank Schoep
Date:
On Aug 16, 2007, at 7:01 PM, Tom Lane wrote:
> …
> Why is the sort step so slow? Sorting a mere 13k rows shouldn't take
> very long.  Maybe you are overrunning work_mem and it's falling back
> to a disk sort ... what is work_mem set to?

By default work_mem is set to "1024". Increasing the value to "8192"
halves the execution time, still leaving a factor twenty-five
performance decrease compared to using the index. The machine I'm
testing this on is a very modest Pentium 3 at 450 MHz.

> Another theory is that you are using a locale in which strcoll() is
> horridly expensive :-(

Running 'locale' indicates I'm using "en_US.UTF-8" with language
"en_NL:en". My databases all use the UTF8 encoding.

Sincerely,

Frank

Re: Bad planner decision - bitmap scan instead of index

From
hubert depesz lubaczewski
Date:
On Thu, Aug 16, 2007 at 06:14:02PM +0200, Frank Schoep wrote:
> The (example) query:
> SELECT * FROM movies WHERE letter = 'T' ORDER BY name ASC LIMIT 100
> OFFSET 1900;

try to change the query to:
SELECT * FROM movies WHERE letter = 'T' ORDER BY letter ASC, name ASC LIMIT 100
OFFSET 1900;

depesz

--
quicksil1er: "postgres is excellent, but like any DB it requires a
highly paid DBA.  here's my CV!" :)
http://www.depesz.com/ - blog dla ciebie (i moje CV)

Re: Bad planner decision - bitmap scan instead of index

From
Frank Schoep
Date:
On Aug 17, 2007, at 9:28 AM, hubert depesz lubaczewski wrote:
> …
> try to change the query to:
> SELECT * FROM movies WHERE letter = 'T' ORDER BY letter ASC, name
> ASC LIMIT 100
> OFFSET 1900;

Thanks for the suggestion, however executing this query takes even
longer regardless of work_mem. The query leads to this plan:

Limit  (cost=4320.68..4320.93 rows=100 width=48) (actual
time=2137.764..2138.294 rows=100 loops=1)
    ->  Sort  (cost=4315.93..4351.49 rows=14221 width=48) (actual
time=2129.755..2136.184 rows=2000 loops=1)
          Sort Key: letter, name
          ->  Bitmap Heap Scan on movies  (cost=90.77..3067.54
rows=14221 width=48) (actual time=20.277..89.913 rows=13640 loops=1)
                Recheck Cond: (letter = 'T'::bpchar)
                ->  Bitmap Index Scan on movies_letter
(cost=0.00..90.77 rows=14221 width=0) (actual time=18.139..18.139
rows=13644 loops=1)
                      Index Cond: (letter = 'T'::bpchar)
Total runtime: 2143.111 ms

To compare, that same query (sorting by two columns) without bitmap
scan runs like this:

Limit  (cost=5025.26..5289.75 rows=100 width=48) (actual
time=14.986..15.911 rows=100 loops=1)
    ->  Index Scan using movies_letter_name on movies
(cost=0.00..37612.76 rows=14221 width=48) (actual time=0.125..13.686
rows=2000 loops=1)
          Index Cond: (letter = 'T'::bpchar)
Total runtime: 16.214 ms

I'm not an expert at how the planner decides which query plan to use,
but it seems that in my (corner?) case bitmap scan shouldn't be
preferred over the index scan, as the index is pre-sorted and spans
all columns involved in the 'WHERE' and 'ORDER BY' clauses.

Regarding the sort performance and work_mem size I have tested the
same scenario on a second machine (dual P3-1.13 GHz) with work_mem
set to 8192, using the same PostgreSQL version. The query plans are
identical and running times are ~300ms for the bitmap scan and ~5ms
for index scan.

Sincerely,

Frank

Re: Bad planner decision - bitmap scan instead of index

From
Michael Stone
Date:
On Fri, Aug 17, 2007 at 10:43:18AM +0200, Frank Schoep wrote:
>On Aug 17, 2007, at 9:28 AM, hubert depesz lubaczewski wrote:
>(cost=0.00..37612.76 rows=14221 width=48) (actual time=0.125..13.686
>rows=2000 loops=1)
[snip]
>I'm not an expert at how the planner decides which query plan to use,

Neither am I. :) I do notice that the estimated number of rows is
significantly larger than the real number; you may want to bump up your
statistics a bit to see if it can estimate better.

Mike Stone

Re: Bad planner decision - bitmap scan instead of index

From
Frank Schoep
Date:
On Aug 17, 2007, at 5:23 PM, Michael Stone wrote:
> On Fri, Aug 17, 2007 at 10:43:18AM +0200, Frank Schoep wrote:
>> On Aug 17, 2007, at 9:28 AM, hubert depesz lubaczewski wrote:
>> (cost=0.00..37612.76 rows=14221 width=48) (actual
>> time=0.125..13.686  rows=2000 loops=1)
> [snip]
>> I'm not an expert at how the planner decides which query plan to use,
>
> Neither am I. :) I do notice that the estimated number of rows is
> significantly larger than the real number; you may want to bump up
> your statistics a bit to see if it can estimate better.

I think the actual number of 2000 rows is based on the LIMIT (100)
and OFFSET (1900) clauses. 14K rows will have to be sorted, but only
2000 have to actually be returned for PostgreSQL to be able to
satisfy the request.

A few weeks ago I set default_statistics_target to 50 to try and
nudge the planner into making better judgments, but apparently this
doesn't influence the planner in the desired way.

Should I try upping that value even more? I took 50 because the
'letter' column only has uppercase letters or digits (36 different
values). 50 seemed a good value for reasonable estimates.

Sincerely,

Frank