Postgresql – Slow Bitmap Heap Scan, Order by killing the execution time

optimizationperformancepostgresqlpostgresql-performancequery-performance

A query that is going to slow on table users, the table has 5 million records, and for increasing query performance I often index function outputs of aggregated data that are convenient for each case, the function output are not jsonbs.

Postgres version 10.1

Schema:

CREATE TABLE users (
  id SERIAL PRIMARY KEY NOT NULL,
  social jsonb,
  flags text[],
  full_name text,
  email text,
  location jsonb,
  contact_info jsonb,
  created_at TIMESTAMP_WITHOUT TIME ZONE
);
CREATE INDEX available_channels_idx ON public.users USING gin (public.available_channels(social, contact_info));
CREATE INDEX mixed_frequent_locations_idx ON public.users USING gin (public.mixed_frequent_locations(location));
CREATE INDEX idx_in_social_follower_count ON public.users USING btree (public.social_follower_count(social) DESC NULLS LAST);
CREATE INDEX created_at_idx ON public.users USING btree (created_at);
CREATE INDEX idx_in_social_follower_count_and_created_at ON public.users USING btree (public.social_follower_count(social) DESC, created_at);

Slow Query (here the Bitmap Heap Scan remove too many rows by index Recheck):

EXPLAIN ANALYZE SELECT *  FROM users 
WHERE (social_follower_count(social) > '30000') 
  AND (engagement_level(social) <= 3) 
  AND (available_channels(social, contact_info) <@ array['yt']) 
  AND (has_emails(contact_info) = TRUE) 
  AND (not_business(social) = TRUE) 
  AND (array['United States'] <@ mixed_frequent_locations(location)) 
  AND (is_visible(social, flags) = TRUE)  
 ORDER BY social_follower_count(social) DESC, "users"."created_at" ASC 
 LIMIT 12 OFFSET 0;

This query returns 11616 results without applying any limit. The variable input of the query is array['United States'], has_emails(contact_info) = TRUE, array['yt'], social_follower_count(social) > '30000'

Query Plan:

Limit  (cost=59629.20..59629.23 rows=12 width=1531) (actual time=330055.413..330055.418 rows=12 loops=1)
   ->  Sort  (cost=59629.20..59629.69 rows=199 width=1531) (actual time=330055.411..330055.412 rows=12 loops=1)
         Sort Key: (social_follower_count(social)) DESC, created_at
         Sort Method: top-N heapsort  Memory: 65kB
         ->  Bitmap Heap Scan on users  (cost=24767.69..59624.63 rows=199 width=1531) (actual time=551.864..330000.716 rows=11616 loops=1)
               Recheck Cond: ((available_channels(social, contact_info) <@ '{yt}'::text[]) AND ('{"United States"}'::text[] <@ mixed_frequent_locations(location)) AND (social_follower_count(social) > 30000))
               Rows Removed by Index Recheck: 883451
               Filter: (has_emails(contact_info) AND not_business(social) AND is_visible(social, flags) AND (engagement_level(social) <= 3))
               Rows Removed by Filter: 9775
               Heap Blocks: exact=17001 lossy=132075
               ->  BitmapAnd  (cost=24767.69..24767.69 rows=6344 width=0) (actual time=422.660..422.660 rows=0 loops=1)
                     ->  Bitmap Index Scan on available_channels_idx  (cost=0.00..4046.06 rows=363475 width=0) (actual time=116.792..116.792 rows=442083 loops=1)
                           Index Cond: (available_channels(social, contact_info) <@ '{yt}'::text[])
                     ->  Bitmap Index Scan on mixed_frequent_locations_idx  (cost=0.00..5550.85 rows=617447 width=0) (actual time=143.090..143.090 rows=620980 loops=1)
                           Index Cond: ('{"United States"}'::text[] <@ mixed_frequent_locations(location))
                     ->  Bitmap Index Scan on idx_in_social_follower_count  (cost=0.00..15170.13 rows=821559 width=0) (actual time=132.214..132.215 rows=834091 loops=1)
                           Index Cond: (social_follower_count(social) > 30000)
Planning time: 0.534 ms
Execution time: 393793.472 ms

Server specifications:
63GB RAM, Intel Core i7-6700K, 250 GB SSD

Increasing work_mem reduced the lossy blocks but not the actual Recheck.

    Limit  (cost=59629.20..59629.23 rows=12 width=1531) (actual time=42330.685..42330.691 rows=12 loops=1)
  ->  Sort  (cost=59629.20..59629.69 rows=199 width=1531) (actual time=42330.662..42330.665 rows=12 loops=1)
        Sort Key: (social_follower_count(social)) DESC, created_at
        Sort Method: top-N heapsort  Memory: 65kB
        ->  Bitmap Heap Scan on users  (cost=24767.69..59624.63 rows=199 width=1531) (actual time=846.650..42281.071 rows=11616 loops=1)
              Recheck Cond: ((available_channels(social, contact_info) <@ '{yt}'::text[]) AND ('{"United States"}'::text[] <@ mixed_frequent_locations(location)) AND (social_follower_count(social) > 30000))
              Rows Removed by Index Recheck: 7149
              Filter: (has_emails(contact_info) AND not_business(social) AND is_visible(social, flags) AND (engagement_level(social) <= 3))
              Rows Removed by Filter: 9775
              Heap Blocks: exact=28018
              ->  BitmapAnd  (cost=24767.69..24767.69 rows=6344 width=0) (actual time=820.608..820.608 rows=0 loops=1)
                    ->  Bitmap Index Scan on available_channels_idx  (cost=0.00..4046.06 rows=363475 width=0) (actual time=207.050..207.050 rows=442083 loops=1)
                          Index Cond: (available_channels(social, contact_info) <@ '{yt}'::text[])
                    ->  Bitmap Index Scan on mixed_frequent_locations_idx  (cost=0.00..5550.85 rows=617447 width=0) (actual time=276.099..276.099 rows=620980 loops=1)
                          Index Cond: ('{"United States"}'::text[] <@ mixed_frequent_locations(location))
                    ->  Bitmap Index Scan on idx_in_social_follower_count  (cost=0.00..15170.13 rows=821559 width=0) (actual time=290.351..290.351 rows=834091 loops=1)
                          Index Cond: (social_follower_count(social) > 30000)
   Planning time: 20.168 ms
   Execution time: 42338.700 ms

Changing set enable_bitmapscan=off; changed a lot the query plan:

 Limit  (cost=0.43..192792.76 rows=12 width=1526) (actual time=25.710..145.877 rows=12 loops=1)
   Buffers: shared hit=8508
     ->  Index Scan using idx_in_social_follower_count_and_created_at2 on users  (cost=0.43..3454196.26 rows=215 width=1526) (actual time=25.707..145.864 rows=12 loops=1)
       Index Cond: (social_follower_count(social) > 30000)
       Filter: (has_emails(contact_info) AND not_business(social) AND 
          is_visible(social, flags) AND (engagement_level(social) <= 3) 
          AND (available_channels(social, contact_info) <@ '{yt}'::text[]) AND ('{"United States"}'::text[] <@ mixed_frequent_locations(location)))
     Rows Removed by Filter: 346
     Buffers: shared hit=8508

Planning time: 0.830 ms
Execution time: 145.949 ms

The execution time dramatically changed, its possible to enable or disable the bitmapscan depending on the query input?

