Re: Planner selects slow "Bitmap Heap Scan" when "Index Scan" is faster

Hi all

On Fri, Apr 6, 2012 at 19:11, Jeff Janes <jeff.janes@gmail.com> wrote:
> On Wed, Apr 4, 2012 at 6:47 AM, Kim Hansen <kim@rthansen.dk> wrote:
>> Hi All
>>
>> I have a query where the planner makes a wrong cost estimate, it looks
>> like it underestimates the cost of a "Bitmap Heap Scan" compared to an
>> "Index Scan".
>>
>> This it the two plans, I have also pasted them below:
>>  Slow (189ms): http://explain.depesz.com/s/2Wq
>>  Fast (21ms): http://explain.depesz.com/s/ThQ
>
> Could you do explain (analyze, buffers)?

I have done that now, the log is pasted in below. It looks like every
buffer fetched is a hit, I would think that PostgreSQL should know
that as almost nothing happens on the server and effective_cache_size
is configured to 8GB.

> Did you run these queries multiple times in both orders?  If you just
> ran them once each, in the order indicated, then the bitmap scan may
> have done the hard work of reading all the needed buffers into cache,
> and the index scan then got to enjoy that cache.

I have run the queries a few times in order to warm up the caches, the
queries stabilise on 20ms and 180ms.

Regards,
Kim

========

yield=> explain (analyze,buffers) select "filtered_demands"."pol" as
"c0" from "demands"."filtered_demands" as "filtered_demands" where
("filtered_demands"."pod" = 'VELAG') group by "filtered_demands"."pol"
order by "filtered_demands"."pol" ASC NULLS LAST;

 QUERY PLAN

-----------------------------------------------------------------------------------------------------------------------------------------------------------
 Sort  (cost=38564.80..38564.80 rows=2 width=6) (actual
time=185.497..185.520 rows=221 loops=1)
   Sort Key: pol
   Sort Method: quicksort  Memory: 35kB
   Buffers: shared hit=14969
   ->  HashAggregate  (cost=38564.77..38564.79 rows=2 width=6) (actual
time=185.303..185.343 rows=221 loops=1)
         Buffers: shared hit=14969
         ->  Bitmap Heap Scan on filtered_demands
(cost=566.23..38503.77 rows=24401 width=6) (actual time=6.119..179.056
rows=18588 loops=1)
               Recheck Cond: (pod = 'VELAG'::text)
               Buffers: shared hit=14969
               ->  Bitmap Index Scan on filtered_demands_pod_pol_idx
(cost=0.00..560.12 rows=24401 width=0) (actual time=4.661..4.661
rows=18588 loops=1)
                     Index Cond: (pod = 'VELAG'::text)
                     Buffers: shared hit=74
 Total runtime: 185.577 ms
(13 rows)

yield=> set enable_bitmapscan = false;
SET
yield=> explain (analyze,buffers) select "filtered_demands"."pol" as
"c0" from "demands"."filtered_demands" as "filtered_demands" where
("filtered_demands"."pod" = 'VELAG') group by "filtered_demands"."pol"
order by "filtered_demands"."pol" ASC NULLS LAST;

     QUERY PLAN

------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Group  (cost=0.00..76534.33 rows=2 width=6) (actual
time=0.029..20.202 rows=221 loops=1)
   Buffers: shared hit=18386
   ->  Index Scan using filtered_demands_pod_pol_idx on
filtered_demands  (cost=0.00..76473.33 rows=24401 width=6) (actual
time=0.027..16.455 rows=18588 loops=1)
         Index Cond: (pod = 'VELAG'::text)
         Buffers: shared hit=18386
 Total runtime: 20.246 ms
(6 rows)



--
Kim Rydhof Thor Hansen
Vadgårdsvej 3, 2. tv.
2860 Søborg
Phone: +45 3091 2437