pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
From: Franck Routier <franck.routier@axege.com>
To: pgsql-performance@postgresql.org
Subject: Re: What happens between end of explain analyze and end of query execution ?
Date: Fri, 05 Apr 2013 15:55:08 +0200
Message-ID: <515ED7BC.40907@axege.com> (raw)
In-Reply-To: <6354.1365102532@sss.pgh.pa.us>
References: <515D92BF.5000309@axege.com>
	<CAPmjWd100eemBz1RTw=r24zgh8+YO8iq86fThqsALznrPuyWqg@mail.gmail.com>
	<515D9FC5.7030105@axege.com>
	<18910.1365092713@sss.pgh.pa.us>
	<515DCB34.6040801@axege.com>
	<6354.1365102532@sss.pgh.pa.us>
List-Unsubscribe:  <mailto:majordomo@postgresql.org?body=unsub%20pgsql-performance>

Le 04/04/2013 21:08, Tom Lane a écrit :
> Franck Routier <franck.routier@axege.com> writes:
>> The request is not using any function. It looks like this:
>> [ unexciting query ]
> Hmph.  Can't see any reason for that to take a remarkably long time to
> plan.  Can you put together a self-contained test case demonstrating
> excessive planning time?  What PG version is this, anyway?
>
> 			regards, tom lane
>
>
Well, I don't know how to reproduce, as it is really only happening on 
this database.

What I notice is that removing joins has a huge impact on the time 
explain takes to return:

The full query takes 2.6 seconds to return. Notice it has dropped from 
3.6 seconds to 2.6 since yesterday after I did a vacuum analyze on the 
tables that go into the request.

EXPLAIN SELECT *
          FROM sanrss
          LEFT JOIN sanrum  ON sanrum.sanrum___rforefide = 
sanrss.sanrss___rforefide AND sanrum.sanrum___rfovsnide = 
sanrss.sanrss___rfovsnide AND sanrum.sanrum___sanrsside = sanrss.sanrsside
             LEFT JOIN sanact  ON sanact.sanact___rforefide = 
sanrum.sanrum___rforefide AND sanact.sanact___rfovsnide = 
sanrum.sanrum___rfovsnide AND sanact.sanact___sanrsside = 
sanrum.sanrum___sanrsside AND sanact.sanact___sanrumide = 
sanrum.sanrumide AND sanact.sanact___sanrumide   IS NOT NULL AND 
sanact.sanact___rsanopide='CCAM'
             LEFT JOIN sandia  ON sandia.sandia___rforefide = 
sanrum.sanrum___rforefide AND sandia.sandia___rfovsnide = 
sanrum.sanrum___rfovsnide AND sandia.sandia___sanrsside = 
sanrum.sanrum___sanrsside AND sandia.sandia___sanrumide = 
sanrum.sanrumide AND sandia.sandiasig=1
             LEFT JOIN saneds  ON sanrss.sanrss___rforefide = 
saneds.saneds___rforefide AND sanrss.sanrss___rfovsnide = 
saneds.saneds___rfovsnide AND sanrss.sanrss___sanedside = saneds.sanedside
             LEFT JOIN rsaidp  ON saneds.saneds___rforefide = 
rsaidp.rsaidp___rforefide AND saneds.saneds___rsaidpide = rsaidp.rsaidpide
               WHERE sanrss.sanrss___rforefide =  'CHCL' AND 
sanrss.sanrss___rfovsnide =  '201012_600'  AND sanrss.sanrsside =  '1188100'
          ORDER BY sanrum.sanrumord, sanrum.sanrumide

==> 2.6 seconds

If I remove the join on either table 'sandia' or table 'saneds', the 
explain return in 1.2 seconds. If I remove both, explain returns in 48ms.

EXPLAIN SELECT *
          FROM sanrss
          LEFT JOIN sanrum  ON sanrum.sanrum___rforefide = 
sanrss.sanrss___rforefide AND sanrum.sanrum___rfovsnide = 
sanrss.sanrss___rfovsnide AND sanrum.sanrum___sanrsside = sanrss.sanrsside
             LEFT JOIN sanact  ON sanact.sanact___rforefide = 
