For some reason, the same query executed locally and from my golang backend application uses different execution plans.

Flow of events: I have encountered an inefficient plan running from my backend application to the database. After connecting to the same PostgreSQL database with a PG client on my local machine (with the same user as the backend Application), I reproduced the query which takes >70ms. I then use my local PG client for adding an index and re-executing the query and the execution went down to <1ms.

It seems however that the same query keeps being executed from my backend Application and still takes >70ms which makes me think that the newly added index is not chosen. I excluded the potential reason that the backend Application query runs in a transaction by using BEGIN; and COMMIT; on my local PG client, with no change in results.

Despite my best efforts I was unable to understand the reason for this unusual behavior. Maybe someone here has an idea? How is this possible?

-- The index I added:
CREATE INDEX CONCURRENTLY mytable_temp ON mytable (poolid, id asc) where NOT used;

-- The query:
BEGIN;
explain analyze UPDATE
    mytable
SET
    used = true
WHERE
    id = (
        SELECT
            id
        FROM
            mytable
        WHERE (poolid = 9
            AND used = false
            AND((startdate IS NULL
                OR startdate <= '2021-12-03 18:12:16.952353384')
            AND(enddate IS NULL
                OR enddate >= '2021-12-03 18:12:16.952353384')))
    ORDER BY
        id ASC
    LIMIT 1
FOR UPDATE SKIP LOCKED)
RETURNING
    mytable.id,
    mytable.poolid,
    mytable.code,
    mytable.startdate,
    mytable.enddate,
    mytable.attributes,
    mytable.used,
    mytable.importid,
    mytable.created;
COMMIT;

The plan (when executed locally):

Update on mytable  (cost=0.92..2.93 rows=1 width=132) (actual time=0.091..0.092 rows=1 loops=1)
  InitPlan 1 (returns $1)
    ->  Limit  (cost=0.43..0.49 rows=1 width=10) (actual time=0.069..0.069 rows=1 loops=1)
          ->  LockRows  (cost=0.43..98599.17 rows=1699030 width=10) (actual time=0.068..0.069 rows=1 loops=1)
                ->  Index Scan using mytable_temp on mytable mytable_1  (cost=0.43..81608.87 rows=1699030 width=10) (actual time=0.065..0.065 rows=1 loops=1)
                      Index Cond: (poolid = 9)
"                      Filter: ((NOT used) AND ((startdate IS NULL) OR (startdate <= '2021-12-03 18:12:16.952353 00'::timestamp with time zone)) AND ((enddate IS NULL) OR (enddate >= '2021-12-03 18:12:16.952353 00'::timestamp with time zone)))"
  ->  Index Scan using mytable_pkey on mytable  (cost=0.43..2.45 rows=1 width=132) (actual time=0.081..0.081 rows=1 loops=1)
        Index Cond: (id = $1)
Planning Time: 0.146 ms
Execution Time: 0.120 ms

CodePudding user response：

Investigation shows that the slow statement is a prepared statement, and the first few executions are fast. That is an almost certain proof that a mis-estimated generic plan is at fault. You can do the following:

• improve PostgreSQL's estimates so that it doesn't choose that generic plan (best, but difficult)

• set plan_cache_mode to force_custom_plan for this statement (from PostgreSQL v12 on)

• avoid using a prepared statement for this query