pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
From: David Wheeler <dwheeler@dgitsystems.com>
To: pgsql-performance@lists.postgresql.org <pgsql-performance@lists.postgresql.org>
Cc: Cameron Redpath <credpath@dgitsystems.com>
Subject: Slow planning, fast execution for particular 3-table query
Date: Mon, 4 Nov 2019 03:04:45 +0000
Message-ID: <175BE386-F861-4064-8B5D-93E63BD90F13@dgitsystems.com> (raw)

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.gma...

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 dwheeler@dgitsystems.com<mailto:dwheeler@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]




Attachments:

image001.png (image/png, 53.0K) download view image
image002.jpg (image/jpeg, 23.9K) download view image

view thread (13+ messages)  latest in thread

Message-ID: <175BE386-F861-4064-8B5D-93E63BD90F13@dgitsystems.com>
Permalink:  ../175BE386-F861-4064-8B5D-93E63BD90F13@dgitsystems.com/
Also on:    postgresql.org/message-id/175BE386-F861-4064-8B5D-93E63BD90F13@dgitsystems.com

 · 

reply

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Reply to all the recipients using the --to and --cc options:
  reply via email

  To: pgsql-performance@postgresql.org
  Cc: dwheeler@dgitsystems.com, pgsql-performance@lists.postgresql.org, credpath@dgitsystems.com
  Subject: Re: Slow planning, fast execution for particular 3-table query
  In-Reply-To: <175BE386-F861-4064-8B5D-93E63BD90F13@dgitsystems.com>

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox