Re: SQL Function Performance

From: Michael Fuhr
Date: 02/13/06 07:46:05
To: Adnan DURSUN
Cc: pgsql-performance(at)postgresql(dot)org
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