Also i have tried increasing default_statistics_target to a higher value 2000 and 1000, but there is no big improvement. The query plan remains the same:

    Limit  (cost=122386.75..122386.78 rows=12 width=1528) (actual time=106296.479..106296.484 rows=12 loops=1)
  Buffers: shared hit=5010705 read=408947 written=467
  ->  Sort  (cost=122386.75..122390.13 rows=1349 width=1528) (actual time=106296.477..106296.478 rows=12 loops=1)
        Sort Key: (social_follower_count(social)) DESC, created_at
        Sort Method: top-N heapsort  Memory: 61kB
        Buffers: shared hit=5010705 read=408947 written=467
        ->  Bitmap Heap Scan on users  (cost=45119.25..122355.83 rows=1349 width=1528) (actual time=556.192..106183.697 rows=41736 loops=1)
              Recheck Cond: ((available_channels(social, contact_info) <@ '{yt}'::text[]) AND ('{"United States"}'::text[] <@ mixed_frequent_locations(location)))
              Rows Removed by Index Recheck: 17700
              Filter: (has_emails(contact_info) AND not_business(social) AND is_visible(social, flags) AND (engagement_level(instagram) <= 3))
              Rows Removed by Filter: 20977
              Heap Blocks: exact=76531
              Buffers: shared hit=5010705 read=408947 written=467
              ->  BitmapAnd  (cost=45119.25..45119.25 rows=15170 width=0) (actual time=533.751..533.751 rows=0 loops=1)
                    Buffers: shared hit=4 read=5492
                    ->  Bitmap Index Scan on available_channels_idx  (cost=0.00..4094.86 rows=369981 width=0) (actual time=100.521..100.522 rows=442083 loops=1)
                          Index Cond: (available_channels(social, contact_info) <@ '{yt}'::text[])
                          Buffers: shared hit=3 read=105
                    ->  Bitmap Index Scan on mixed_frequent_locations_idx  (cost=0.00..5576.65 rows=620353 width=0) (actual time=156.311..156.311 rows=620980 loops=1)
                          Index Cond: ('{"United States"}'::text[] <@ mixed_frequent_locations(location))
                          Buffers: shared hit=1 read=141
                    ->  Bitmap Index Scan on idx_in_contact_info_has_emails  (cost=0.00..35446.23 rows=1919173 width=0) (actual time=243.802..243.803 rows=1918927 loops=1)
                          Index Cond: (has_emails(contact_info) = true)
                          Buffers: shared read=5246
Planning time: 13.691 ms
Execution time: 106296.586 ms

Selectivity analysis of the conditions:

(social_follower_count(social) > '30000')  - 834091 records
(engagement_level(social) <= 3) - 4311859 records
(available_channels(social, contact_info) <@ array['yt']) - 342815 records
(has_emails(contact_info) = TRUE) - 1918927 records
(not_business(social) = TRUE) -  3869626 records
(array['United States'] <@ mixed_frequent_locations(location)) - 620980 records
(is_visible(social, flags) = TRUE) - 4959302 records

As @jjanes suggested removing the clause social_follower_count(social) > 30000 the query plan changes dramatically, now a full index scan is applied and Bitmap Heap Scan doesn't apply.

 Limit  (cost=0.43..88024.52 rows=12 width=1436) (actual time=20.779..181.868 rows=12 loops=1)
   ->  Index Scan using idx_in_social_follower_count_and_created_at on users  (cost=0.43..9543278.28 rows=1301 width=1436) (actual time=20.777..181.858 rows=12 loops=1)
         Filter: (has_emails(contact_info) AND not_business(social) AND is_visible(social, flags) AND (engagement_level(social) <= 3) AND (available_channels(social, contact_info) <@ '{yt}'::text[]) AND ('{"United States"}'::text[] <@ mixed_frequent_locations(
location)))
         Rows Removed by Filter: 347
 Planning time: 0.523 ms
 Execution time: 181.963 ms

Best Answer

I have a identical issue after upgrading from postgresql 9.1 to 9.6, including the better performance when I disabled enable_bitmapscan.

You are probably running with low default_statistics_target:

SHOW default_statistics_target ;

for new postgresql versions this should be increased due to the lot of new query planer capabilities making the default value of 100 ridiculous, try to increase it with enable_bitmapscan enabled, then try your query again until it selects the best query plan.

You can try different set of values by issuing:

set default_statistics_target to '2000'; --for example --this is a reasonable value for most of databases...

and then :

analyze;  --(or vacuum analyze)

then run your query again and again until you found the best statistics target for you...

And then you can put the default value in postgresql.conf and reload/restart the service.