Re: What happens between end of explain analyze and end of query execution ?

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