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-04 18:49:24
Message-ID: 515DCB34.6040801@axege.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Le 04/04/2013 18:25, Tom Lane a écrit :
> Franck Routier <franck(dot)routier(at)axege(dot)com> writes:
>> Right, explain alone takes 3.6 seconds, so the time really seems to go
>> query planning...
> Well, you've not shown us the query, so it's all going to be
> speculation. But maybe you have some extremely expensive function that
> the planner is evaluating to fold to a constant, or something like that?
> The generated plan isn't terribly complicated, but we can't see what
> was required to produce it.
>
> regards, tom lane
>
>
The request is not using any function. It looks like this:

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

Schema looks like this :
rsaidp
|
v
sanrss --------
| |
v v
sanrum sandia
|
v
sanact

Primary keys are most made of several varchars. Foreign keys do exist.
Query is getting these data for one specific sanrss.
This used to take around 50ms to execute, and is now taking 3.5 seconds.
And it looks like this is spent computing a query plan...

I also tried: PREPARE qry(id) as select ....
The prepare takes 3.5 seconds. Execute qry(value) takes a few
milliseconds...

Regards,
Franck

In response to

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message nik9000 2013-04-04 19:05:52 Re: What happens between end of explain analyze and end of query execution ?
Previous Message Tom Lane 2013-04-04 16:25:13 Re: What happens between end of explain analyze and end of query execution ?