1

In summary, Postgres prefers doing the equivalent of a [datetime index seqscan]+[filter (using the heavy function)] instead of using the index when using = to find what I like. When simply replacing = with ~~, it starts using a bitmapAnd on datetime+indexed field which is thousands of time quicker.

I tried:

  • setting the cost of seqscan up, enable_seqscan=off, effective_cache_size=<size of indices> without any effect.
  • changing the cost of the execution of the function to 1000, but it also affects the index lookups cost even if it doesn't execute the function when using the index.
  • raising the parallel_setup_cost to 10000 to make the explain understand the minimum cost of setting up parallel index scan is above 5000 which is the minimum cost of the bitmapAnd index scan.
  • run analyze on the table.

It seems the planner doesn't take into accounts how many records it'll have to filter thru the costly function even if the planner knows how many records it'll have to filter. And I can confirm that using the index instead of filtering with the function result in order of magnitudes less processing time.

Any idea how to convince Postgres it is a bad idea to execute that function?

The table is quite simple:

fluentbit=# \d logs_nginx_p2022w07
                       Table "public.logs_nginx_p2022w07"
       Column       |           Type           | Collation | Nullable | Default 
--------------------+--------------------------+-----------+----------+---------
 dt                 | timestamp with time zone |           | not null | 
 logs_meta_id       | integer                  |           | not null | 
 log                | text                     |           |          | 
 http_authorization | jsonb                    |           |          | 
 log_format         | logs_nginx_format        |           | not null | 
Partition of: logs_nginx FOR VALUES FROM ('2022-02-14 00:00:00-05') TO ('2022-02-21 00:00:00-05')
Indexes:
    "logs_nginx_p2022w07_dest_service_idx" btree (((logs_nginx_extract_fields(log_format, log)).dest_service) COLLATE "C") WITH (fillfactor='100')
    "logs_nginx_p2022w07_dt_logs_meta_id_idx" btree (dt, logs_meta_id)
    "logs_nginx_p2022w07_logs_nginx_get_remote_ip_idx" btree (logs_nginx_get_remote_ip(log))
    "logs_nginx_p2022w07_remote_user_idx" btree (logs_nginx_get_remote_user(http_authorization)) WHERE http_authorization IS NOT NULL
Foreign-key constraints:
    TABLE "logs_nginx" CONSTRAINT "logs_nginx_logs_meta_id_fk" FOREIGN KEY (logs_meta_id) REFERENCES logs_meta(id)

The function logs_nginx_extract_fields does a CASE, a couple regexes and returns 10 values and is quite heavy on the CPU.

Here are the EXPLAIN ANALYZE for both = and ~~.

Using Equality operator:

fluentbit=# explain analyze select dt,log from logs_nginx where dt between '2022-02-15 13:00:00-05' and '2022-02-15 14:00:00-05' and ((logs_nginx_extract_fields(log_format, log)).dest_service = 'customerportal-webapi') limit 1000;
                                                                                                 QUERY PLAN                                                                                                  
-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=1000.57..577572.04 rows=49 width=517) (actual time=44379.393..44379.453 rows=0 loops=1)
   ->  Gather  (cost=1000.57..577572.04 rows=49 width=517) (actual time=44328.092..44328.151 rows=0 loops=1)
         Workers Planned: 2
         Workers Launched: 0
         ->  Parallel Index Scan using logs_nginx_p2022w07_dt_logs_meta_id_idx on logs_nginx_p2022w07 logs_nginx  (cost=0.56..576567.14 rows=20 width=517) (actual time=44327.829..44327.829 rows=0 loops=1)
               Index Cond: ((dt >= '2022-02-15 13:00:00-05'::timestamp with time zone) AND (dt <= '2022-02-15 14:00:00-05'::timestamp with time zone))
               Filter: ((logs_nginx_extract_fields(log_format, log)).dest_service = 'customerportal-webapi'::text)
               Rows Removed by Filter: 299642
 Planning Time: 0.162 ms
 JIT:
   Functions: 7
   Options: Inlining true, Optimization true, Expressions true, Deforming true
   Timing: Generation 1.122 ms, Inlining 10.860 ms, Optimization 26.515 ms, Emission 13.784 ms, Total 52.279 ms
 Execution Time: 44380.632 ms

Using LIKE operator:

fluentbit=# explain analyze select dt,log from logs_nginx where dt between '2022-02-15 13:00:00-05' and '2022-02-15 14:00:00-05' and ((logs_nginx_extract_fields(log_format, log)).dest_service ~~ 'customerportal-webapi') limit 1000;
                                                                         QUERY PLAN                                                                          
-------------------------------------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=5323.55..5496.48 rows=49 width=517) (actual time=0.023..0.025 rows=0 loops=1)
   ->  Bitmap Heap Scan on logs_nginx_p2022w07 logs_nginx  (cost=5323.55..5496.48 rows=49 width=517) (actual time=0.022..0.023 rows=0 loops=1)
         Recheck Cond: ((dt >= '2022-02-15 13:00:00-05'::timestamp with time zone) AND (dt <= '2022-02-15 14:00:00-05'::timestamp with time zone))
         Filter: ((logs_nginx_extract_fields(log_format, log)).dest_service ~~ 'customerportal-webapi'::text)
         ->  BitmapAnd  (cost=5323.55..5323.55 rows=49 width=0) (actual time=0.020..0.021 rows=0 loops=1)
               ->  Bitmap Index Scan on logs_nginx_p2022w07_dest_service_idx  (cost=0.00..54.85 rows=6438 width=0) (actual time=0.019..0.020 rows=0 loops=1)
                     Index Cond: ((logs_nginx_extract_fields(log_format, log)).dest_service = 'customerportal-webapi'::text)
               ->  Bitmap Index Scan on logs_nginx_p2022w07_dt_logs_meta_id_idx  (cost=0.00..5268.43 rows=352886 width=0) (never executed)
                     Index Cond: ((dt >= '2022-02-15 13:00:00-05'::timestamp with time zone) AND (dt <= '2022-02-15 14:00:00-05'::timestamp with time zone))
 Planning Time: 0.277 ms
 Execution Time: 0.066 ms
0

1 Answer 1

2

The index is decorated with COLLATE "C", which prevents the simple equality operator from being used, while LIKE is special-cased to be usable in this case.

You can drop the collation decoration from the index, or you can add one to the test in the query:

AND ((logs_nginx_extract_fields(log_format, log)).dest_service = 'customerportal-webapi' COLLATE "C")

Note that even if your database's default collation is "C", that is still considered to be a different collation than an explicitly specified COLLATE "C".

1
  • The database isn't using C as default collation and I wanted to be able to use left-anchored comparisons. Thanks for clarifying that even equality operator needs a collation.
    – TiCPU
    Dec 17, 2022 at 16:10

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

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