Received: from localhost (unknown [200.46.204.183]) by mail.postgresql.org (Postfix) with ESMTP id 2191564FDBB for ; Thu, 13 Nov 2008 09:29:21 -0400 (AST) Received: from mail.postgresql.org ([200.46.204.86]) by localhost (mx1.hub.org [200.46.204.183]) (amavisd-maia, port 10024) with ESMTP id 06176-06 for ; Thu, 13 Nov 2008 09:29:17 -0400 (AST) X-Greylist: from auto-whitelisted by SQLgrey-1.7.6 Received: from vilnius.balt.net (vilnius.balt.net [195.14.170.14]) by mail.postgresql.org (Postfix) with ESMTP id 23A1B64FD64 for ; Thu, 13 Nov 2008 09:29:16 -0400 (AST) Received: from nSoft.lt (unknown [217.117.29.29]) by vilnius.balt.net (Postfix) with ESMTP id 874843BC192 for ; Thu, 13 Nov 2008 15:29:13 +0200 (EET) Received: from [192.168.16.113] (unknown [192.168.16.113]) by nSoft.lt (Postfix) with ESMTP id A0393BF03F for ; Thu, 13 Nov 2008 16:27:20 +0000 (GMT) Message-ID: <491C2BA5.7080401@nsoft.lt> Date: Thu, 13 Nov 2008 15:29:09 +0200 From: Julius Tuskenis User-Agent: Thunderbird 2.0.0.17 (Windows/20080914) MIME-Version: 1.0 CC: pgsql-admin@postgresql.org Subject: Re: function executes sql 100 times longer it should References: <491AE3F2.601@nsoft.lt> <1226500247.2221.2.camel@lin-it1.eaglepress.local> <491BE279.50702@nsoft.lt> <9b1af80e0811130345o37666c5dob841d93954826357@mail.gmail.com> In-Reply-To: <9b1af80e0811130345o37666c5dob841d93954826357@mail.gmail.com> Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=1.581 tagged_above=0 required=5 tests=MISSING_HEADERS=1.581 X-Spam-Level: * X-Archive-Number: 200811/70 X-Sequence-Number: 30724 Thank you Vyacheslav. your "bit or street magic" worked and now I have Execution Plans for both queries: from function and simple SQL. I'm not good in reading and interpreting these please advice witch part should I put my attention to? FUNCTION: "Unique (cost=290.13..290.15 rows=1 width=132) (actual time=1834.211..1834.222 rows=2 loops=1)" " -> Sort (cost=290.13..290.14 rows=1 width=132) (actual time=1834.207..1834.209 rows=2 loops=1)" " Sort Key: filter_b_preke_matoma.prek_pavadinimas, filter_b_preke_matoma.prek_id, b_kainorascio_sudetis.ks_kaina, b_mato_vienetai.mvnt_trumpinys" " Sort Method: quicksort Memory: 17kB" " -> Nested Loop Left Join (cost=1.03..290.12 rows=1 width=132) (actual time=374.851..1834.169 rows=2 loops=1)" " Join Filter: (b_grupes_prekes.gp_grupe = b_grupe.grup_id)" " Filter: ((b_grupe.grup_id = $1) OR ($1 IS NULL))" " -> Nested Loop Left Join (cost=1.03..288.07 rows=1 width=136) (actual time=45.915..1795.235 rows=694 loops=1)" " -> Nested Loop (cost=1.03..281.39 rows=1 width=132) (actual time=45.902..1789.018 rows=694 loops=1)" " -> Nested Loop (cost=1.03..281.11 rows=1 width=140) (actual time=8.021..1734.222 rows=6367 loops=1)" " -> Nested Loop (cost=1.03..280.58 rows=1 width=136) (actual time=6.618..79.367 rows=6000 loops=1)" " -> Nested Loop (cost=1.03..268.87 rows=1 width=125) (actual time=6.595..34.114 rows=2820 loops=1)" " Join Filter: (filter_b_preke_matoma.prek_matovnt = b_mato_vienetai.mvnt_id)" " -> Function Scan on filter_b_preke_matoma (cost=0.00..267.50 rows=5 width=126) (actual time=6.580..11.766 rows=2820 loops=1)" " Filter: (((prek_pavadinimas)::text ~~* (('%'::text || ($3)::text) || '%'::text)) OR ($3 IS NULL))" " -> Materialize (cost=1.03..1.06 rows=3 width=7) (actual time=0.001..0.002 rows=3 loops=2820)" " -> Seq Scan on b_mato_vienetai (cost=0.00..1.03 rows=3 width=7) (actual time=0.005..0.009 rows=3 loops=1)" " -> Index Scan using idx_ks_preke on b_kainorascio_sudetis (cost=0.00..11.67 rows=3 width=15) (actual time=0.007..0.010 rows=2 loops=2820)" " Index Cond: (b_kainorascio_sudetis.ks_preke = filter_b_preke_matoma.prek_id)" " -> Index Scan using idx_kag_kainorastis on b_kainorascio_grafikas (cost=0.00..0.52 rows=1 width=4) (actual time=0.199..0.272 rows=1 loops=6000)" " Index Cond: (b_kainorascio_grafikas.kag_kainorastis = b_kainorascio_sudetis.ks_kainorastis)" " Filter: fnk_grafikas_galioja(b_kainorascio_grafikas.kag_grafikas)" " -> Index Scan using unq_kainorastis_pardavimo_taskui on b_pardavimo_tasko_kainorastis (cost=0.00..0.28 rows=1 width=4) (actual time=0.005..0.006 rows=0 loops=6367)" " Index Cond: ((b_pardavimo_tasko_kainorastis.ptk_pardavimotaskas = $2) AND (b_pardavimo_tasko_kainorastis.ptk_kainorastis = b_kainorascio_sudetis.ks_kainorastis))" " -> Index Scan using idx_gp_preke on b_grupes_prekes (cost=0.00..6.67 rows=1 width=8) (actual time=0.006..0.006 rows=0 loops=694)" " Index Cond: (b_grupes_prekes.gp_preke = filter_b_preke_matoma.prek_id)" " -> Seq Scan on b_grupe (cost=0.00..1.42 rows=42 width=4) (actual time=0.004..0.023 rows=42 loops=694)" "Total runtime: 1834.686 ms" SIMPLE SQL: "Unique (cost=281.91..281.93 rows=1 width=132) (actual time=34.438..34.447 rows=2 loops=1)" " -> Sort (cost=281.91..281.92 rows=1 width=132) (actual time=34.435..34.436 rows=2 loops=1)" " Sort Key: filter_b_preke_matoma.prek_pavadinimas, filter_b_preke_matoma.prek_id, b_kainorascio_sudetis.ks_kaina, b_mato_vienetai.mvnt_trumpinys" " Sort Method: quicksort Memory: 17kB" " -> Nested Loop (cost=1.07..281.90 rows=1 width=132) (actual time=15.226..34.396 rows=2 loops=1)" " -> Nested Loop (cost=1.07..280.37 rows=1 width=136) (actual time=15.197..34.331 rows=2 loops=1)" " -> Nested Loop (cost=1.07..280.08 rows=1 width=144) (actual time=13.976..34.233 rows=7 loops=1)" " -> Nested Loop (cost=1.07..279.55 rows=1 width=140) (actual time=12.178..29.760 rows=7 loops=1)" " -> Nested Loop (cost=1.07..269.69 rows=1 width=133) (actual time=12.165..29.700 rows=2 loops=1)" " -> Hash Join (cost=1.07..264.97 rows=15 width=125) (actual time=6.452..13.617 rows=2820 loops=1)" " Hash Cond: (filter_b_preke_matoma.prek_matovnt = b_mato_vienetai.mvnt_id)" " -> Function Scan on filter_b_preke_matoma (cost=0.00..260.00 rows=1000 width=126) (actual time=6.418..7.828 rows=2820 loops=1)" " -> Hash (cost=1.03..1.03 rows=3 width=7) (actual time=0.013..0.013 rows=3 loops=1)" " -> Seq Scan on b_mato_vienetai (cost=0.00..1.03 rows=3 width=7) (actual time=0.005..0.007 rows=3 loops=1)" " -> Index Scan using idx_gp_preke on b_grupes_prekes (cost=0.00..0.30 rows=1 width=8) (actual time=0.004..0.004 rows=0 loops=2820)" " Index Cond: (b_grupes_prekes.gp_preke = filter_b_preke_matoma.prek_id)" " Filter: (b_grupes_prekes.gp_grupe = 43)" " -> Index Scan using idx_ks_preke on b_kainorascio_sudetis (cost=0.00..9.82 rows=3 width=15) (actual time=0.009..0.019 rows=4 loops=2)" " Index Cond: (b_kainorascio_sudetis.ks_preke = filter_b_preke_matoma.prek_id)" " -> Index Scan using idx_kag_kainorastis on b_kainorascio_grafikas (cost=0.00..0.52 rows=1 width=4) (actual time=0.536..0.634 rows=1 loops=7)" " Index Cond: (b_kainorascio_grafikas.kag_kainorastis = b_kainorascio_sudetis.ks_kainorastis)" " Filter: fnk_grafikas_galioja(b_kainorascio_grafikas.kag_grafikas)" " -> Index Scan using unq_kainorastis_pardavimo_taskui on b_pardavimo_tasko_kainorastis (cost=0.00..0.28 rows=1 width=4) (actual time=0.009..0.009 rows=0 loops=7)" " Index Cond: ((b_pardavimo_tasko_kainorastis.ptk_pardavimotaskas = 18) AND (b_pardavimo_tasko_kainorastis.ptk_kainorastis = b_kainorascio_sudetis.ks_kainorastis))" " -> Seq Scan on b_grupe (cost=0.00..1.52 rows=1 width=4) (actual time=0.012..0.020 rows=1 loops=2)" " Filter: (b_grupe.grup_id = 43)" "Total runtime: 34.804 ms" Vyacheslav Kalinin rašė: > Most likely, you get different plans because the function has to deal with the parametrized query, hence planner cannot effectively use statistics. For example conditions like this > WHERE (grup_id=$2 OR $2 is Null) > would prevent planner from use of index (if there is one), while with literal query they would be simplified to just > WHERE grup_id=42. > > On Thu, Nov 13, 2008 at 11:16 AM, Julius Tuskenis > wrote: > > Its a good start, but leads to nothing because Explain doesn't go into the function. > > It does, after a bit of street magic: > CREATE OR REPLACE FUNCTION fnk_grupes_prekes(prm_ > pardavimo_taskas integer, prm_grupe integer, prm_filtras character varying) > RETURNS refcursor AS > $BODY$ > declare > cur refcursor; > begin > open cur for > explain analyze > SELECT DISTINCT prek_id, prek_pavadinimas, ks_kaina, mvnt_trumpinys > FROM filter_b_preke_matoma() > LEFT OUTER JOIN b_grupes_prekes ON (gp_preke=prek_id) > LEFT OUTER JOIN b_grupe ON (gp_grupe=grup_id) > JOIN b_mato_vienetai ON (mvnt_id=prek_matovnt) > JOIN b_kainorascio_sudetis ON (ks_preke = prek_id) > JOIN b_kainorascio_grafikas ON (ks_kainorastis=kag_kainorastis) > JOIN b_pardavimo_tasko_kainorastis ON (ks_kainorastis=ptk_kainorastis) > WHERE (grup_id=$2 OR $2 is Null) > AND ptk_pardavimotaskas=$1 > AND ((prek_pavadinimas ILIKE ('%'||$3||'%')) OR $3 is NULL) > AND fnk_grafikas_galioja(kag_grafikas) = true > ORDER BY prek_pavadinimas; > return cur; > end; > $BODY$ > LANGUAGE 'plpgsql' VOLATILE; > begin; > select fnk_grupes_prekes(...); > fetch all in cur; > (I didnt test the above commands, but that's what I do to debug in-function plans) > > > -- Julius Tuskenis Programavimo skyriaus vadovas UAB nSoft mob. +37068233050