pg.ddx.io pgsql-performance@postgresql.org mailing list archive
help / color / mirror / Atom feedQuery timing increased from 3s to 55s when used as function instead of select
9+ messages / 5 participants
[nested] [flat]
* Query timing increased from 3s to 55s when used as function instead of select
@ 2010-05-21 13:54 Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-27 15:33 ` Re: Query timing increased from 3s to 55s when used as function instead of select Craig Ringer <craig@postnewspapers.com.au>
0 siblings, 1 reply; 9+ messages in thread
From: Tyler Hildebrandt @ 2010-05-21 13:54 UTC (permalink / raw)
To: pgsql-performance; +Cc: Sebastian Ritter <sebastian@campbell-lange.net>; rory <rory@campbell-lange.net>
We're using a function that when run as a select statement outside of the
function takes roughly 1.5s to complete whereas running an identical
query within a function is taking around 55s to complete.
We are lost as to why placing this query within a function as opposed to
substituting the variables in a select statement is so drastically different.
The timings posted here are from a 512MB memory virtual machine and are not of
major concern on their own but we are finding the same issue in our production
environment with far superior hardware.
The function can be found here:
http://campbell-lange.net/media/files/fn_medirota_get_staff_leave_summary.sql
---
Timings for the individual components on their own is as follows:
select * from fn_medirota_validate_rota_master(6);
Time: 0.670 ms
select to_date(EXTRACT (YEAR FROM current_date)::text, 'YYYY');
Time: 0.749 ms
select * from fn_medirota_people_template_generator(2, 6, date'2009-01-01',
date'2009-12-31', TRUE) AS templates;
Time: 68.004 ms
select * from fn_medirota_people_template_generator(2, 6, date'2010-01-01',
date'2010-12-31', TRUE) AS templates;
Time: 1797.323
Copying the exact same for loop select statement from the query above into
the psql query buffer and running them with variable substitution yields the
following:
Running FOR loop SElECT with variable substitution:
Time: 3150.585 ms
Whereas invoking the function yields:
select * from fn_medirota_get_staff_leave_summary(6);
Time: 57375.477 ms
We have tried using explain analyse to update the query optimiser, dropped and
recreated the function and have restarted both the machine and the postgres
server multiple times.
Any help or advice would be greatly appreciated.
Kindest regards,
Tyler Hildebrandt
---
EXPLAIN ANALYSE VERBOSE SELECT * FROM fn_medirota_get_staff_leave_summary(6);
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------
{FUNCTIONSCAN
:startup_cost 0.00
:total_cost 260.00
:plan_rows 1000
:plan_width 85
:targetlist (
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 1
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 1
}
:resno 1
:resname id
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 2
:vartype 1043
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 2
}
:resno 2
:resname t_full_name
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 3
:vartype 16
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 3
}
:resno 3
:resname b_enabled
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 4
:vartype 1043
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 4
}
:resno 4
:resname t_anniversary
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 5
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 5
}
:resno 5
:resname n_last_year_annual
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 6
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 6
}
:resno 6
:resname n_last_year_other
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 7
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 7
}
:resno 7
:resname n_this_year_annual
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 8
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 8
}
:resno 8
:resname n_this_year_other
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
)
:qual <>
:lefttree <>
:righttree <>
:initPlan <>
:extParam (b)
:allParam (b)
:scanrelid 1
:funcexpr
{FUNCEXPR
:funcid 150447
:funcresulttype 149366
:funcretset true
:funcformat 0
:args (
{CONST
:consttype 23
:consttypmod -1
:constlen 4
:constbyval true
:constisnull false
:constvalue 4 [ 6 0 0 0 0 0 0 0 ]
}
)
}
:funccolnames ("id" "t_full_name" "b_enabled" "t_anniversary" "n_last_year_
annual" "n_last_year_other" "n_this_year_annual" "n_this_year_other")
:funccoltypes <>
:funccoltypmods <>
}
Function Scan on fn_medirota_get_staff_leave_summary (cost=0.00..260.00
rows=1000 width=85) (actual time=51877.812..51877.893 rows=94 loops=1)
Total runtime: 51878.008 ms
(183 rows)
--
Tyler Hildebrandt
Software Developer
tyler@campbell-lange.net
Campbell-Lange Workshop
www.campbell-lange.net
020 7631 1555
3 Tottenham Street London W1T 2AF
Registered in England No. 04551928
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: Query timing increased from 3s to 55s when used as function instead of select
2010-05-21 13:54 Query timing increased from 3s to 55s when used as function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
@ 2010-05-27 15:33 ` Craig Ringer <craig@postnewspapers.com.au>
2010-05-27 15:55 ` Re: Query timing increased from 3s to 55s when used as function instead of select Craig Ringer <craig@postnewspapers.com.au>
0 siblings, 1 reply; 9+ messages in thread
From: Craig Ringer @ 2010-05-27 15:33 UTC (permalink / raw)
To: Tyler Hildebrandt <tyler@campbell-lange.net>; +Cc: pgsql-performance@postgresql.org, Sebastian Ritter <sebastian@campbell-lange.net>; rory <rory@campbell-lange.net>
On 21/05/2010 9:54 PM, Tyler Hildebrandt wrote:
> We're using a function that when run as a select statement outside of the
> function takes roughly 1.5s to complete whereas running an identical
> query within a function is taking around 55s to complete.
>
> We are lost as to why placing this query within a function as opposed to
> substituting the variables in a select statement is so drastically different.
This is a frequently asked question. It's the same issue as with
prepared queries, where the planner has to pick a more general plan when
it doesn't know the value of a parameter. The short answer is "work
around it by using EXECUTE ... USING to invoke your query dynamically".
( Oddly, this FAQ doesn't seem to be on the FAQ list at
http://wiki.postgresql.org/wiki/FAQ )
--
Craig Ringer
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: Query timing increased from 3s to 55s when used as function instead of select
2010-05-21 13:54 Query timing increased from 3s to 55s when used as function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-27 15:33 ` Re: Query timing increased from 3s to 55s when used as function instead of select Craig Ringer <craig@postnewspapers.com.au>
@ 2010-05-27 15:55 ` Craig Ringer <craig@postnewspapers.com.au>
0 siblings, 0 replies; 9+ messages in thread
From: Craig Ringer @ 2010-05-27 15:55 UTC (permalink / raw)
To: Tyler Hildebrandt <tyler@campbell-lange.net>; +Cc: pgsql-performance@postgresql.org, Sebastian Ritter <sebastian@campbell-lange.net>; rory <rory@campbell-lange.net>
On 27/05/2010 11:33 PM, Craig Ringer wrote:
> On 21/05/2010 9:54 PM, Tyler Hildebrandt wrote:
>> We're using a function that when run as a select statement outside of the
>> function takes roughly 1.5s to complete whereas running an identical
>> query within a function is taking around 55s to complete.
>>
>> We are lost as to why placing this query within a function as opposed to
>> substituting the variables in a select statement is so drastically
>> different.
>
> This is a frequently asked question. It's the same issue as with
> prepared queries, where the planner has to pick a more general plan when
> it doesn't know the value of a parameter. The short answer is "work
> around it by using EXECUTE ... USING to invoke your query dynamically".
>
> ( Oddly, this FAQ doesn't seem to be on the FAQ list at
> http://wiki.postgresql.org/wiki/FAQ )
Added as:
http://wiki.postgresql.org/wiki/FAQ#Why_is_my_query_much_slower_when_run_as_a_prepared_query.3F
and the subsequent entry too.
Comments, edits, clarification appreciated. I know it's not as well
written as it could be, could use archive links, etc; it's just pass 1.
--
Craig Ringer
^ permalink raw reply [nested|flat] 9+ messages in thread
* Query timing increased from 3s to 55s when used as a function instead of select
@ 2010-05-25 09:59 Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-25 10:30 ` Re: Query timing increased from 3s to 55s when used as a function instead of select A. Kretschmer <andreas.kretschmer@schollglas.com>
2010-05-25 16:18 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Jorge Montero <jorge_montero@homedecorators.com>
0 siblings, 2 replies; 9+ messages in thread
From: Tyler Hildebrandt @ 2010-05-25 09:59 UTC (permalink / raw)
To: pgsql-performance
We're using a function that when run as a select statement outside of the
function takes roughly 1.5s to complete whereas running an identical
query within a function is taking around 55s to complete.
We are lost as to why placing this query within a function as opposed to
substituting the variables in a select statement is so drastically different.
The timings posted here are from a 512MB memory virtual machine and are not of
major concern on their own but we are finding the same issue in our production
environment with far superior hardware.
The function can be found here:
http://campbell-lange.net/media/files/fn_medirota_get_staff_leave_summary.sql
---
Timings for the individual components on their own is as follows:
select * from fn_medirota_validate_rota_master(6);
Time: 0.670 ms
select to_date(EXTRACT (YEAR FROM current_date)::text, 'YYYY');
Time: 0.749 ms
select * from fn_medirota_people_template_generator(2, 6, date'2009-01-01',
date'2009-12-31', TRUE) AS templates;
Time: 68.004 ms
select * from fn_medirota_people_template_generator(2, 6, date'2010-01-01',
date'2010-12-31', TRUE) AS templates;
Time: 1797.323
Copying the exact same for loop select statement from the query above into
the psql query buffer and running them with variable substitution yields the
following:
Running FOR loop SElECT with variable substitution:
Time: 3150.585 ms
Whereas invoking the function yields:
select * from fn_medirota_get_staff_leave_summary(6);
Time: 57375.477 ms
We have tried using explain analyse to update the query optimiser, dropped and
recreated the function and have restarted both the machine and the postgres
server multiple times.
Any help or advice would be greatly appreciated.
Kindest regards,
Tyler Hildebrandt
---
EXPLAIN ANALYSE VERBOSE SELECT * FROM fn_medirota_get_staff_leave_summary(6);
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------
{FUNCTIONSCAN
:startup_cost 0.00
:total_cost 260.00
:plan_rows 1000
:plan_width 85
:targetlist (
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 1
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 1
}
:resno 1
:resname id
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 2
:vartype 1043
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 2
}
:resno 2
:resname t_full_name
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 3
:vartype 16
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 3
}
:resno 3
:resname b_enabled
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 4
:vartype 1043
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 4
}
:resno 4
:resname t_anniversary
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 5
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 5
}
:resno 5
:resname n_last_year_annual
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 6
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 6
}
:resno 6
:resname n_last_year_other
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 7
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 7
}
:resno 7
:resname n_this_year_annual
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 8
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 8
}
:resno 8
:resname n_this_year_other
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
)
:qual <>
:lefttree <>
:righttree <>
:initPlan <>
:extParam (b)
:allParam (b)
:scanrelid 1
:funcexpr
{FUNCEXPR
:funcid 150447
:funcresulttype 149366
:funcretset true
:funcformat 0
:args (
{CONST
:consttype 23
:consttypmod -1
:constlen 4
:constbyval true
:constisnull false
:constvalue 4 [ 6 0 0 0 0 0 0 0 ]
}
)
}
:funccolnames ("id" "t_full_name" "b_enabled" "t_anniversary" "n_last_year_
annual" "n_last_year_other" "n_this_year_annual" "n_this_year_other")
:funccoltypes <>
:funccoltypmods <>
}
Function Scan on fn_medirota_get_staff_leave_summary (cost=0.00..260.00
rows=1000 width=85) (actual time=51877.812..51877.893 rows=94 loops=1)
Total runtime: 51878.008 ms
(183 rows)
--
Tyler Hildebrandt
Software Developer
tyler@campbell-lange.net
Campbell-Lange Workshop
www.campbell-lange.net
020 7631 1555
3 Tottenham Street London W1T 2AF
Registered in England No. 04551928
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: Query timing increased from 3s to 55s when used as a function instead of select
2010-05-25 09:59 Query timing increased from 3s to 55s when used as a function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
@ 2010-05-25 10:30 ` A. Kretschmer <andreas.kretschmer@schollglas.com>
2010-05-25 13:41 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
1 sibling, 1 reply; 9+ messages in thread
From: A. Kretschmer @ 2010-05-25 10:30 UTC (permalink / raw)
To: pgsql-performance
In response to Tyler Hildebrandt :
> We're using a function that when run as a select statement outside of the
> function takes roughly 1.5s to complete whereas running an identical
> query within a function is taking around 55s to complete.
>
> select * from fn_medirota_get_staff_leave_summary(6);
> Time: 57375.477 ms
I think, your problem is here:
SELECT INTO current_user * FROM
fn_medirota_validate_rota_master(in_currentuser);
The planner has no knowledge about how many rows this functions returns
if he don't know the actual parameter. Because of this, this query
enforce a seq-scan. Try to rewrite that to something like:
execute 'select * from fn_medirota_validate_rota_master(' ||
in_currentuser' || ')' into current_user
*untested*
HTH, Andreas
--
Andreas Kretschmer
Kontakt: Heynitz: 035242/47150, D1: 0160/7141639 (mehr: -> Header)
GnuPG: 0x31720C99, 1006 CCB4 A326 1D42 6431 2EB0 389D 1DC2 3172 0C99
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: Query timing increased from 3s to 55s when used as a function instead of select
2010-05-25 09:59 Query timing increased from 3s to 55s when used as a function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-25 10:30 ` Re: Query timing increased from 3s to 55s when used as a function instead of select A. Kretschmer <andreas.kretschmer@schollglas.com>
@ 2010-05-25 13:41 ` Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-25 14:55 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Merlin Moncure <mmoncure@gmail.com>
0 siblings, 1 reply; 9+ messages in thread
From: Tyler Hildebrandt @ 2010-05-25 13:41 UTC (permalink / raw)
To: pgsql-performance
> I think, your problem is here:
>
> SELECT INTO current_user * FROM
> fn_medirota_validate_rota_master(in_currentuser);
>
>
> The planner has no knowledge about how many rows this functions returns
> if he don't know the actual parameter. Because of this, this query
> enforce a seq-scan. Try to rewrite that to something like:
>
> execute 'select * from fn_medirota_validate_rota_master(' ||
> in_currentuser' || ')' into current_user
>
Thanks for your response. This doesn't seem to solve our issue, unfortunately.
As a side to that, we have the fn_medirota_validate_rota_master calls in a
large amount of our other functions that are running very well.
--
Tyler Hildebrandt
Software Developer
tyler@campbell-lange.net
Campbell-Lange Workshop
www.campbell-lange.net
020 7631 1555
3 Tottenham Street London W1T 2AF
Registered in England No. 04551928
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: Query timing increased from 3s to 55s when used as a function instead of select
2010-05-25 09:59 Query timing increased from 3s to 55s when used as a function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-25 10:30 ` Re: Query timing increased from 3s to 55s when used as a function instead of select A. Kretschmer <andreas.kretschmer@schollglas.com>
2010-05-25 13:41 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
@ 2010-05-25 14:55 ` Merlin Moncure <mmoncure@gmail.com>
2010-05-25 14:57 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Merlin Moncure <mmoncure@gmail.com>
0 siblings, 1 reply; 9+ messages in thread
From: Merlin Moncure @ 2010-05-25 14:55 UTC (permalink / raw)
To: Tyler Hildebrandt <tyler@campbell-lange.net>; +Cc: pgsql-performance
On Tue, May 25, 2010 at 9:41 AM, Tyler Hildebrandt
<tyler@campbell-lange.net> wrote:
>> I think, your problem is here:
>>
>> SELECT INTO current_user * FROM
>> fn_medirota_validate_rota_master(in_currentuser);
>>
>>
>> The planner has no knowledge about how many rows this functions returns
>> if he don't know the actual parameter. Because of this, this query
>> enforce a seq-scan. Try to rewrite that to something like:
>>
>> execute 'select * from fn_medirota_validate_rota_master(' ||
>> in_currentuser' || ')' into current_user
>>
>
> Thanks for your response. This doesn't seem to solve our issue, unfortunately.
>
> As a side to that, we have the fn_medirota_validate_rota_master calls in a
> large amount of our other functions that are running very well.
any chance of seeing the function source?
merlin
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: Query timing increased from 3s to 55s when used as a function instead of select
2010-05-25 09:59 Query timing increased from 3s to 55s when used as a function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-25 10:30 ` Re: Query timing increased from 3s to 55s when used as a function instead of select A. Kretschmer <andreas.kretschmer@schollglas.com>
2010-05-25 13:41 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-25 14:55 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Merlin Moncure <mmoncure@gmail.com>
@ 2010-05-25 14:57 ` Merlin Moncure <mmoncure@gmail.com>
0 siblings, 0 replies; 9+ messages in thread
From: Merlin Moncure @ 2010-05-25 14:57 UTC (permalink / raw)
To: Tyler Hildebrandt <tyler@campbell-lange.net>; +Cc: pgsql-performance
On Tue, May 25, 2010 at 10:55 AM, Merlin Moncure <mmoncure@gmail.com> wrote:
> On Tue, May 25, 2010 at 9:41 AM, Tyler Hildebrandt
> <tyler@campbell-lange.net> wrote:
>>> I think, your problem is here:
>>>
>>> SELECT INTO current_user * FROM
>>> fn_medirota_validate_rota_master(in_currentuser);
>>>
>>>
>>> The planner has no knowledge about how many rows this functions returns
>>> if he don't know the actual parameter. Because of this, this query
>>> enforce a seq-scan. Try to rewrite that to something like:
>>>
>>> execute 'select * from fn_medirota_validate_rota_master(' ||
>>> in_currentuser' || ')' into current_user
>>>
>>
>> Thanks for your response. This doesn't seem to solve our issue, unfortunately.
>>
>> As a side to that, we have the fn_medirota_validate_rota_master calls in a
>> large amount of our other functions that are running very well.
>
> any chance of seeing the function source?
oops! I missed it :-). looking at your function, what version of
postgres? have you experimented w/return query?
merlin
^ permalink raw reply [nested|flat] 9+ messages in thread
* Re: Query timing increased from 3s to 55s when used as a function instead of select
2010-05-25 09:59 Query timing increased from 3s to 55s when used as a function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
@ 2010-05-25 16:18 ` Jorge Montero <jorge_montero@homedecorators.com>
1 sibling, 0 replies; 9+ messages in thread
From: Jorge Montero @ 2010-05-25 16:18 UTC (permalink / raw)
To: Tyler Hildebrandt <tyler@campbell-lange.net>; pgsql-performance
Have you read this?
http://blog.endpoint.com/2008/12/why-is-my-function-slow.html
99% of the 'function is slow' problems are caused by this.
Have you checked the difference between explain and prepare + explain execute?
>>> Tyler Hildebrandt <tyler@campbell-lange.net> 05/25/10 4:59 AM >>>
We're using a function that when run as a select statement outside of the
function takes roughly 1.5s to complete whereas running an identical
query within a function is taking around 55s to complete.
We are lost as to why placing this query within a function as opposed to
substituting the variables in a select statement is so drastically different.
The timings posted here are from a 512MB memory virtual machine and are not of
major concern on their own but we are finding the same issue in our production
environment with far superior hardware.
The function can be found here:
http://campbell-lange.net/media/files/fn_medirota_get_staff_leave_summary.sql
---
Timings for the individual components on their own is as follows:
select * from fn_medirota_validate_rota_master(6);
Time: 0.670 ms
select to_date(EXTRACT (YEAR FROM current_date)::text, 'YYYY');
Time: 0.749 ms
select * from fn_medirota_people_template_generator(2, 6, date'2009-01-01',
date'2009-12-31', TRUE) AS templates;
Time: 68.004 ms
select * from fn_medirota_people_template_generator(2, 6, date'2010-01-01',
date'2010-12-31', TRUE) AS templates;
Time: 1797.323
Copying the exact same for loop select statement from the query above into
the psql query buffer and running them with variable substitution yields the
following:
Running FOR loop SElECT with variable substitution:
Time: 3150.585 ms
Whereas invoking the function yields:
select * from fn_medirota_get_staff_leave_summary(6);
Time: 57375.477 ms
We have tried using explain analyse to update the query optimiser, dropped and
recreated the function and have restarted both the machine and the postgres
server multiple times.
Any help or advice would be greatly appreciated.
Kindest regards,
Tyler Hildebrandt
---
EXPLAIN ANALYSE VERBOSE SELECT * FROM fn_medirota_get_staff_leave_summary(6);
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------------------------------------
{FUNCTIONSCAN
:startup_cost 0.00
:total_cost 260.00
:plan_rows 1000
:plan_width 85
:targetlist (
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 1
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 1
}
:resno 1
:resname id
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 2
:vartype 1043
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 2
}
:resno 2
:resname t_full_name
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 3
:vartype 16
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 3
}
:resno 3
:resname b_enabled
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 4
:vartype 1043
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 4
}
:resno 4
:resname t_anniversary
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 5
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 5
}
:resno 5
:resname n_last_year_annual
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 6
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 6
}
:resno 6
:resname n_last_year_other
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 7
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 7
}
:resno 7
:resname n_this_year_annual
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
{TARGETENTRY
:expr
{VAR
:varno 1
:varattno 8
:vartype 23
:vartypmod -1
:varlevelsup 0
:varnoold 1
:varoattno 8
}
:resno 8
:resname n_this_year_other
:ressortgroupref 0
:resorigtbl 0
:resorigcol 0
:resjunk false
}
)
:qual <>
:lefttree <>
:righttree <>
:initPlan <>
:extParam (b)
:allParam (b)
:scanrelid 1
:funcexpr
{FUNCEXPR
:funcid 150447
:funcresulttype 149366
:funcretset true
:funcformat 0
:args (
{CONST
:consttype 23
:consttypmod -1
:constlen 4
:constbyval true
:constisnull false
:constvalue 4 [ 6 0 0 0 0 0 0 0 ]
}
)
}
:funccolnames ("id" "t_full_name" "b_enabled" "t_anniversary" "n_last_year_
annual" "n_last_year_other" "n_this_year_annual" "n_this_year_other")
:funccoltypes <>
:funccoltypmods <>
}
Function Scan on fn_medirota_get_staff_leave_summary (cost=0.00..260.00
rows=1000 width=85) (actual time=51877.812..51877.893 rows=94 loops=1)
Total runtime: 51878.008 ms
(183 rows)
--
Tyler Hildebrandt
Software Developer
tyler@campbell-lange.net
Campbell-Lange Workshop
www.campbell-lange.net
020 7631 1555
3 Tottenham Street London W1T 2AF
Registered in England No. 04551928
--
Sent via pgsql-performance mailing list (pgsql-performance@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-performance
^ permalink raw reply [nested|flat] 9+ messages in thread
end of thread, other threads:[~2010-05-27 15:55 UTC | newest]
Thread overview: 9+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2010-05-21 13:54 Query timing increased from 3s to 55s when used as function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-27 15:33 ` Re: Query timing increased from 3s to 55s when used as function instead of select Craig Ringer <craig@postnewspapers.com.au>
2010-05-27 15:55 ` Re: Query timing increased from 3s to 55s when used as function instead of select Craig Ringer <craig@postnewspapers.com.au>
2010-05-25 09:59 Query timing increased from 3s to 55s when used as a function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-25 10:30 ` Re: Query timing increased from 3s to 55s when used as a function instead of select A. Kretschmer <andreas.kretschmer@schollglas.com>
2010-05-25 13:41 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Tyler Hildebrandt <tyler@campbell-lange.net>
2010-05-25 14:55 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Merlin Moncure <mmoncure@gmail.com>
2010-05-25 14:57 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Merlin Moncure <mmoncure@gmail.com>
2010-05-25 16:18 ` Re: Query timing increased from 3s to 55s when used as a function instead of select Jorge Montero <jorge_montero@homedecorators.com>
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