PostgreSQL: Unexpected query behavior (slow) with addtional AND clause

Question

I'm querying two tables via an inner join.

• table 1 has a gin index used in where clause (for full text search, ts_vector)
• table 2 has a gist index from an extension

Using just these two indexes in a where clause is super-fast, as expected.

However, if I add an additional "AND-clause" to a varchar field in table 1, the query goes from 40ms to 40s (note "only" 280k rows):

WHERE
    table1.my_tsv @@ to_tsquery('english', 'my & text')
    AND table2.mol@>'c1ccccc1' -- gist index
    AND table1.classification = 'ABC' -- makes query very slow

Important that table1.classification contains mostly nulls + about 5 discrete values (as text). it's not indexed (and doing so does not help).

Why does this additional filter make the query so slow and how can it be avoided?

In fact, if I comment any of the three clauses, the query is fast. it's the combination of all three that makes it slow.

Statistics on the tables are all newly created.

Explain plans in plain text (obfuscated) and as recommended from https://explain.depesz.com:

Slow Query with 3 conditions:

https://explain.depesz.com/s/oL4G

 Nested Loop  (cost=104.45..1134.42 rows=1 width=169) (actual time=1205.297..43174.433 rows=29 loops=1)
   Join Filter: (c.compound_id = cs.compound_id)
   Rows Removed by Join Filter: 336391
   Buffers: shared hit=1516917
   ->  Bitmap Heap Scan on compounds c  (cost=37.87..41.89 rows=1 width=177) (actual time=0.717..1.607 rows=126 loops=1)         Recheck Cond: ((classification = 'my class'::text) AND (text_tsv @@ '''mi'' & ''text'''::tsquery))
         Heap Blocks: exact=109
         Buffers: shared hit=129
         ->  BitmapAnd  (cost=37.87..37.87 rows=1 width=0) (actual time=0.699..0.705 rows=0 loops=1)
               Buffers: shared hit=20
               ->  Bitmap Index Scan on idx_classification  (cost=0.00..9.21 rows=655 width=0) (actual time=0.108..0.113 rows=693 loops=1)
                     Index Cond: (classification = 'my class'::text)
                     Buffers: shared hit=2
               ->  Bitmap Index Scan on idx_ft_txt  (cost=0.00..28.41 rows=55 width=0) (actual time=0.572..0.572 rows=799 loops=1)
                     Index Cond: (text_tsv @@ '''mi'' & ''text'''::tsquery)
                     Buffers: shared hit=18
   ->  Bitmap Heap Scan on structure cs  (cost=66.58..1089.04 rows=280 width=8) (actual time=16.055..342.221 rows=2670 loops=126)
         Recheck Cond: (mol_col @> 'c1ccccc1'::mol)
         Rows Removed by Index Recheck: 5538
         Heap Blocks: exact=577206
         Buffers: shared hit=1516788
         ->  Bitmap Index Scan on idx_mol  (cost=0.00..66.51 rows=280 width=0) (actual time=15.410..15.410 rows=8208 loops=126)
               Index Cond: (rdkit_mol @> 'c1ccccc1'::mol)
               Buffers: shared hit=939582
 Planning:
   Buffers: shared hit=376
 Planning Time: 7.983 ms
 Execution Time: 43176.101 ms
(28 rows)

Fast query with 2 conditions:

https://explain.depesz.com/s/W8wQ

 Hash Join  (cost=302.76..1325.95 rows=1 width=169) (actual time=31.394..360.847 rows=140 loops=1)
   Hash Cond: (cs.compound_id = c.compound_id)
   Buffers: shared hit=12712
   ->  Bitmap Heap Scan on structure cs  (cost=66.58..1089.04 rows=280 width=8) (actual time=21.086..356.402 rows=2670 loops=1)
         Recheck Cond: (mol_col @> 'c1ccccc1'::mol)
         Rows Removed by Index Recheck: 5538
         Heap Blocks: exact=4581
         Buffers: shared hit=12038
         ->  Bitmap Index Scan on idx_rd_mol  (cost=0.00..66.51 rows=280 width=0) (actual time=20.260..20.261 rows=8208 loops=1)
               Index Cond: (mol_col @> 'c1ccccc1'::mol)
               Buffers: shared hit=7457
   ->  Hash  (cost=235.49..235.49 rows=55 width=177) (actual time=3.680..3.681 rows=799 loops=1)
         Buckets: 1024  Batches: 1  Memory Usage: 242kB
         Buffers: shared hit=674
         ->  Bitmap Heap Scan on compounds c  (cost=28.43..235.49 rows=55 width=177) (actual time=0.833..3.354 rows=799 loops=1)
               Recheck Cond: (text_tsv @@ '''mi'' & ''text'''::tsquery)
               Heap Blocks: exact=656
               Buffers: shared hit=674
               ->  Bitmap Index Scan on idx_ft_text  (cost=0.00..28.41 rows=55 width=0) (actual time=0.756..0.756 rows=799 loops=1)
                     Index Cond: (text_tsv @@ '''mi'' & ''text'''::tsquery)
                     Buffers: shared hit=18
 Planning:
   Buffers: shared hit=9
 Planning Time: 0.365 ms
 Execution Time: 361.151 ms
(25 rows)

From a different question I found this:

set enable_nestloop to off;

which makes the query run in 700ms vs 43s. This is a manual setting and there can be different queries that might or might not need this setting. It should work without such hacks.

The issue is the same if I filter by a different "text" column but if I add a numeric column (int) as 3rd condition, it's fast.

Some more investigating I also noticed that if i do a very basic LIKE '%my text%' query which I know is not the same as full text search, the query is also fast even though more rows are returned. So the issue is caused by the combination of Gin & Gist & additional condition.

Answer 1

Because of the two conditions on the table table1, the query planner thinks that only a single row of that table will match. Given this assumption, it considers it is fine to run a bitmap scan on table2 for each matched row in table1.

If the assumption is false and many rows are matched on table1, then the bitmap scan on table2 will be run many times, making the query slow.

Without the extra condition, the query planner assumes that it will match 244 rows in table1 and chooses a different plan where each stable is scanned only once.