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

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.
> Guggenberg 26, DE-82380 Peißenberg
> fon: +49-8803-4899016  fax: +49-8803-4899017
> info@fduerr.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?
>>
>>
> 

-- 
Adrian Klaver
adrian.klaver@aklaver.com