We’re having trouble working out why the planning time for this particular 
query is slow (~2.5s vs 0.9ms execution time). As you can see below, there are 
only 3 tables involved so it’s hard to imagine what decisions the planner has 
to make that take so long. After 5 runs the prepared-statement code kicks in 
and it becomes quick, but it’s quite infuriating for the first 5 runs given the 
execution is so much faster.

Are you able to give any tips what might be taking so long (and how we might 
improve it)?

We read elsewhere that someone had a “catalog stats file leak”, which I’m 
taking to mean a big pg_statistic table. Ours is 10mb, which doesn’t seem 
particularly large to me, but I don’t have much context for it. 
https://www.postgresql.org/message-id/CABWW-d21z_WgawkjXFQQviqm16oAx0KQvR6bLkRxvYQmhdByfg%40mail.gmail.com

Other queries (with 3 or more tables) in the same db seem to be planning much 
quicker.

The query:

explain (analyse) SELECT subscription_binding.subscription_binding,
     subscription_binding.tid,
     subscription.subscription_uuid,
     subscription_binding.subscription_binding_uuid,
     binding.binding_uuid,
     subscription_binding.start_time,
     subscription_binding.end_time,
     subscription_binding.timezone,
     now() >= subscription_binding.start_time AND 
(subscription_binding.end_time IS NULL OR now() <= 
subscription_binding.end_time) AS active
    FROM jackpot.binding
      JOIN jackpot.subscription_binding USING (tid, binding)
      JOIN jackpot.subscription USING (tid, subscription)
    where (tid=2082003407) AND 
(binding_uuid='4f61dcd5-97a0-4098-b9ae-c1546c31b2e6'::uuid) offset 0 limit 1000;
                                                                            
QUERY PLAN
------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit  (cost=1.29..25.38 rows=1 width=80) (actual time=0.770..0.771 rows=1 
loops=1)
   ->  Nested Loop  (cost=1.29..25.38 rows=1 width=80) (actual 
time=0.770..0.771 rows=1 loops=1)
         ->  Nested Loop  (cost=0.86..16.91 rows=1 width=76) (actual 
time=0.697..0.698 rows=1 loops=1)
               ->  Index Scan using binding_tid_binding_uuid_key on binding  
(cost=0.43..8.45 rows=1 width=28) (actual time=0.647..0.647 rows=1 loops=1)
                     Index Cond: ((tid = 2082003407) AND (binding_uuid = 
'4f61dcd5-97a0-4098-b9ae-c1546c31b2e6'::uuid))
               ->  Index Scan using subscription_binding_idx on 
subscription_binding  (cost=0.43..8.45 rows=1 width=64) (actual 
time=0.045..0.046 rows=1 loops=1)
                     Index Cond: ((tid = 2082003407) AND (binding = 
binding.binding))
         ->  Index Scan using subscription_pkey on subscription  
(cost=0.43..8.45 rows=1 width=28) (actual time=0.068..0.068 rows=1 loops=1)
               Index Cond: ((tid = 2082003407) AND (subscription = 
subscription_binding.subscription))
Planning time: 2429.682 ms
Execution time: 0.914 ms
(11 rows)

Postgres version 9.5.19

Each of the tables has between 3-4 indexes, and all the indexes include tid as 
first parameter. No partitions, no sign of a stray replication slot / 
uncommitted transaction / prepared transaction that may be holding up autovac, 
no sign of bloated indexes.

TIA!

Best regards,

David Wheeler
General Manager Bali Office
Bali T +62 361 475 2333   M +62 819 3660 9180
E dwhee...@dgitsystems.com<mailto:dwhee...@dgitsystems.com>
Jl. Pura Mertasari No. 7, Sunset Road Abian Base
Kuta, Badung – Bali 80361, Indonesia
http://www.dgitsystems.com<http://www.dgitsystems.com/>

[signature_1605257152][signature_1263573595]


Reply via email to