PgSQL 15.3: Execution plan not using index as expected

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

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

Hello,

---------------------------------------------------------------------
-------------------------
  PostgreSQL 9.3.4 on x86_64-unknown-linux-gnu, compiled by gcc
(Debian
4.8.3-2) 4.8.3, 64-bit

---------------------------------------------------------------------
------------------------------------------------
  PostgreSQL 15.3 (Debian 15.3-1.pgdg120+1) on x86_64-pc-linux-gnu,
compiled by gcc (Debian 12.2.0-14) 12.2.0, 64-bit
(1 Zeile)

9.3 plan
-> Index Scan using client_session_user_id_idx on client_session

Looks like a collation issue given the difference in compilers used.
In the 9.3 plan the index is used.
Maybe try a reindex of the table.

HTH,
Rob

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@fduerr.de

Am 11.08.23 um 16:32 schrieb Adrian Klaver:

Thanks Rob,

no it's not a problem with the index. It's a problem with the use of
CURRENT_USER in the WHERE
I submitted a new post on this matter with a test case.

Kind regards

======================================
Dürr Software Entw.
Guggenberg 26, DE-82380 Peißenberg
fon: +49-8803-4899016 fax: +49-8803-4899017
info@fduerr.de

Am 12.08.23 um 04:25 schrieb rob stone: