Thread: SQL Function Performance

SQL Function Performance

From
"Adnan DURSUN"
Date:
 
            Hi all,
 
            My database has an SQL function. The result comes in 30-40 seconds when i use the SQL function. On the other hand; The result comes
        300-400 milliseconds when i run the SQL statement. Any idea ?? My database is Postgresql 8.1.2..
       
            Function is below :
 
CREATE OR REPLACE FUNCTION fn_online_seferler_satis("varchar", date, int4, "varchar", "varchar")
  RETURNS SETOF record AS
$BODY$
SELECT  (S.KALKIS_YERI||' '||S.VARIS_YERI||' '||S.SAAT)::varchar AS SEFER_BILGI,
 sum((i.bilet_ucreti + coalesce(i.police_ucreti,0)) - coalesce(i.int_artik_ucret,0)) as top_satis,
 count(1)::int4 as top_koltuk
   FROM T_KOLTUK_ISLEM I,
 T_KOLTUK_SON_DURUM SD,
 T_LOKAL_PLAN LP,
 W_SEFERLER S
  WHERE I.FIRMA_NO = SD.FIRMA_NO
    AND I.HAT_NO = SD.HAT_NO
    AND I.SEFER_KOD = SD.SEFER_KOD
    AND I.PLAN_TARIHI = SD.PLAN_TARIHI
    AND I.BIN_YER_KOD = SD.BIN_YER_KOD
    AND I.KOLTUK_NO = SD.KOLTUK_NO
    AND I.KOD = SD.ISLEM_KOD
    AND SD.ISLEM = 'S'
    AND LP.FIRMA_NO = I.FIRMA_NO
    AND LP.HAT_NO = I.HAT_NO
    AND LP.SEFER_KOD = I.SEFER_KOD
    AND LP.PLAN_TARIHI = I.PLAN_TARIHI
    AND LP.YER_KOD = I.BIN_YER_KOD
    AND I.FIRMA_NO = $1
    AND S.FIRMA_NO = LP.FIRMA_NO
    AND S.HAT_NO = LP.HAT_NO
    AND S.KOD = LP.SEFER_KOD
    AND S.IPTAL = 'H'
    AND ((I.ISLEM_TARIHI =  $2 AND $5 = 'I') OR (LP.KALKIS_TARIHI = $2 AND $5 = 'K'))
    AND (((LP.LOKAL_KOD = $3 AND $4 = 'K')) OR  ((I.ypt_lcl_kod = $3 AND $4 = 'I'))) 
GROUP BY S.KALKIS_YERI,S.VARIS_YERI,S.SAAT;
$BODY$
  LANGUAGE 'sql' VOLATILE;
 
Adnan DURSUN
ASRIN Bilişim Ltd.Şti
Turkey
 

Re: SQL Function Performance

