0

Platform: Heroku; PostgreSQL Version 13

I have a table around 46GB and there are two GIN indexes on name and email columns I have a search query that is suppose to search in name and email columns using the indexes defined and most of the time it works fine as explain analyze reveales but some time it just stops using those index and use a totally different index that is not even related to query. Here is the query

EXPLAIN (ANALYZE TRUE, buffers TRUE, timing TRUE)
SELECT
    "sometbl".*
FROM
    "sometbl"
WHERE
    "sometbl"."deleted_at" IS NULL
    AND(email ILIKE '%sometxt%' OR name ILIKE '%sometxt%')

ORDER BY
    created_at DESC
LIMIT 10 OFFSET 0;

Explain Analyze info (Bad Plan)

Limit  (cost=0.09..7598.95 rows=10 width=1428) (actual time=300.670..67670.269 rows=7 loops=1)
  Buffers: shared hit=9947970 read=2567029 written=9
  I/O Timings: read=10637.696 write=0.152
  ->  Index Scan Backward using index_sometbl_on_created_at on sometbl  (cost=0.09..2429357.54 rows=3197 width=1428) (actual time=300.669..67670.257 rows=7 loops=1)
"        Filter: ((deleted_at IS NULL) AND (((email)::text ~~* '%sometxt%'::text) OR ((name)::text ~~* '%sometxt%'::text)))"
        Rows Removed by Filter: 16184624
        Buffers: shared hit=9947970 read=2567029 written=9
        I/O Timings: read=10637.696 write=0.152
Planning:
  Buffers: shared hit=594
Planning Time: 1.808 ms
Execution Time: 67670.327 ms

index_mytbl_on_created_at is an index on created_at and I am really not sure why the planner is choosing this index.

While it should be like this (Good Plan)

Limit  (cost=7020.60..7020.61 rows=10 width=1428) (actual time=575.046..575.053 rows=7 loops=1)
  Buffers: shared hit=24090 read=2040
  I/O Timings: read=139.303
  ->  Sort  (cost=7020.60..7022.20 rows=3197 width=1428) (actual time=575.045..575.049 rows=7 loops=1)
        Sort Key: created_at DESC
        Sort Method: quicksort  Memory: 29kB
        Buffers: shared hit=24090 read=2040
        I/O Timings: read=139.303
        ->  Bitmap Heap Scan on sometbl  (cost=745.12..7006.78 rows=3197 width=1428) (actual time=574.917..575.009 rows=7 loops=1)
"              Recheck Cond: (((email)::text ~~* '%sometxt%'::text) OR ((name)::text ~~* '%sometxt%'::text))"
              Filter: (deleted_at IS NULL)
              Heap Blocks: exact=7
              Buffers: shared hit=24090 read=2040
              I/O Timings: read=139.303
              ->  BitmapOr  (cost=745.12..745.12 rows=3201 width=0) (actual time=574.864..574.866 rows=0 loops=1)
                    Buffers: shared hit=24087 read=2036
                    I/O Timings: read=139.277
                    ->  Bitmap Index Scan on trgm_idx_sometbl_email  (cost=0.00..398.41 rows=1606 width=0) (actual time=424.932..424.933 rows=7 loops=1)
"                          Index Cond: ((email)::text ~~* '%sometxt%'::text)"
                          Buffers: shared hit=21569 read=765
                          I/O Timings: read=75.132
                    ->  Bitmap Index Scan on trgm_idx_sometbl_name  (cost=0.00..346.39 rows=1595 width=0) (actual time=149.929..149.929 rows=0 loops=1)
"                          Index Cond: ((name)::text ~~* '%sometxt%'::text)"
                          Buffers: shared hit=2518 read=1271
                          I/O Timings: read=64.145
Planning:
  Buffers: shared hit=2
Planning Time: 0.584 ms
Execution Time: 575.177 ms

Few things that I have tried.

  1. If I use one column in the query every things works fine and planner choose the right index.
EXPLAIN ANALYSE SELECT
    "mytbl".*
FROM
    "mytbl"
WHERE
    "mytbl"."deleted_at" IS NULL
    and email ILIKE '%somestr%'
ORDER BY
    created_at DESC
LIMIT 10 OFFSET 0; 

explain analyze

Limit  (cost=4067.45..4067.45 rows=10 width=1439) (actual time=801.053..801.055 rows=1 loops=1)
  ->  Sort  (cost=4067.45..4068.27 rows=1636 width=1439) (actual time=801.052..801.053 rows=1 loops=1)
        Sort Key: created_at DESC
        Sort Method: quicksort  Memory: 26kB
        ->  Bitmap Heap Scan on mytbl (cost=834.54..4060.38 rows=1636 width=1439) (actual time=801.039..801.041 rows=1 loops=1)
