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(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?
>>
>>
>

--
Adrian Klaver
adrian(dot)klaver(at)aklaver(dot)com