From
andrew@pillette.com
Date:
If you have only recently analyzed the tables in the query, close your psql session (if that's what you were using) and
thenrestart it. I've gotten burned by asking a query using the function, which I believe is when PG creates the plan
forthe function, and then making significant changes to the tables behind it (new index, bulk insert, etc.). By
startinga new session, the function will be re-planned according to up to date statistics or using newly created
indices.

Re: SQL Function Performance

From
Michael Fuhr
Date:
On Sun, Feb 12, 2006 at 10:25:28PM +0200, Adnan DURSUN wrote:
> My database has an SQL function. The result comes in 30-40 seconds
> when i use the SQL function. On the other hand; The result comes
> 300-400 milliseconds when i run the SQL statement. Any idea ??

Have you analyzed the tables?  If that's not the problem then could
you post the EXPLAIN ANALYZE output for the direct query and for a
prepared query?  For the prepared query do this:

PREPARE stmt (varchar, date, int4, varchar, varchar) AS SELECT ... ;

where "..." is the same SQL as in the function body, including the
numbered parameters ($1, $2, etc.).  To execute the query do this:

EXPLAIN ANALYZE EXECUTE stmt (...);

Where "..." is the same parameter list you'd pass to the function
(the same values you used in the direct query).

If you need to re-prepare the query then run "DEALLOCATE stmt"
before doing so.

--
Michael Fuhr

Re: SQL Function Performance

From
"Adnan DURSUN"
Date:

 
Date: 02/13/06 07:46:05
Subject: Re: [PERFORM] SQL Function Performance
 
On Sun, Feb 12, 2006 at 10:25:28PM +0200, Adnan DURSUN wrote:
>> My database has an SQL function. The result comes in 30-40 seconds
>> when i use the SQL function. On the other hand; The result comes
>> 300-400 milliseconds when i run the SQL statement. Any idea ??
 
>Have you analyzed the tables?  If that's not the problem then could
>you post the EXPLAIN ANALYZE output for the direct query and for a
>prepared query?  For the prepared query do this:
 
EXPLAIN ANALYZE for direct query :
 
QUERY PLAN
"HashAggregate  (cost=29.37..29.40 rows=1 width=58) (actual time=12.114..12.114 rows=0 loops=1)"
"  ->  Nested Loop  (cost=9.55..29.36 rows=1 width=58) (actual time=12.107..12.107 rows=0 loops=1)"
"        Join Filter: (((""inner"".hat_no)::text = (""outer"".hat_no)::text) AND (""inner"".sefer_kod = ""outer"".sefer_kod) AND (""inner"".plan_tarihi = ""outer"".plan_tarihi) AND (""inner"".bin_yer_kod = ""outer"".bin_yer_kod) AND (""inner"".koltuk_no = ""outer"".koltuk_no))"
"        ->  Nested Loop  (cost=9.55..26.15 rows=1 width=93) (actual time=12.102..12.102 rows=0 loops=1)"
"              ->  Nested Loop  (cost=9.55..20.60 rows=1 width=65) (actual time=8.984..12.012 rows=1 loops=1)"
"                    ->  Nested Loop  (cost=9.55..14.62 rows=1 width=48) (actual time=6.155..7.919 rows=41 loops=1)"
"                          Join Filter: (""outer"".sefer_tip_kod = ""inner"".kod)"
"                          ->  Hash Join  (cost=9.55..13.58 rows=1 width=52) (actual time=6.129..6.846 rows=41 loops=1)"
"                                Hash Cond: (""outer"".kod = ""inner"".varis_yer_kod)"
"                                ->  Seq Scan on t_yer y2  (cost=0.00..3.44 rows=115 width=14) (actual time=0.018..0.374 rows=115 loops=1)"
"                                      Filter: ((iptal)::text = 'H'::text)"
"                                ->  Hash  (cost=9.55..9.55 rows=1 width=46) (actual time=6.058..6.058 rows=41 loops=1)"
"                                      ->  Merge Join  (cost=9.45..9.55 rows=1 width=46) (actual time=4.734..5.894 rows=41 loops=1)"
"                                            Merge Cond: (""outer"".kod = ""inner"".kalkis_yer_kod)"
"                                            ->  Index Scan using t_yer_pkey on t_yer y1  (cost=0.00..9.62 rows=115 width=14) (actual time=0.021..0.183 rows=40 loops=1)"
"                                                  Filter: ((iptal)::text = 'H'::text)"
"                                            ->  Sort  (cost=9.45..9.45 rows=1 width=40) (actual time=4.699..4.768 rows=41 loops=1)"
"                                                  Sort Key: h.kalkis_yer_kod"
"                                                  ->  Nested Loop  (cost=4.51..9.44 rows=1 width=40) (actual time=0.410..4.427 rows=41 loops=1)"
"                                                        Join Filter: ((""inner"".""no"")::text = (""outer"".hat_no)::text)"
"                                                        ->  Hash Join  (cost=4.51..8.09 rows=1 width=27) (actual time=0.384..1.036 rows=41 loops=1)"
"                                                              Hash Cond: ((""outer"".durumu)::text = (""inner"".kod)::text)"
"                                                              ->  Hash Join  (cost=2.25..5.80 rows=3 width=32) (actual time=0.193..0.652 rows=41 loops=1)"
"                                                                    Hash Cond: ((""outer"".ek_dev)::text = (""inner"".kod)::text)"
"                                                                    ->  Seq Scan on t_seferler s  (cost=0.00..3.21 rows=41 width=37) (actual time=0.009..0.256 rows=41 loops=1)"
"                                                                          Filter: (((iptal)::text = 'H'::text) AND ((iptal)::text = 'H'::text) AND ((firma_no)::text = '1'::text))"
"                                                                    ->  Hash  (cost=2.25..2.25 rows=2 width=5) (actual time=0.156..0.156 rows=2 loops=1)"
"                                                                          ->  Seq Scan on t_domains d1  (cost=0.00..2.25 rows=2 width=5) (actual time=0.055..0.138 rows=2 loops=1)"
"                                                                                Filter: ((name)::text = 'EKDEV'::text)"
"                                                              ->  Hash  (cost=2.25..2.25 rows=2 width=5) (actual time=0.164..0.164 rows=2 loops=1)"
"                                                                    ->  Seq Scan on t_domains d2  (cost=0.00..2.25 rows=2 width=5) (actual time=0.057..0.142 rows=2 loops=1)"
"                                                                          Filter: ((name)::text = 'SFR_DURUMU'::text)"
"                                                        ->  Seq Scan on t_hatlar h  (cost=0.00..1.23 rows=10 width=18) (actual time=0.004..0.042 rows=10 loops=41)"
"                                                              Filter: ('1'::text = (firma_no)::text)"
"                          ->  Seq Scan on t_sefer_tip t  (cost=0.00..1.03 rows=1 width=9) (actual time=0.005..0.009 rows=1 loops=41)"
"                                Filter: (((iptal)::text = 'H'::text) AND ('1'::text = (firma_no)::text))"
"                    ->  Index Scan using t_lokal_plan_sefer_liste_idx on t_lokal_plan lp  (cost=0.00..5.97 rows=1 width=22) (actual time=0.091..0.092 rows=0 loops=41)"
"                          Index Cond: (((lp.firma_no)::text = '1'::text) AND ((""outer"".hat_no)::text = (lp.hat_no)::text) AND (""outer"".kod = lp.sefer_kod) AND (lp.kalkis_tarihi = '2006-02-13'::date))"
"                          Filter: (lokal_kod = 62)"
"              ->  Index Scan using t_koltuk_son_durum_pkey on t_koltuk_son_durum sd  (cost=0.00..5.53 rows=1 width=28) (actual time=0.079..0.079 rows=0 loops=1)"
"                    Index Cond: (('1'::text = (sd.firma_no)::text) AND ((""outer"".hat_no)::text = (sd.hat_no)::text) AND (""outer"".kod = sd.sefer_kod) AND (""outer"".plan_tarihi = sd.plan_tarihi) AND (""outer"".yer_kod = sd.bin_yer_kod))"
"                    Filter: ((islem)::text = 'S'::text)"
"        ->  Index Scan using t_koltuk_islem_kod_ukey on t_koltuk_islem i  (cost=0.00..3.18 rows=1 width=57) (never executed)"
"              Index Cond: (i.kod = ""outer"".islem_kod)"
"              Filter: ((firma_no)::text = '1'::text)"
"Total runtime: 13.984 ms"
 
Adnan DURSUN
ASRIN Bilişim Ltd.Şti
Ankara / TURKEY
 

Re: SQL Function Performance

From
"Adnan DURSUN"
Date:
 
Date: 02/13/06 07:46:05
Subject: Re: [PERFORM] SQL Function Performance
 
On Sun, Feb 12, 2006 at 10:25:28PM +0200, Adnan DURSUN wrote:
>> My database has an SQL function. The result comes in 30-40 seconds
>> when i use the SQL function. On the other hand; The result comes
>> 300-400 milliseconds when i run the SQL statement. Any idea ??
 
>Have you analyzed the tables?  If that's not the problem then could
>you post the EXPLAIN ANALYZE output for the direct query and for a
>prepared query?  For the prepared query do this:
 
>EXPLAIN ANALYZE EXECUTE stmt (...);
 
 Here is the EXPLAIN ANALYZE output for prepared statement :
 
QUERY PLAN
"HashAggregate  (cost=29.37..29.40 rows=1 width=58) (actual time=10.600..10.600 rows=0 loops=1)"
"  ->  Nested Loop  (cost=9.55..29.36 rows=1 width=58) (actual time=10.594..10.594 rows=0 loops=1)"
"        Join Filter: (((""inner"".hat_no)::text = (""outer"".hat_no)::text) AND (""inner"".sefer_kod = ""outer"".sefer_kod) AND (""inner"".plan_tarihi = ""outer"".plan_tarihi) AND (""inner"".bin_yer_kod = ""outer"".bin_yer_kod) AND (""inner"".koltuk_no = ""outer"".koltuk_no))"
"        ->  Nested Loop  (cost=9.55..26.15 rows=1 width=93) (actual time=10.588..10.588 rows=0 loops=1)"
"              ->  Nested Loop  (cost=9.55..20.60 rows=1 width=65) (actual time=7.422..10.499 rows=1 loops=1)"
"                    ->  Nested Loop  (cost=9.55..14.62 rows=1 width=48) (actual time=5.455..7.247 rows=41 loops=1)"
"                          Join Filter: (""outer"".sefer_tip_kod = ""inner"".kod)"
"                          ->  Hash Join  (cost=9.55..13.58 rows=1 width=52) (actual time=5.432..6.131 rows=41 loops=1)"
"                                Hash Cond: (""outer"".kod = ""inner"".varis_yer_kod)"
"                                ->  Seq Scan on t_yer y2  (cost=0.00..3.44 rows=115 width=14) (actual time=0.018..0.375 rows=115 loops=1)"
"                                      Filter: ((iptal)::text = 'H'::text)"
"                                ->  Hash  (cost=9.55..9.55 rows=1 width=46) (actual time=5.352..5.352 rows=41 loops=1)"
"                                      ->  Merge Join  (cost=9.45..9.55 rows=1 width=46) (actual time=4.713..5.182 rows=41 loops=1)"
"                                            Merge Cond: (""outer"".kod = ""inner"".kalkis_yer_kod)"
"                                            ->  Index Scan using t_yer_pkey on t_yer y1  (cost=0.00..9.62 rows=115 width=14) (actual time=0.021..0.176 rows=40 loops=1)"
"                                                  Filter: ((iptal)::text = 'H'::text)"
"                                            ->  Sort  (cost=9.45..9.45 rows=1 width=40) (actual time=4.678..4.747 rows=41 loops=1)"
"                                                  Sort Key: h.kalkis_yer_kod"
"                                                  ->  Nested Loop  (cost=4.51..9.44 rows=1 width=40) (actual time=0.412..4.389 rows=41 loops=1)"
"                                                        Join Filter: ((""inner"".""no"")::text = (""outer"".hat_no)::text)"
"                                                        ->  Hash Join  (cost=4.51..8.09 rows=1 width=27) (actual time=0.386..1.137 rows=41 loops=1)"
"                                                              Hash Cond: ((""outer"".durumu)::text = (""inner"".kod)::text)"
"                                                              ->  Hash Join  (cost=2.25..5.80 rows=3 width=32) (actual time=0.193..0.751 rows=41 loops=1)"
"                                                                    Hash Cond: ((""outer"".ek_dev)::text = (""inner"".kod)::text)"
"                                                                    ->  Seq Scan on t_seferler s  (cost=0.00..3.21 rows=41 width=37) (actual time=0.009..0.258 rows=41 loops=1)"
"                                                                          Filter: (((iptal)::text = 'H'::text) AND ((iptal)::text = 'H'::text) AND ((firma_no)::text = '1'::text))"
"                                                                    ->  Hash  (cost=2.25..2.25 rows=2 width=5) (actual time=0.141..0.141 rows=2 loops=1)"
"                                                                          ->  Seq Scan on t_domains d1  (cost=0.00..2.25 rows=2 width=5) (actual time=0.048..0.131 rows=2 loops=1)"
"                                                                                Filter: ((name)::text = 'EKDEV'::text)"
"                                                              ->  Hash  (cost=2.25..2.25 rows=2 width=5) (actual time=0.160..0.160 rows=2 loops=1)"
"                                                                    ->  Seq Scan on t_domains d2  (cost=0.00..2.25 rows=2 width=5) (actual time=0.056..0.139 rows=2 loops=1)"
"                                                                          Filter: ((name)::text = 'SFR_DURUMU'::text)"
"                                                        ->  Seq Scan on t_hatlar h  (cost=0.00..1.23 rows=10 width=18) (actual time=0.004..0.045 rows=10 loops=41)"
"                                                              Filter: ('1'::text = (firma_no)::text)"
"                          ->  Seq Scan on t_sefer_tip t  (cost=0.00..1.03 rows=1 width=9) (actual time=0.004..0.009 rows=1 loops=41)"
"                                Filter: (((iptal)::text = 'H'::text) AND ('1'::text = (firma_no)::text))"
"                    ->  Index Scan using t_lokal_plan_sefer_liste_idx on t_lokal_plan lp  (cost=0.00..5.97 rows=1 width=22) (actual time=0.071..0.072 rows=0 loops=41)"
"                          Index Cond: (((lp.firma_no)::text = '1'::text) AND ((""outer"".hat_no)::text = (lp.hat_no)::text) AND (""outer"".kod = lp.sefer_kod) AND (lp.kalkis_tarihi = '2006-02-13'::date))"
"                          Filter: (lokal_kod = 62)"
"              ->  Index Scan using t_koltuk_son_durum_pkey on t_koltuk_son_durum sd  (cost=0.00..5.53 rows=1 width=28) (actual time=0.078..0.078 rows=0 loops=1)"
"                    Index Cond: (('1'::text = (sd.firma_no)::text) AND ((""outer"".hat_no)::text = (sd.hat_no)::text) AND (""outer"".kod = sd.sefer_kod) AND (""outer"".plan_tarihi = sd.plan_tarihi) AND (""outer"".yer_kod = sd.bin_yer_kod))"
"                    Filter: ((islem)::text = 'S'::text)"
"        ->  Index Scan using t_koltuk_islem_kod_ukey on t_koltuk_islem i  (cost=0.00..3.18 rows=1 width=57) (never executed)"
"              Index Cond: (i.kod = ""outer"".islem_kod)"
"              Filter: ((firma_no)::text = '1'::text)"
"Total runtime: 11.856 ms"
 
Adnan DURSUN
ASRIN Bilişim Ltd.Şti
Ankara / TURKEY
 

Re: SQL Function Performance

From
"Adnan DURSUN"
Date:
>Date: 02/13/06 22:09:48
>Subject: RE: [PERFORM] SQL Function Performance
 

>I've run into this issue. It basically comes down to the plan that is being used inside the function is not the same as the plan used when you issue the query manually >outside of the function.  Although I'm no expert on when plans are prepared and re-evaluated for functions, I know that they are not re-evaluated each time to execute the >function.

 in my case; both direct query and sql function gererate same execution plan. Also, execution plan belongs to the sql function better than direct sql query plan. But, direct sql result comes less than 1 second. sql function result comes about in 50 seconds.

Adnan DURSUN
ASRIN Bilişim Ltd.Şti

Re: SQL Function Performance

From
"Adnan DURSUN"
Date:
-------Original Message-------
 
Date: 02/14/06 01:46:16
Subject: RE: [PERFORM] SQL Function Performance
 

>> in my case; both direct query and sql function gererate same execution plan. Also, execution plan belongs to the sql function better than direct sql
>> query plan. But, direct sql result comes less than 1 second. sql function result comes about in 50 seconds.

>How are you getting at the plan inside your function?  If you just do an EXPLAIN on the function call you get a FUNCTION SCAN line in your plan, which tells you >nothing.  I remember I had to work through some process for catching the output of the Explain plan in a cursor and returning that to actually see the plan.  I saw in a >previous response he suggested using a PREPARE and EXECUTE against that.  I'm not sure that's the same as what's going on in the function (although I could be >wrong).

   Yes, i have got sql function prepared execution plan using PREPARE and EXECUTE that he suggested to me.


>Just humor me and try creating the sql query in the fuction in a text variable and then Executing it. 

   But i believe that, that behavior of PostgreSQL is not good. It should handle this case. PostgreSQL has this "sql function" functionality and it should
   give good serve...Of course, i will do your suggesion if i dont solve it.

>Prior to that, however, you might try just recreating the function.  The plan may be re-evaluated at that point.
    Ok. i did it many times. But nothing was changed..
- Mark

 
Adnan DURSUN
ASRIN Bilişim Ltd.Şti


 

Re: SQL Function Performance

From
Tom Lane
Date:
"Adnan DURSUN" <a_dursun@hotmail.com> writes:
>>>> EXPLAIN ANALYZE EXECUTE stmt (...);

>    Here is the EXPLAIN ANALYZE output for prepared statement :

This is exactly the same as the other plan --- you did not parameterize
the query.  To see what's going on, you need to insert PREPARE
parameters in the places where the function uses plpgsql variables.

            regards, tom lane

Re: SQL Function Performance

From
Michael Fuhr
Date:
On Mon, Feb 13, 2006 at 07:57:07PM -0500, Tom Lane wrote:
> "Adnan DURSUN" <a_dursun@hotmail.com> writes:
> >>>> EXPLAIN ANALYZE EXECUTE stmt (...);
>
> >    Here is the EXPLAIN ANALYZE output for prepared statement :
>
> This is exactly the same as the other plan --- you did not parameterize
> the query.  To see what's going on, you need to insert PREPARE
> parameters in the places where the function uses plpgsql variables.

Actually it was an SQL function, but that also does PREPARE/EXECUTE,
right?

Adnan, what Tom is saying is that I requested this (simplified):

PREPARE stmt (integer) AS SELECT * FROM foo WHERE id = $1;
EXPLAIN ANALYZE EXECUTE stmt (12345);

but instead you appear to have done this:

PREPARE stmt AS SELECT * FROM foo WHERE id = 12345;
EXPLAIN ANALYZE EXECUTE stmt;

We can tell because if you had done it the first way (parameterized)
then the EXPLAIN ANALYZE output would have shown the parameters as
$1, $2, $3, etc., which it didn't.

--
Michael Fuhr

Re: SQL Function Performance

From
"Adnan DURSUN"
Date:
 
Date: 02/14/06 03:32:28
Subject: Re: [PERFORM] SQL Function Performance
 
On Mon, Feb 13, 2006 at 07:57:07PM -0500, Tom Lane wrote:
>> "Adnan DURSUN" <a_dursun@hotmail.com> writes:
>> >>>> EXPLAIN ANALYZE EXECUTE stmt (...);
>>
>> >    Here is the EXPLAIN ANALYZE output for prepared statement :
>>
>> This is exactly the same as the other plan --- you did not parameterize
>> the query.  To see what's going on, you need to insert PREPARE
>> parameters in the places where the function uses plpgsql variables.
 
>Actually it was an SQL function, but that also does PREPARE/EXECUTE,
>right?
 
>Adnan, what Tom is saying is that I requested this (simplified):
 
>PREPARE stmt (integer) AS SELECT * FROM foo WHERE id = $1;
>EXPLAIN ANALYZE EXECUTE stmt (12345);
 
Ok. I am sending right execution plan.  I made mistake apologize me..
 
   QUERY PLAN
"HashAggregate  (cost=276.73..276.76 rows=1 width=58) (actual time=192648.385..192648.385 rows=0 loops=1)"
"  ->  Nested Loop  (cost=5.90..276.71 rows=1 width=58) (actual time=192648.377..192648.377 rows=0 loops=1)"
"        Join Filter: (((""inner"".hat_no)::text = (""outer"".hat_no)::text) AND (""inner"".sefer_kod = ""outer"".sefer_kod) AND (""inner"".plan_tarihi = ""outer"".plan_tarihi) AND (""inner"".bin_yer_kod = ""outer"".bin_yer_kod) AND (""inner"".koltuk_no = ""outer"".koltuk_no) AND (((""inner"".islem_tarihi = $2) AND (($5)::text = 'I'::text)) OR ((""outer"".kalkis_tarihi = $2) AND (($5)::text = 'K'::text))) AND (((""outer"".lokal_kod = $3) AND (($4)::text = 'K'::text)) OR ((""inner"".ypt_lcl_kod = $3) AND (($4)::text = 'I'::text))))"
"        ->  Nested Loop  (cost=5.90..267.19 rows=3 width=101) (actual time=76.240..30974.777 rows=63193 loops=1)"
"              ->  Nested Loop  (cost=5.90..123.48 rows=26 width=73) (actual time=32.082..4357.786 rows=14296 loops=1)"
"                    ->  Nested Loop  (cost=3.62..15.29 rows=1 width=48) (actual time=1.279..46.882 rows=41 loops=1)"
"                          Join Filter: ((""inner"".kod)::text = (""outer"".durumu)::text)"
"                          ->  Nested Loop  (cost=3.62..13.01 rows=1 width=53) (actual time=1.209..40.010 rows=41 loops=1)"
"                                ->  Nested Loop  (cost=3.62..8.49 rows=1 width=47) (actual time=1.150..38.928 rows=41 loops=1)"
"                                      Join Filter: ((""inner"".""no"")::text = (""outer"".hat_no)::text)"
"                                      ->  Nested Loop  (cost=2.25..6.79 rows=1 width=28) (actual time=0.710..24.708 rows=41 loops=1)"
"                                            Join Filter: (""inner"".sefer_tip_kod = ""outer"".kod)"
"                                            ->  Seq Scan on t_sefer_tip t  (cost=0.00..1.03 rows=1 width=9) (actual time=0.117..0.126 rows=1 loops=1)"
"                                                  Filter: (((iptal)::text = 'H'::text) AND (($1)::text = (firma_no)::text))"
"                                            ->  Hash Join  (cost=2.25..5.74 rows=2 width=32) (actual time=0.567..24.349 rows=41 loops=1)"
"                                                  Hash Cond: ((""outer"".ek_dev)::text = (""inner"".kod)::text)"
"                                                  ->  Seq Scan on t_seferler s  (cost=0.00..3.21 rows=34 width=37) (actual time=0.077..23.466 rows=41 loops=1)"
"                                                        Filter: (((iptal)::text = 'H'::text) AND ((iptal)::text = 'H'::text) AND ((firma_no)::text = ($1)::text))"
"                                                  ->  Hash  (cost=2.25..2.25 rows=2 width=5) (actual time=0.451..0.451 rows=2 loops=1)"
"                                                        ->  Seq Scan on t_domains d1  (cost=0.00..2.25 rows=2 width=5) (actual time=0.346..0.429 rows=2 loops=1)"
"                                                              Filter: ((name)::text = 'EKDEV'::text)"
"                                      ->  Merge Join  (cost=1.37..1.59 rows=9 width=24) (actual time=0.032..0.313 rows=10 loops=41)"
"                                            Merge Cond: (""outer"".kod = ""inner"".kalkis_yer_kod)"
"                                            ->  Index Scan using t_yer_pkey on t_yer y1  (cost=0.00..9.62 rows=115 width=14) (actual time=0.013..0.164 rows=40 loops=41)"
"                                                  Filter: ((iptal)::text = 'H'::text)"
"                                            ->  Sort  (cost=1.37..1.39 rows=9 width=18) (actual time=0.007..0.025 rows=10 loops=41)"
"                                                  Sort Key: h.kalkis_yer_kod"
"                                                  ->  Seq Scan on t_hatlar h  (cost=0.00..1.23 rows=9 width=18) (actual time=0.078..0.125 rows=10 loops=1)"
"                                                        Filter: (($1)::text = (firma_no)::text)"
"                                ->  Index Scan using t_yer_pkey on t_yer y2  (cost=0.00..4.51 rows=1 width=14) (actual time=0.011..0.015 rows=1 loops=41)"
"                                      Index Cond: (""outer"".varis_yer_kod = y2.kod)"
"                                      Filter: ((iptal)::text = 'H'::text)"
"                          ->  Seq Scan on t_domains d2  (cost=0.00..2.25 rows=2 width=5) (actual time=0.054..0.140 rows=2 loops=41)"
"                                Filter: ((name)::text = 'SFR_DURUMU'::text)"
"                    ->  Bitmap Heap Scan on t_lokal_plan lp  (cost=2.28..107.70 rows=33 width=30) (actual time=9.709..103.130 rows=349 loops=41)"
"                          Recheck Cond: (((lp.firma_no)::text = ($1)::text) AND ((""outer"".hat_no)::text = (lp.hat_no)::text) AND (""outer"".kod = lp.sefer_kod))"
"                          ->  Bitmap Index Scan on t_lokal_plan_pkey  (cost=0.00..2.28 rows=33 width=0) (actual time=8.340..8.340 rows=349 loops=41)"
"                                Index Cond: (((lp.firma_no)::text = ($1)::text) AND ((""outer"".hat_no)::text = (lp.hat_no)::text) AND (""outer"".kod = lp.sefer_kod))"
"              ->  Index Scan using t_koltuk_son_durum_pkey on t_koltuk_son_durum sd  (cost=0.00..5.51 rows=1 width=28) (actual time=0.467..1.829 rows=4 loops=14296)"
"                    Index Cond: ((($1)::text = (sd.firma_no)::text) AND ((""outer"".hat_no)::text = (sd.hat_no)::text) AND (""outer"".kod = sd.sefer_kod) AND (""outer"".plan_tarihi = sd.plan_tarihi) AND (""outer"".yer_kod = sd.bin_yer_kod))"
"                    Filter: ((islem)::text = 'S'::text)"
"        ->  Index Scan using t_koltuk_islem_kod_ukey on t_koltuk_islem i  (cost=0.00..3.13 rows=1 width=65) (actual time=2.534..2.538 rows=1 loops=63193)"
"              Index Cond: (i.kod = ""outer"".islem_kod)"
"              Filter: ((firma_no)::text = ($1)::text)"
"Total runtime: 192649.904 ms"
Adnan DURSUN
ASRIN Bilişim Ltd.Şti
 

Re: SQL Function Performance

From
Michael Fuhr
Date:
On Tue, Feb 14, 2006 at 11:33:57AM +0200, Adnan DURSUN wrote:
>         ->  Nested Loop  (cost=5.90..267.19 rows=3 width=101) (actual time=76.240..30974.777 rows=63193 loops=1)
>               ->  Nested Loop  (cost=5.90..123.48 rows=26 width=73) (actual time=32.082..4357.786 rows=14296 loops=1)

A prepared query is planned before the parameters' values are known,
so the planner can't take full advantage of column statistics to
estimate row counts.  The planner must therefore decide on a plan
that should be reasonable in most cases; apparently this isn't one
of those cases, as the disparity between estimated and actual rows
shows.  Maybe Tom (one of the core developers) can comment on whether
anything can be done to improve the plan in this case.

Absent a better solution, you could write a PL/pgSQL function and
build the query as a text string, then EXECUTE it.  That would give
you a new plan each time, one that can take better advantage of
statistics, at the cost of having to plan the query each time you
call the function (but you probably don't care about that cost
as long as the overall results are better).  Here's an example:

CREATE FUNCTION fooquery(qval text) RETURNS SETOF foo AS $$
DECLARE
    row    foo%ROWTYPE;
    query  text;
BEGIN
    query := 'SELECT * FROM foo WHERE val = ' || quote_literal(qval);

    FOR row IN EXECUTE query LOOP
        RETURN NEXT row;
    END LOOP;

    RETURN;
END;
$$ LANGUAGE plpgsql STABLE STRICT;

--
Michael Fuhr

Re: SQL Function Performance

From
"Adnan DURSUN"
Date:
 
 
-------Original Message-------
 
Date: 02/14/06 23:05:55
Subject: Re: [PERFORM] SQL Function Performance
 
>On Tue, Feb 14, 2006 at 11:33:57AM +0200, Adnan DURSUN wrote:
>>         ->  Nested Loop  (cost=5.90..267.19 rows=3 width=101) (actual time=76.240..30974.777 rows=63193 loops=1)
>>               ->  Nested Loop  (cost=5.90..123.48 rows=26 width=73) (actual time=32.082..4357.786 rows=14296 loops=1)
 
>Absent a better solution, you could write a PL/pgSQL function and
>build the query as a text string, then EXECUTE it.  That would give
>you a new plan each time, one that can take better advantage of
>statistics, at the cost of having to plan the query each time you
>call the function (but you probably don't care about that cost
>as long as the overall results are better).  Here's an example:
 
    Yes, i did it. i wrote a PL/pgSQL function. Now results come at 100 ms.. :-)
