Re: PgSQL 15.3: Execution plan not using index as expected

Thanks Adrian,

sorry for the misunderstanding.
I ran ANALYZE, it didn't change a thing (as expected).
Anyway, I pinned the problem down now: It's the use of CURRENT_USER (or
SESSION_USER etc.) in the WHERE condition.
If i replace it with 'postgres' (the result of CURRENT_USER) the planner
works as expected..
The old 9.x - version of PgSQL didn't have that problem.

Test case:

-- our test table with index on user_id
CREATE TABLE tt (
 user_id VARCHAR(63) NOT NULL DEFAULT SESSION_USER
);
CREATE INDEX tt_user_id_idx ON tt(user_id);

-- fill with test data
INSERT INTO tt(user_id) select 'U' || i from generate_series(1,100000) as i;
INSERT INTO tt(user_id) select SESSION_USER from generate_series(1,100);

-- query using CURRENT_USER as WHERE-condition - doesn't use index
EXPLAIN ANALYZE SELECT * FROM tt WHERE user_id::character
varying(63)=CURRENT_USER::character varying(63) LIMIT 1;
                                               QUERY PLAN
---------------------------------------------------------------------------------------------------------
 Limit  (cost=0.00..21.65 rows=1 width=6) (actual time=18.143..18.143
rows=1 loops=1)
   ->  Seq Scan on tt  (cost=0.00..2446.00 rows=113 width=6) (actual
time=18.141..18.141 rows=1 loops=1)
         Filter: ((user_id)::text = ((CURRENT_USER)::character
varying(63))::text)
         Rows Removed by Filter: 100000
 Planning Time: 0.154 ms
 Execution Time: 18.163 ms
(6 Zeilen)

SELECT CURRENT_USER;
 current_user
--------------
 postgres
(1 Zeile)

-- query using result of CURRENT_USER as WHERE-condition - uses index
EXPLAIN ANALYZE SELECT * FROM tt WHERE user_id::character
varying(63)='postgres'::character varying(63) LIMIT 1;
                                                           QUERY PLAN
--------------------------------------------------------------------------------------------------------------------------------
 Limit  (cost=0.42..0.47 rows=1 width=6) (actual time=0.018..0.019
rows=1 loops=1)
   ->  Index Only Scan using tt_user_id_idx on tt (cost=0.42..6.39
rows=113 width=6) (actual time=0.017..0.018 rows=1 loops=1)
         Index Cond: (user_id = 'postgres'::text)
         Heap Fetches: 0
 Planning Time: 0.081 ms
 Execution Time: 0.026 ms
(6 Zeilen)

-- CURRENT_USER is not expensive..
EXPLAIN ANALYZE SELECT CURRENT_USER;
                                     QUERY PLAN
-------------------------------------------------------------------------------------
 Result  (cost=0.00..0.01 rows=1 width=64) (actual time=0.005..0.006
rows=1 loops=1)
 Planning Time: 0.031 ms
 Execution Time: 0.025 ms
(3 Zeilen)

I hope that this should clarify the problem.
Thanks and kind regards

======================================
Dürr Software Entw.
info(at)fduerr(dot)de

