Subject: Re: Bitmap scan is undercosted?
To: Jeff Janes <jeff.janes@gmail.com>, Tom Lane <tgl@sss.pgh.pa.us>
Cc: Justin Pryzby <pryzby@telsasoft.com>,
 pgsql-performance@lists.postgresql.org
References: <73a4936d-2814-dc08-ed0c-978f76f435b0@gmail.com>
 <20171201183427.GK18413@telsasoft.com> <20171201231104.GN18413@telsasoft.com>
 <d2b6a335-8c62-4983-3b5b-c8a75cf37d6f@gmail.com>
 <CAMkU=1wkjV3CjWE=Cksp_qSZhNbxTOcyc=dDuwhnDzVxGMu6qQ@mail.gmail.com>
 <f8edc163-7ebe-cdb8-d068-685355045f24@gmail.com>
 <CAMkU=1zGL7UZpaycNH1Zs=K-TuaJx4P5EmP2mZM3DHzy9JinHg@mail.gmail.com>
 <18188.1512258290@sss.pgh.pa.us>
 <CAMkU=1yKK0M4W+bNc31PZhH15dzPakSmpr6TH9exT8OUZvmg_w@mail.gmail.com>
From: Vitaliy Garnashevich <vgarnashevich@gmail.com>
Message-ID: <0a0bfd5f-06cc-918b-da75-4e45c4e8ea27@gmail.com>
Date: Mon, 4 Dec 2017 00:11:47 +0200
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:52.0) Gecko/20100101
 Thunderbird/52.5.0
MIME-Version: 1.0
In-Reply-To: 
 <CAMkU=1yKK0M4W+bNc31PZhH15dzPakSmpr6TH9exT8OUZvmg_w@mail.gmail.com>
Content-Type: multipart/alternative;
 boundary="------------680E8145918951260F30BBA8"
Content-Language: en-US
Precedence: bulk

This is a multi-part message in MIME format.
--------------680E8145918951260F30BBA8
Content-Type: text/plain; charset=utf-8; format=flowed
Content-Transfer-Encoding: 8bit

On 03/12/2017 03:27, Jeff Janes wrote:
> Due to that, when I disable bitmapscans and seqscans, I start getting 
> slow index scans on the wrong index, i2 rather than i1.  I don't know 
> why he doesn't see that in his example.
When I increase effective_cache_size to 1024MB, I start getting the plan 
with the slower index i2, too.

*Bitmap Heap Scan* on public.aaa  (cost=12600.90..*23688**.70* rows=9488 
width=5) (actual time=107.529..*115.902* rows=9976 loops=1)
   ->  BitmapAnd  (cost=12600.90..12600.90 rows=9488 width=0) (actual 
time=105.133..105.133 rows=0 loops=1)
         ->  Bitmap Index Scan on i1  (cost=0.00..1116.43 rows=96000 
width=0) (actual time=16.313..16.313 rows=100508 loops=1)
         ->  Bitmap Index Scan on i2  (cost=0.00..11479.47 rows=988338 
width=0) (actual time=77.950..77.950 rows=1000200 loops=1)

*Index Scan* using i2 on public.aaa  (cost=0.44..*48227.31* rows=9488 
width=5) (actual time=0.020..*285.695* rows=9976 loops=1)

*Seq Scan* on public.aaa  (cost=0.00..*169248.54* rows=9488 width=5) 
(actual time=0.024..*966.469* rows=9976 loops=1)

This way the estimates and the actual time get more sense. But then 
there's the question - maybe it's i1 runs too fast, and is estimated 
incorrectly? Why that happens?

Here are the complete plans with the two different kinds of index scans 
once again:

Index Scan using i1 on public.aaa  (cost=0.44..66621.56 rows=10340 
width=5) (actual time=0.027..47.075 rows=9944 loops=1)
   Output: num, flag
   Index Cond: (aaa.num = 1)
   Filter: aaa.flag
   Rows Removed by Filter: 89687
   Buffers: shared hit=39949
Planning time: 0.104 ms
Execution time: 47.351 ms

Index Scan using i2 on public.aaa  (cost=0.44..48227.31 rows=9488 
width=5) (actual time=0.020..285.695 rows=9976 loops=1)
   Output: num, flag
   Index Cond: (aaa.flag = true)
   Filter: (aaa.flag AND (aaa.num = 1))
   Rows Removed by Filter: 990224
   Buffers: shared hit=46984
