Re: SQL Function Performance

From: Michael Fuhr
Date: 02/14/06 03:32:28
To: Tom Lane
Cc: Adnan DURSUN; pgsql-performance(at)postgresql(dot)org
Subject: Re: [PERFORM] SQL Function Performance

On Mon, Feb 13, 2006 at 07:57:07PM -0500, Tom Lane wrote:
>> "Adnan DURSUN" <a_dursun(at)hotmail(dot)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