Am 11.08.23 um 16:32 schrieb Adrian Klaver:
> On 8/11/23 03:11, Dürr Software wrote:
>
> Please reply to list also
> Ccing list
>> Dear Adrian,
>>
>> thanks for the reply. Of course i ran ANALYZE on the 15.3 system, its
>> in the second part of my post, but here again, FYI:
>
> That is EXPLAIN ANALYZE where it is an option to the command:
>
> https://www.postgresql.org/docs/current/sql-explain.html
>
> ANALYZE
>
>     Carry out the command and show actual run times and other
> statistics. This parameter defaults to FALSE.
>
>
> What I was talking about was the ANALYZE command:
>
> https://www.postgresql.org/docs/current/sql-analyze.html
>
> ANALYZE collects statistics about the contents of tables in the
> database, and stores the results in the pg_statistic system catalog.
> Subsequently, the query planner uses these statistics to help
> determine the most efficient execution plans for queries.
>
>>
>> test=# \d client_session
>>                                                   Tabelle
>> »client_session«
>>     Spalte     |              Typ               | Sortierfolge | NULL
>> erlaubt? |                   Vorgabewert
>> ---------------+--------------------------------+--------------+---------------+--------------------------------------------------
>>
>> id            | bigint                         |              | not
>> null       | nextval('admin.client_session_id_seq'::regclass)
>> tstamp_start  | timestamp(3) without time zone |              | not
>> null       | now()
>> permit_id     | character varying(63)          |              | not
>> null       | "current_user"()
>> user_id       | character varying(63)          |              | not
>> null       | "session_user"()
>>
>> Indexe:
>>      "client_session_pkey" PRIMARY KEY, btree (id)
>>      "client_session_user_id_idx" btree (user_id, tstamp_start DESC)
>>
>> test=# explain analyze SELECT permit_id FROM client_session WHERE
>> user_id::character varying(63)=SESSION_USER::character varying(63)
>> ORDER BY tstamp_start DESC LIMIT 1;
>>                                                                     QUERY
>> PLAN
>> ---------------------------------------------------------------------------------------------------------------------------------------------------
>>
>> Limit  (cost=2852336.36..2852336.48 rows=1 width=23) (actual
>> time=5994.540..6000.702 rows=1 loops=1)
>>    ->  Gather Merge  (cost=2852336.36..2852697.59 rows=3096 width=23)
>> (actual time=5946.422..5952.583 rows=1 loops=1)
>>          Workers Planned: 2
>>          Workers Launched: 2
>>          ->  Sort  (cost=2851336.34..2851340.21 rows=1548 width=23)
>> (actual time=5934.963..5934.964 rows=1 loops=3)
>>                Sort Key: tstamp_start DESC
>>                Sort Method: quicksort  Memory: 25kB
>>                Worker 0:  Sort Method: quicksort  Memory: 25kB
>>                Worker 1:  Sort Method: quicksort  Memory: 25kB
>>                ->  Parallel Seq Scan on client_session
>>   (cost=0.00..2851328.60 rows=1548 width=23) (actual
>> time=3885.774..5934.915 rows=1 loops=3)
>>                      Filter: ((user_id)::text =
>> ((SESSION_USER)::character varying(63))::text)
>>                      Rows Removed by Filter: 37163374
>> Planning Time: 0.167 ms
>> JIT:
>>    Functions: 13
>>    Options: Inlining true, Optimization true, Expressions true,
>> Deforming true
>>    Timing: Generation 0.940 ms, Inlining 119.027 ms, Optimization
>> 79.333 ms, Emission 29.624 ms, Total 228.924 ms
>> Execution Time: 6001.014 ms
>> (18 Zeilen)
>>
>> Funny thing: if i create an index on tstamp_start alone, it is used
>> just perfectly:
>>
>> Indexe:
>>      "client_session_pkey" PRIMARY KEY, btree (id)
>>      "client_session_tstamp_start" btree (tstamp_start)
>>      "client_session_user_id_idx" btree (user_id, tstamp_start DESC)
>>
>> test=# explain analyze SELECT permit_id FROM admin.client_session
>> WHERE user_id::character varying(63)=SESSION_USER::character
>> varying(63) ORDER BY tstamp_start DESC LIMIT 1;
>>
>> QUERY PLAN
>> ---------------------------------------------------------------------------------------------------------------------------------------------------------------------
>>
>>   Limit  (cost=0.57..1787.85 rows=1 width=23) (actual
>> time=0.721..0.723 rows=1 loops=1)
>>     ->  Index Scan Backward using client_session_tstamp_start on
>> client_session (cost=0.57..6639766.39 rows=3715 width=23) (actual
>> time=0.719..0.719 rows=1 loops=1)
>>           Filter: ((user_id)::text = ((SESSION_USER)::character
>> varying(63))::text)
>>   Planning Time: 0.227 ms
>>   Execution Time: 0.761 ms
>> (5 Zeilen)
>>
>> ======================================
>> Dürr Software Entw.
>> info(at)fduerr(dot)de
>>
>> Am 10.08.23 um 16:41 schrieb Adrian Klaver:
>>> On 8/9/23 01:14, Dürr Software wrote:
>>>> Dear list,
>>>>
>>>> i have a strange problem when migrating a DB from version 9.3.4 to
>>>> 15.3:
>>>> An index which seems perfect for the query and is used in 9.3.4 as
>>>> expected is not used in 15.3.
>>>
>>> Did you run ANALYZE on the 15.3 database after the migration?
>>>
>>>
>>
>