"              Recheck Cond: ((email)::text ~~* '%somestr%'::text)"
              Filter: (deleted_at IS NULL)
              Heap Blocks: exact=1
              ->  Bitmap Index Scan on trgm_idx_mytbl_email  (cost=0.00..834.46 rows=1637 width=0) (actual time=801.015..801.015 rows=1 loops=1)
"                    Index Cond: ((email)::text ~~* '%somestr%'::text)"
Planning Time: 0.497 ms
Execution Time: 801.158 ms

working perfectly fine and if I change it with name then it is working as well.

  1. If I remove the
ORDER BY
    created_at DESC

part and run the above query then planner again chooses the right indexes.

Limit  (cost=1371.22..1390.80 rows=10 width=1439) (actual time=789.841..789.845 rows=1 loops=1)
  Buffers: shared hit=47417 read=1942
  I/O Timings: read=8.258
  ->  Bitmap Heap Scan on mytbl (cost=1371.22..7752.83 rows=3260 width=1439) (actual time=789.840..789.843 rows=1 loops=1)
"        Recheck Cond: (((email)::text ~~* '%somestr%'::text) OR ((name)::text ~~* '%somestr%'::text))"
        Filter: (deleted_at IS NULL)
        Heap Blocks: exact=1
        Buffers: shared hit=47417 read=1942
        I/O Timings: read=8.258
        ->  BitmapOr  (cost=1371.22..1371.22 rows=3263 width=0) (actual time=789.809..789.810 rows=0 loops=1)
              Buffers: shared hit=47416 read=1942
              I/O Timings: read=8.258
              ->  Bitmap Index Scan on trgm_idx_mytbl_email  (cost=0.00..834.46 rows=1637 width=0) (actual time=704.337..704.337 rows=1 loops=1)
"                    Index Cond: ((email)::text ~~* '%somestr%'::text)"
                    Buffers: shared hit=45677
              ->  Bitmap Index Scan on trgm_idx_mytbl_name  (cost=0.00..536.44 rows=1626 width=0) (actual time=85.469..85.469 rows=0 loops=1)
"                    Index Cond: ((name)::text ~~* '%somestr%'::text)"
                    Buffers: shared hit=1739 read=1942
                    I/O Timings: read=8.258
Planning:
  Buffers: shared hit=2
Planning Time: 0.587 ms
Execution Time: 789.925 ms

  1. I have manually ran the analyze on the table in question and auto vacuum just completed few hours ago.
1
0

So, warning up-front: I don't have a fix for your problem, this is just explaining what's going on.

It comes down to the selectivity of your WHERE. If the planner thinks very few rows will satisfy the WHERE, it makes sense to use the GIN indexes, get all rows that match, and then perform a sort. But if the planner thinks lots of rows will pass the filter, it sees the ORDER BY created_at DESC LIMIT 10, and instead decides to scan the index in-order until it sees 10 rows that satisfy the WHERE.

Unfortunately, it's estimate of how likely rows are to pass your WHERE can be very wrong. You can try increasing the statistics target on the column in question & redoing an analyze, but another way would be to restructure your query to always force all rows to be fetched - though fair warning that if you ever use this query with a string that does match lots of rows, it will make it very slow. It would be something like this:

select * from (
  SELECT
    "mytbl".*
  FROM
    "mytbl"
  WHERE
    "mytbl"."deleted_at" IS NULL
    AND(email ILIKE '%somestr%' OR name ILIKE '%somestr')
  -- OFFSET 0 is an optimization fence to make sure the planner
  -- doesn't push the ORDER BY into this level.
  OFFSET 0
)
ORDER BY
    created_at DESC
LIMIT 10 OFFSET 0;

Lastly, PG has support for extended statistics that consider more than one column at a time - in this case, it's the fact that emails are not randomly distributed across created_at values that the planner needs to be aware of, and would not be by default. Unfortunately, I'm afraid I've never used this feature myself and don't want to give you incorrect instructions - and I'm not sure it can be used in this case, where one of the columns is being ordered by, not filtered on - so I'm just going to point you to the docs.

6
  • Thank you for you reply @AdamKG! What surprises me is that why sometime same query with same search params works fine and use GIN indexes and sometime it does not. Is there a possibility of other factors involved like load etc ?
    – hassan_i
    Sep 9 at 2:09
  • @hassan_i The planner does not take load into account. Could you capture a plan from it using the gin indexes in a case were do you have the OR and do have the ORDER BY?
    – jjanes
    Sep 9 at 3:24
  • @jjanes the plan mentioned above 'Few things that I have tried.' is the plan where every things works as normal with same search params.
    – hassan_i
    Sep 9 at 3:33
  • But the suspicious part is estimation and actual values, where planner thins that there will be rows=3095 matching while only 0 rows matches. I have done the analyze again but the results are the same.
    – hassan_i
    Sep 9 at 3:36
  • @hassan_i But neither one of those actually has the same parameters. There is no 'sometimes' here. You write one query it does one thing, you write a different query it does a different thing. The planner screws up, but not in a way that is random.
    – jjanes
    Sep 9 at 4:18

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.