Planning time: 0.098 ms
Execution time: 286.081 ms


// The test DB was populated with: create table aaa as select 
floor(random()*100)::int num, (random()*10 < 1)::bool flag from 
generate_series(1, 10000000) id;

Regards,
Vitaliy


--------------680E8145918951260F30BBA8
Content-Type: text/html; charset=utf-8
Content-Transfer-Encoding: 8bit

<html>
  <head>
    <meta http-equiv="Content-Type" content="text/html; charset=utf-8">
  </head>
  <body text="#000000" bgcolor="#FFFFFF">
    <div class="moz-cite-prefix">On 03/12/2017 03:27, Jeff Janes wrote:<br>
    </div>
    <blockquote type="cite"
cite="mid:CAMkU=1yKK0M4W+bNc31PZhH15dzPakSmpr6TH9exT8OUZvmg_w@mail.gmail.com">
      <div dir="ltr">
        <div class="gmail_extra">
          <div class="gmail_quote">Due to that, when I disable
            bitmapscans and seqscans, I start getting slow index scans
            on the wrong index, i2 rather than i1.  I don't know why he
            doesn't see that in his example.</div>
        </div>
      </div>
    </blockquote>
    When I increase effective_cache_size to 1024MB, I start getting the
    plan with the slower index i2, too.<br>
    <br>
    <b>Bitmap Heap Scan</b> on public.aaa  (cost=12600.90..<b>23688</b><b>.70</b>
    rows=9488 width=5) (actual time=107.529..<b>115.902</b> rows=9976
    loops=1)<br>
      -&gt;  BitmapAnd  (cost=12600.90..12600.90 rows=9488 width=0)
    (actual time=105.133..105.133 rows=0 loops=1)<br>
            -&gt;  Bitmap Index Scan on i1  (cost=0.00..1116.43
    rows=96000 width=0) (actual time=16.313..16.313 rows=100508 loops=1)<br>
            -&gt;  Bitmap Index Scan on i2  (cost=0.00..11479.47
    rows=988338 width=0) (actual time=77.950..77.950 rows=1000200
    loops=1)<br>
    <br>
    <b>Index Scan</b> using i2 on public.aaa  (cost=0.44..<b>48227.31</b>
    rows=9488 width=5) (actual time=0.020..<b>285.695</b> rows=9976
    loops=1)<br>
    <br>
    <b>Seq Scan</b> on public.aaa  (cost=0.00..<b>169248.54</b>
    rows=9488 width=5) (actual time=0.024..<b>966.469</b> rows=9976
    loops=1)<br>
    <br>
    This way the estimates and the actual time get more sense. But then
    there's the question - maybe it's i1 runs too fast, and is estimated
    incorrectly? Why that happens?<br>
    <br>
    Here are the complete plans with the two different kinds of index
    scans once again:<br>
    <br>
    Index Scan using i1 on public.aaa  (cost=0.44..66621.56 rows=10340
    width=5) (actual time=0.027..47.075 rows=9944 loops=1)<br>
      Output: num, flag<br>
      Index Cond: (aaa.num = 1)<br>
      Filter: aaa.flag<br>
      Rows Removed by Filter: 89687<br>
      Buffers: shared hit=39949<br>
    Planning time: 0.104 ms<br>
    Execution time: 47.351 ms<br>
    <br>
    Index Scan using i2 on public.aaa  (cost=0.44..48227.31 rows=9488
    width=5) (actual time=0.020..285.695 rows=9976 loops=1)<br>
      Output: num, flag<br>
      Index Cond: (aaa.flag = true)<br>
      Filter: (aaa.flag AND (aaa.num = 1))<br>
      Rows Removed by Filter: 990224<br>
      Buffers: shared hit=46984<br>
    Planning time: 0.098 ms<br>
    Execution time: 286.081 ms<br>
    <br>
    <br>
    // The test DB was populated with: create table aaa as select
    floor(random()*100)::int num, (random()*10 &lt; 1)::bool flag from
    generate_series(1, 10000000) id;<br>
    <br>
    Regards,<br>
    Vitaliy<br>
    <br>
  </body>
</html>

--------------680E8145918951260F30BBA8--