[pgrouting-users] Re: [OT] stored procedure performance [SOLVED]

[Stephen Woodbridge]

OK, googling about seems like this is normal but bad behavior. I did 
fine a way to work around this bad behavior.

This is BAD (function called 6 times):
select a.*, (b).* from (select x, y, imt_rgeo_countyzip(x,y) as b from 
(select -79.2723 as x, 41.2393 as y) as c) as a;

This is GOOD (function called 1 time):
select a.*, (b).* from (select x, y, imt_rgeo_countyzip(x,y) as b from 
(select -79.2723 as x, 41.2393 as y) as c offset 0) as a;

It is amazing what you can find in Google :)

-Steve

On 10/24/2011 12:04 PM, Stephen Woodbridge wrote:
> Hi All,
>
> This is a little off topic, but I did find this issue developing a
> postgis related stored procedure.
>
> This is a simple reverse geocoder and it works fine, but here is the
> issue and this potentially impacts all procedures that return a record.
>
> So here is the basic query. I added some raise notice to show whats
> happening.
>
> select * from imt_rgeo_countyzip(-79.2723,41.2393);
> "Clarion";"PA";"42031";"16225";0;0
>
> NOTICE: calling imt_rgeo_countyzip
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: rr: (Clarion,PA,42031,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: zip: (16225,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> Total query runtime: 81 ms.
> 1 row retrieved.
>
> So here is the problem! If you call the function this way, it appears to
> get called once for each field in the returned record. So if you have 6
> fields it actually executes the function 6 times!!!! and the cost goes
> up by 6X to 415 ms from 81 ms.
>
> select (imt_rgeo_countyzip(-79.2723,41.2393)).*;
> "Clarion";"PA";"42031";"16225";0;0
>
> NOTICE: calling imt_rgeo_countyzip
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: rr: (Clarion,PA,42031,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: zip: (16225,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: calling imt_rgeo_countyzip
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: rr: (Clarion,PA,42031,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: zip: (16225,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: calling imt_rgeo_countyzip
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: rr: (Clarion,PA,42031,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: zip: (16225,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: calling imt_rgeo_countyzip
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: rr: (Clarion,PA,42031,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: zip: (16225,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: calling imt_rgeo_countyzip
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: rr: (Clarion,PA,42031,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: zip: (16225,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: calling imt_rgeo_countyzip
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: rr: (Clarion,PA,42031,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
> NOTICE: zip: (16225,0), radius: 0.0013
> CONTEXT: PL/pgSQL function "imt_rgeo_countyzip" line 8 at assignment
>
> Total query runtime: 415 ms.
> 1 row retrieved.
>
> Thoughts,
> -Steve