I dont like that method but i have to do it for perfomance....
 
Many thanks to everyone who helps...
 
Adnan DURSUN
ASRIN Bilisim Ltd.
Ankara /TURKEY
---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster

Re: SQL Function Performance

From
"Mark Liberman"
Date:

I've run into this issue. It basically comes down to the plan that is being used inside the function is not the same as the plan used when you issue the query manually outside of the function.  Although I'm no expert on when plans are prepared and re-evaluated for functions, I know that they are not re-evaluated each time to execute the function.

So, what I did in such cases was to build up the sql query in a text variable inside my function, and then use the EXECUTE command inside the function.  When you use the EXECUTE command, the plan is prepared each time.  I know there is some minimal overhead of preparing the plan each time, but it seems like it's minor compared to the saving's you'll get.

- Mark

Re: SQL Function Performance

From
"Mark Liberman"
Date:

> in my case; both direct query and sql function gererate same execution plan. Also, execution plan belongs to the sql function better than direct sql > query plan. But, direct sql result comes less than 1 second. sql function result comes about in 50 seconds.

How are you getting at the plan inside your function?  If you just do an EXPLAIN on the function call you get a FUNCTION SCAN line in your plan, which tells you nothing.  I remember I had to work through some process for catching the output of the Explain plan in a cursor and returning that to actually see the plan.  I saw in a previous response he suggested using a PREPARE and EXECUTE against that.  I'm not sure that's the same as what's going on in the function (although I could be wrong).

Just humor me and try creating the sql query in the fuction in a text variable and then Executing it. 

Prior to that, however, you might try just recreating the function.  The plan may be re-evaluated at that point.

- Mark