2

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
  • Can you run vacuum analyze on the tables? – 777Anon Oct 2 '18 at 14:56
  • @LucianoAndressMartini Yes, but the problem still remains. – Imanol Y. Oct 2 '18 at 15:45
  • You probably aren't running this exact query over and over. Can you describe what the general class is? That is, what of the hard coded values change, and which stay the same? – jjanes Oct 2 '18 at 15:47
  • 1
    If you set enable_bitmapscan=off before running the query, what do you get for an execution time and an execution plan? – jjanes Oct 2 '18 at 15:49
  • @jjanes Updated my question with your suggestion, changed a lot the result. – Imanol Y. Oct 2 '18 at 16:01
2

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.

  • I have tried increasing default_statistics_target to 2000 and to 10000, and after analyze and re-running the query the query plan didnt change and the execution time has been 121257.823 ms and 106296.586 ms each – Imanol Y. Oct 3 '18 at 11:31
  • 1
    Please read this: gist.github.com/hgmnz/883144 I think it will help a lot, because it talks about bitmapscan problem when using limit. – 777Anon Oct 3 '18 at 15:15
  • 1
    And this is interesting too: datadoghq.com/blog/… – 777Anon Oct 3 '18 at 15:22
  • 1
    Sorry for not having anything more to help =( – 777Anon Oct 3 '18 at 15:22
1

The recheck is needed because the full bitmap cannot fit in the allowed memory, so it has to use lossy compression by storing just the blocks, rather the blocks and row-offsets-within-block. Increase the setting of "work_mem" so that the entire bitmap fits in memory, i.e. until there are no longer "Heap Blocks:...lossy=...".

Now, that still might not be good enough, but at least it will have a fighting chance.


It looks like the above helped by about a factor of 10, but is still not good enough.

It is certainly possible to set enable_bitmapscan = off before a specific queries, and then reset enable_bitmapscan after that query. The potential problems with that is that some programming frameworks which try to abstract away the SQL make it hard for you to get your hands on the query in order to do that; and that it can be hard to know which queries you need that setting for. If the PostgreSQL planner did a good job of understanding that, then you wouldn't have this problem in the first place; so you are kind of on your own there.

The fundamental problem is probably this line:

->  Bitmap Heap Scan on users  (cost=24767.69..59624.63 rows=199 width=1531) (actual time=846.650..42281.071 rows=11616 loops=1)

It finds 60x times more rows than it expects to find. The reason for this is probably a correlation between the columns, for example people who have YouTube channels are more likely to be popular than random chance would suggest. In newer versions of postgres, there is a way to gather statistics on cross-column correlations, but that won't work for you here because (currently) they have to be actual columns, not expressions, and also because I think it only works on scalars, not arrays.

One idea would be to drop the social_follower_count(social) > '30000' part of the query. Since you are already sorting by that value and taking just the top 12, is it really necessary to also restrict on a quantitative cutoff as well? If you omitted that part, it would no longer have the ability to be correlated with other values and so cause estimation problems.

  • thanks a lot, I have tried increasing work_mem and no more lossy are showd Heap Blocks: exact=28018 but still (actual time=566.220..35140.352 rows=11616 loops=1) Remains too high. – Imanol Y. Oct 2 '18 at 15:43
  • 1
    Can you update the question with the execution plan you get with the higher value of work_mem? Also, can you show EXPLAIN (ANALYZE, BUFFERS) rather than just EXPLAIN ANALYZE? Finally, turning track_io_timing=on before repeating the ANALYZE can help, if you are able to do that. – jjanes Oct 2 '18 at 15:51
  • Thanks, I've expanded my answer accordingly. – jjanes Oct 2 '18 at 19:08
  • i have tried removing social_follower_count(social) from the where but remains the same, the only thing that seems to work is turning off enable_bitmapscan , the problem is that as you said my use of case is an ORM that executes a lot of different filterings against this table, and the great majority of them perform slower without bitmap scan strategy – Imanol Y. Oct 3 '18 at 13:08
  • 1
    When you remove the >30000 clause, does the estimated row count get better, but just not by enough to fix the problem? Or does it just make no difference? – jjanes Oct 3 '18 at 16:16

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.