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 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