sanrum.sanrum___rforefide AND sanact.sanact___rfovsnide = 
sanrum.sanrum___rfovsnide AND sanact.sanact___sanrsside = 
sanrum.sanrum___sanrsside AND sanact.sanact___sanrumide = 
sanrum.sanrumide AND sanact.sanact___sanrumide   IS NOT NULL AND 
sanact.sanact___rsanopide='CCAM'
             LEFT JOIN saneds  ON sanrss.sanrss___rforefide = 
saneds.saneds___rforefide AND sanrss.sanrss___rfovsnide = 
saneds.saneds___rfovsnide AND sanrss.sanrss___sanedside = saneds.sanedside
             LEFT JOIN rsaidp  ON saneds.saneds___rforefide = 
rsaidp.rsaidp___rforefide AND saneds.saneds___rsaidpide = rsaidp.rsaidpide
               WHERE sanrss.sanrss___rforefide =  'CHCL' AND 
sanrss.sanrss___rfovsnide =  '201012_600'  AND sanrss.sanrsside =  '1188100'
          ORDER BY sanrum.sanrumord, sanrum.sanrumide

==> 1.2 seconds

EXPLAIN SELECT *
          FROM sanrss
          LEFT JOIN sanrum  ON sanrum.sanrum___rforefide = 
sanrss.sanrss___rforefide AND sanrum.sanrum___rfovsnide = 
sanrss.sanrss___rfovsnide AND sanrum.sanrum___sanrsside = sanrss.sanrsside
             LEFT JOIN sanact  ON sanact.sanact___rforefide = 
sanrum.sanrum___rforefide AND sanact.sanact___rfovsnide = 
sanrum.sanrum___rfovsnide AND sanact.sanact___sanrsside = 
sanrum.sanrum___sanrsside AND sanact.sanact___sanrumide = 
sanrum.sanrumide AND sanact.sanact___sanrumide   IS NOT NULL AND 
sanact.sanact___rsanopide='CCAM'
             LEFT JOIN sandia  ON sandia.sandia___rforefide = 
sanrum.sanrum___rforefide AND sandia.sandia___rfovsnide = 
sanrum.sanrum___rfovsnide AND sandia.sandia___sanrsside = 
sanrum.sanrum___sanrsside AND sandia.sandia___sanrumide = 
sanrum.sanrumide AND sandia.sandiasig=1
               WHERE sanrss.sanrss___rforefide =  'CHCL' AND 
sanrss.sanrss___rfovsnide =  '201012_600'  AND sanrss.sanrsside =  '1188100'
          ORDER BY sanrum.sanrumord, sanrum.sanrumide

==> 1.2 seconds

EXPLAIN SELECT *
          FROM sanrss
          LEFT JOIN sanrum  ON sanrum.sanrum___rforefide = 
sanrss.sanrss___rforefide AND sanrum.sanrum___rfovsnide = 
sanrss.sanrss___rfovsnide AND sanrum.sanrum___sanrsside = sanrss.sanrsside
             LEFT JOIN sanact  ON sanact.sanact___rforefide = 
sanrum.sanrum___rforefide AND sanact.sanact___rfovsnide = 
sanrum.sanrum___rfovsnide AND sanact.sanact___sanrsside = 
sanrum.sanrum___sanrsside AND sanact.sanact___sanrumide = 
sanrum.sanrumide AND sanact.sanact___sanrumide   IS NOT NULL AND 
sanact.sanact___rsanopide='CCAM'
               WHERE sanrss.sanrss___rforefide =  'CHCL' AND 
sanrss.sanrss___rfovsnide =  '201012_600'  AND sanrss.sanrsside =  '1188100'
          ORDER BY sanrum.sanrumord, sanrum.sanrumide

==> 48 ms

Maybe the statistics tables for sandia and saneds are in a bad shape ? 
(don't know how to check this).

Regards,

Franck

Attachments:

  smime.p7s (application/pkcs7-signature, 4.4K) download

view thread (21+ messages)  latest in thread

Message-ID: <515ED7BC.40907@axege.com>
Permalink:  ../515ED7BC.40907@axege.com/
Also on:    postgresql.org/message-id/515ED7BC.40907@axege.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: franck.routier@axege.com
  Subject: Re: What happens between end of explain analyze and end of query execution ?
  In-Reply-To: <515ED7BC.40907@axege.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