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

From: Franck Routier <franck(dot)routier(at)axege(dot)com>
To: pgsql-performance(at)postgresql(dot)org
Subject: Re: What happens between end of explain analyze and end of query execution ?
Date: 2013-04-05 13:55:08
Message-ID: 515ED7BC.40907@axege.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Le 04/04/2013 21:08, Tom Lane a écrit :
> Franck Routier <franck(dot)routier(at)axege(dot)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

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Tom Lane 2013-04-05 14:17:28 Re: What happens between end of explain analyze and end of query execution ?
Previous Message Merlin Moncure 2013-04-04 19:19:23 Re: What happens between end of explain analyze and end of query execution ?