Received: from maia.hub.org (maia-2.hub.org [200.46.204.251]) by mail.postgresql.org (Postfix) with ESMTP id 7C960632C1C for ; Sun, 20 Jun 2010 08:59:32 -0300 (ADT) Received: from mail.postgresql.org ([200.46.204.86]) by maia.hub.org (mx1.hub.org [200.46.204.251]) (amavisd-maia, port 10024) with ESMTP id 32203-09 for ; Sun, 20 Jun 2010 11:59:23 +0000 (UTC) Received: from news.hub.org (news.hub.org [200.46.204.72]) by mail.postgresql.org (Postfix) with ESMTP id DF80B6323AE for ; Sun, 20 Jun 2010 08:59:24 -0300 (ADT) Received: from news.hub.org (news.hub.org [200.46.204.72]) by news.hub.org (8.14.4/8.14.4) with ESMTP id o5KBxJuk090614 for ; Sun, 20 Jun 2010 08:59:19 -0300 (ADT) (envelope-from news@news.hub.org) Received: (from news@localhost) by news.hub.org (8.14.4/8.14.4/Submit) id o5KBsd0k079445 for pgsql-performance@postgresql.org; Sun, 20 Jun 2010 08:54:39 -0300 (ADT) (envelope-from news) From: "Davor J." X-Newsgroups: pgsql.performance Subject: Re: Slow function in queries SELECT clause. Date: Sun, 20 Jun 2010 13:53:52 +0200 Organization: Hub.Org Networking Services Lines: 492 Message-ID: References: Mime-Version: 1.0 Content-Type: multipart/alternative; boundary="----=_NextPart_000_0107_01CB1080.067DB0F0" X-Complaints-To: usenet@news.hub.org X-Priority: 3 X-MSMail-Priority: Normal X-Newsreader: Microsoft Outlook Express 6.00.2900.5931 X-MimeOLE: Produced By Microsoft MimeOLE V6.00.2900.5931 To: pgsql-performance@postgresql.org X-Virus-Scanned: Maia Mailguard 1.0.1 X-Spam-Status: No, hits=0.791 tagged_above=-10 required=5 tests=BAYES_50=0.8, HTML_MESSAGE=0.001, T_RP_MATCHES_RCVD=-0.01 X-Spam-Level: X-Archive-Number: 201006/352 X-Sequence-Number: 39208 This is a multi-part message in MIME format. ------=_NextPart_000_0107_01CB1080.067DB0F0 Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: quoted-printable I didn't consider them to be important as they showed the same, only the = execution time was different. Also, they are a bit more complex than the = ones put in the previous post. But here they are: Definitions: ----------------------------------------------------------- CREATE OR REPLACE FUNCTION = appfunctions.fnc_unit_conversion_factor(_tree_id integer, _unit_to_id = integer) RETURNS real AS $BODY$=20 DECLARE BEGIN=20 RETURN (SELECT unit_conv_factor AS factor FROM vew_unit_conversions AS c INNER JOIN tbl_sensors AS s ON (s.unit_id =3D c.unit_id_from) INNER JOIN tbl_trees USING (sens_id) WHERE tree_id =3D _tree_id AND unit_id_to =3D _unit_to_id)::real; END;=20 $BODY$ LANGUAGE 'plpgsql' IMMUTABLE -------------------------- CREATE OR REPLACE FUNCTION = appfunctions.fnc_unit_conversion_offset(_tree_id integer, _unit_to_id = integer) RETURNS real AS $BODY$=20 DECLARE BEGIN=20 RETURN (SELECT unit_conv_offset AS offset FROM vew_unit_conversions AS c INNER JOIN tbl_sensors AS s ON (s.unit_id =3D c.unit_id_from) INNER JOIN tbl_trees USING (sens_id) WHERE tree_id =3D _tree_id AND unit_id_to =3D _unit_to_id)::real; END;=20 $BODY$ LANGUAGE 'plpgsql' IMMUTABLE -------------------------- CREATE OR REPLACE FUNCTION appfunctions.fnc_unit_convert(_rawdata real, = _tree_id integer, _unit_to_id integer) RETURNS real AS $BODY$=20 DECLARE=20 BEGIN=20 RETURN _rawdata * fnc_unit_conversion_factor(_tree_id, _unit_to_id)=20 + fnc_unit_conversion_offset(_tree_id, _unit_to_id); END;=20 $BODY$ LANGUAGE 'plpgsql' IMMUTABLE Executions: ----------------------------------------------------------- EXPLAIN ANALYSE SELECT timestamp, data_from_tree_id_70 AS "flow_11"=20 FROM=20 (SELECT sens_chan_data_timestamp AS timestamp, sens_chan_data_data AS = data_from_tree_id_70 FROM tbl_sensor_channel_data WHERE tree_id =3D 70 = AND sens_chan_data_timestamp >=3D '2008-06-11T00:00:00' AND = sens_chan_data_timestamp <=3D '2008-06-18T00:00:00' ) AS "70"=20 ORDER BY timestamp; "Sort (cost=3D175531.00..175794.64 rows=3D105456 width=3D12) (actual = time=3D598.454..638.400 rows=3D150678 loops=3D1)" " Sort Key: tbl_sensor_channel_data.sens_chan_data_timestamp" " Sort Method: external sort Disk: 3240kB" " -> Bitmap Heap Scan on tbl_sensor_channel_data = (cost=3D3005.29..166732.66 rows=3D105456 width=3D12) (actual = time=3D34.810..371.099 rows=3D150678 loops=3D1)" " Recheck Cond: ((tree_id =3D 70) AND (sens_chan_data_timestamp = >=3D '2008-06-11 00:00:00'::timestamp without time zone) AND = (sens_chan_data_timestamp <=3D '2008-06-18 00:00:00'::timestamp without = time zone))" " -> Bitmap Index Scan on tbl_sensor_channel_data_pkey = (cost=3D0.00..2978.92 rows=3D105456 width=3D0) (actual = time=3D28.008..28.008 rows=3D150678 loops=3D1)" " Index Cond: ((tree_id =3D 70) AND = (sens_chan_data_timestamp >=3D '2008-06-11 00:00:00'::timestamp without = time zone) AND (sens_chan_data_timestamp <=3D '2008-06-18 = 00:00:00'::timestamp without time zone))" "Total runtime: 663.478 ms" ----------------------------------------------------------- EXPLAIN ANALYSE SELECT timestamp, fnc_unit_convert(data_from_tree_id_70, 70, 7) AS "flow_11"=20 FROM=20 (SELECT sens_chan_data_timestamp AS timestamp, sens_chan_data_data AS = data_from_tree_id_70 FROM tbl_sensor_channel_data WHERE tree_id =3D 70 = AND sens_chan_data_timestamp >=3D '2008-06-11T00:00:00' AND = sens_chan_data_timestamp <=3D '2008-06-18T00:00:00' ) AS "70"=20 ORDER BY timestamp; "Sort (cost=3D201895.00..202158.64 rows=3D105456 width=3D12) (actual = time=3D35334.017..35372.977 rows=3D150678 loops=3D1)" " Sort Key: tbl_sensor_channel_data.sens_chan_data_timestamp" " Sort Method: external sort Disk: 3240kB" " -> Bitmap Heap Scan on tbl_sensor_channel_data = (cost=3D3005.29..193096.66 rows=3D105456 width=3D12) (actual = time=3D60.012..35037.129 rows=3D150678 loops=3D1)" " Recheck Cond: ((tree_id =3D 70) AND (sens_chan_data_timestamp = >=3D '2008-06-11 00:00:00'::timestamp without time zone) AND = (sens_chan_data_timestamp <=3D '2008-06-18 00:00:00'::timestamp without = time zone))" " -> Bitmap Index Scan on tbl_sensor_channel_data_pkey = (cost=3D0.00..2978.92 rows=3D105456 width=3D0) (actual = time=3D21.884..21.884 rows=3D150678 loops=3D1)" " Index Cond: ((tree_id =3D 70) AND = (sens_chan_data_timestamp >=3D '2008-06-11 00:00:00'::timestamp without = time zone) AND (sens_chan_data_timestamp <=3D '2008-06-18 = 00:00:00'::timestamp without time zone))" "Total runtime: 35397.841 ms" ----------------------------------------------------------- EXPLAIN ANALYSE SELECT timestamp, data_from_tree_id_70*fnc_unit_conversion_factor(70, 7)+ = fnc_unit_conversion_offset(70, 7) AS "flow_11"=20 FROM=20 (SELECT sens_chan_data_timestamp AS timestamp, sens_chan_data_data AS = data_from_tree_id_70 FROM tbl_sensor_channel_data WHERE tree_id =3D 70 = AND sens_chan_data_timestamp >=3D '2008-06-11T00:00:00' AND = sens_chan_data_timestamp <=3D '2008-06-18T00:00:00' ) AS "70"=20 ORDER BY timestamp; EXPLAIN ANALYSE SELECT timestamp, "Sort (cost=3D176058.28..176321.92 rows=3D105456 width=3D12) (actual = time=3D630.350..669.843 rows=3D150678 loops=3D1)" " Sort Key: tbl_sensor_channel_data.sens_chan_data_timestamp" " Sort Method: external sort Disk: 3240kB" " -> Bitmap Heap Scan on tbl_sensor_channel_data = (cost=3D3005.29..167259.94 rows=3D105456 width=3D12) (actual = time=3D35.498..399.726 rows=3D150678 loops=3D1)" " Recheck Cond: ((tree_id =3D 70) AND (sens_chan_data_timestamp = >=3D '2008-06-11 00:00:00'::timestamp without time zone) AND = (sens_chan_data_timestamp <=3D '2008-06-18 00:00:00'::timestamp without = time zone))" " -> Bitmap Index Scan on tbl_sensor_channel_data_pkey = (cost=3D0.00..2978.92 rows=3D105456 width=3D0) (actual = time=3D27.433..27.433 rows=3D150678 loops=3D1)" " Index Cond: ((tree_id =3D 70) AND = (sens_chan_data_timestamp >=3D '2008-06-11 00:00:00'::timestamp without = time zone) AND (sens_chan_data_timestamp <=3D '2008-06-18 = 00:00:00'::timestamp without time zone))" "Total runtime: 694.968 ms" "Szymon Guz" wrote in message = news:AANLkTimB8-0KZrRbddqgxnZ5TjdgF2t3fFbu2lvx-2V0@mail.gmail.com... 2010/6/19 Davor J. I think I have read what is to be read about queries being prepared = in plpgsql functions, but I still can not explain the following, so I = thought to post it here: Suppose 2 functions: factor(int,int) and offset(int, int). Suppose a third function: convert(float,int,int) which simply = returns $1*factor($2,$3)+offset($2,$3) All three functions are IMMUTABLE. Very simple, right? Now I have very fast AND very slow executing = queries on some 150k records: VERY FAST (half a second): ---------------- SELECT data*factor(1,2)+offset(1,2) FROM tbl_data; VERY SLOW (a minute): ---------------- SELECT convert(data, 1, 2) FROM tbl_data; The slowness cannot be due to calling a function 150k times. If I = define convert2(float,int,int) to return a constant value, then it executes = in about a second. (still half as slow as the VERY FAST query). I assume that factor and offset are cached in the VERY FAST query, = and not in the slow one? If so, why not and how can I "force" it? Currently = I need only one function for conversions. Regards, Davor Hi, show us the code of those two functions and explain analyze of those = queries. regards Szymon Guz ------=_NextPart_000_0107_01CB1080.067DB0F0 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable =EF=BB=BF
I didn't consider them to be important = as they=20 showed the same, only the execution time was different. Also, they are a = bit=20 more complex than the ones put in the previous post. But here they=20 are:
 
Definitions:
--------------------------------------------= ---------------
CREATE=20 OR REPLACE FUNCTION appfunctions.fnc_unit_conversion_factor(_tree_id = integer,=20 _unit_to_id integer)
  RETURNS real AS
$BODY$ =
DECLARE
BEGIN=20
RETURN (SELECT unit_conv_factor AS factor
  FROM=20 vew_unit_conversions AS c
  INNER JOIN tbl_sensors AS s ON = (s.unit_id =3D=20 c.unit_id_from)
  INNER JOIN tbl_trees USING (sens_id)
  = WHERE=20 tree_id =3D _tree_id AND unit_id_to =3D _unit_to_id)::real;
END;=20
$BODY$
  LANGUAGE 'plpgsql'=20 IMMUTABLE
--------------------------
CREATE OR REPLACE FUNCTION=20 appfunctions.fnc_unit_conversion_offset(_tree_id integer, _unit_to_id=20 integer)
  RETURNS real AS
$BODY$
DECLARE
BEGIN =
RETURN=20 (SELECT unit_conv_offset AS offset
  FROM vew_unit_conversions = AS=20 c
  INNER JOIN tbl_sensors AS s ON (s.unit_id =3D=20 c.unit_id_from)
  INNER JOIN tbl_trees USING (sens_id)
  = WHERE=20 tree_id =3D _tree_id AND unit_id_to =3D _unit_to_id)::real;
END;=20
$BODY$
  LANGUAGE 'plpgsql'=20 IMMUTABLE
--------------------------
CREATE OR REPLACE FUNCTION=20 appfunctions.fnc_unit_convert(_rawdata real, _tree_id integer, = _unit_to_id=20 integer)
  RETURNS real AS
$BODY$
DECLARE
BEGIN =
RETURN=20 _rawdata
 * fnc_unit_conversion_factor(_tree_id, _unit_to_id)=20
 + fnc_unit_conversion_offset(_tree_id, _unit_to_id);
END;=20
$BODY$
  LANGUAGE 'plpgsql' IMMUTABLE
 
 
 
Executions:
---------------------------------------------= --------------
EXPLAIN=20 ANALYSE SELECT timestamp,
 
data_from_tree_id_70 AS "flow_11" =
 
 FROM
(SELECT = sens_chan_data_timestamp AS=20 timestamp, sens_chan_data_data AS data_from_tree_id_70 FROM=20 tbl_sensor_channel_data WHERE tree_id =3D 70 AND = sens_chan_data_timestamp >=3D=20 '2008-06-11T00:00:00' AND sens_chan_data_timestamp <=3D = '2008-06-18T00:00:00' )=20 AS "70"
 
 ORDER BY timestamp;
 
"Sort  = (cost=3D175531.00..175794.64 rows=3D105456=20 width=3D12) (actual time=3D598.454..638.400 rows=3D150678 = loops=3D1)"
"  Sort=20 Key: tbl_sensor_channel_data.sens_chan_data_timestamp"
"  Sort=20 Method:  external sort  Disk: 3240kB"
"  ->  = Bitmap=20 Heap Scan on tbl_sensor_channel_data  (cost=3D3005.29..166732.66 = rows=3D105456=20 width=3D12) (actual time=3D34.810..371.099 rows=3D150678=20 loops=3D1)"
"        Recheck Cond: = ((tree_id=20 =3D 70) AND (sens_chan_data_timestamp >=3D '2008-06-11 = 00:00:00'::timestamp=20 without time zone) AND (sens_chan_data_timestamp <=3D '2008-06-18=20 00:00:00'::timestamp without time=20 zone))"
"        ->  = Bitmap Index=20 Scan on tbl_sensor_channel_data_pkey  (cost=3D0.00..2978.92 = rows=3D105456=20 width=3D0) (actual time=3D28.008..28.008 rows=3D150678=20 loops=3D1)"
"         &nb= sp;   =20 Index Cond: ((tree_id =3D 70) AND (sens_chan_data_timestamp >=3D = '2008-06-11=20 00:00:00'::timestamp without time zone) AND (sens_chan_data_timestamp = <=3D=20 '2008-06-18 00:00:00'::timestamp without time zone))"
"Total runtime: = 663.478=20 ms"
-----------------------------------------------------------
EXP= LAIN=20 ANALYSE SELECT timestamp,
 
fnc_unit_convert(data_from_tree_id_70, = 70, 7) AS=20 "flow_11"
 
 FROM
(SELECT = sens_chan_data_timestamp AS=20 timestamp, sens_chan_data_data AS data_from_tree_id_70 FROM=20 tbl_sensor_channel_data WHERE tree_id =3D 70 AND = sens_chan_data_timestamp >=3D=20 '2008-06-11T00:00:00' AND sens_chan_data_timestamp <=3D = '2008-06-18T00:00:00' )=20 AS "70"
 
 ORDER BY timestamp;
 
"Sort  = (cost=3D201895.00..202158.64 rows=3D105456=20 width=3D12) (actual time=3D35334.017..35372.977 rows=3D150678 = loops=3D1)"
" =20 Sort Key: tbl_sensor_channel_data.sens_chan_data_timestamp"
"  = Sort=20 Method:  external sort  Disk: 3240kB"
"  ->  = Bitmap=20 Heap Scan on tbl_sensor_channel_data  (cost=3D3005.29..193096.66 = rows=3D105456=20 width=3D12) (actual time=3D60.012..35037.129 rows=3D150678=20 loops=3D1)"
"        Recheck Cond: = ((tree_id=20 =3D 70) AND (sens_chan_data_timestamp >=3D '2008-06-11 = 00:00:00'::timestamp=20 without time zone) AND (sens_chan_data_timestamp <=3D '2008-06-18=20 00:00:00'::timestamp without time=20 zone))"
"        ->  = Bitmap Index=20 Scan on tbl_sensor_channel_data_pkey  (cost=3D0.00..2978.92 = rows=3D105456=20 width=3D0) (actual time=3D21.884..21.884 rows=3D150678=20 loops=3D1)"
"         &nb= sp;   =20 Index Cond: ((tree_id =3D 70) AND (sens_chan_data_timestamp >=3D = '2008-06-11=20 00:00:00'::timestamp without time zone) AND (sens_chan_data_timestamp = <=3D=20 '2008-06-18 00:00:00'::timestamp without time zone))"
"Total runtime: = 35397.841=20 ms"
-----------------------------------------------------------
EXP= LAIN=20 ANALYSE SELECT timestamp,
 
data_from_tree_id_70*fnc_unit_conversion_factor(70,=20 7)+ fnc_unit_conversion_offset(70, 7) AS "flow_11"
 
 FROM
(SELECT = sens_chan_data_timestamp AS=20 timestamp, sens_chan_data_data AS data_from_tree_id_70 FROM=20 tbl_sensor_channel_data WHERE tree_id =3D 70 AND = sens_chan_data_timestamp >=3D=20 '2008-06-11T00:00:00' AND sens_chan_data_timestamp <=3D = '2008-06-18T00:00:00' )=20 AS "70"
 
 ORDER BY timestamp;
 
EXPLAIN ANALYSE SELECT = timestamp,
 
"Sort  = (cost=3D176058.28..176321.92 rows=3D105456=20 width=3D12) (actual time=3D630.350..669.843 rows=3D150678 = loops=3D1)"
"  Sort=20 Key: tbl_sensor_channel_data.sens_chan_data_timestamp"
"  Sort=20 Method:  external sort  Disk: 3240kB"
"  ->  = Bitmap=20 Heap Scan on tbl_sensor_channel_data  (cost=3D3005.29..167259.94 = rows=3D105456=20 width=3D12) (actual time=3D35.498..399.726 rows=3D150678=20 loops=3D1)"
"        Recheck Cond: = ((tree_id=20 =3D 70) AND (sens_chan_data_timestamp >=3D '2008-06-11 = 00:00:00'::timestamp=20 without time zone) AND (sens_chan_data_timestamp <=3D '2008-06-18=20 00:00:00'::timestamp without time=20 zone))"
"        ->  = Bitmap Index=20 Scan on tbl_sensor_channel_data_pkey  (cost=3D0.00..2978.92 = rows=3D105456=20 width=3D0) (actual time=3D27.433..27.433 rows=3D150678=20 loops=3D1)"
"         &nb= sp;   =20 Index Cond: ((tree_id =3D 70) AND (sens_chan_data_timestamp >=3D = '2008-06-11=20 00:00:00'::timestamp without time zone) AND (sens_chan_data_timestamp = <=3D=20 '2008-06-18 00:00:00'::timestamp without time zone))"
"Total runtime: = 694.968=20 ms"
 
 
 
 
 
"Szymon Guz" <mabewlun@gmail.com> wrote in = message news:AANLkTimB8-0KZrRbddqgxnZ5TjdgF2t3fFbu2lvx-2V0@mail.gmail.com..= .


2010/6/19 Davor J. <DavorJ@live.com>
I think I have read what is to be read about = queries being=20 prepared in
plpgsql functions, but I still can not explain the = following,=20 so I thought
to post it here:

Suppose 2 functions: = factor(int,int)=20 and offset(int, int).
Suppose a third function: = convert(float,int,int)=20 which simply returns
$1*factor($2,$3)+offset($2,$3)
All three=20 functions are IMMUTABLE.

Very simple, right? Now I have very = fast AND=20 very slow executing queries on
some 150k records:

VERY = FAST (half=20 a second):
----------------
SELECT = data*factor(1,2)+offset(1,2) FROM=20 tbl_data;

VERY SLOW (a minute):
----------------
SELECT = convert(data, 1, 2) FROM tbl_data;

The slowness cannot be due = to=20 calling a function 150k times. If I = define
convert2(float,int,int) to=20 return a constant value, then it executes in
about a second. = (still half=20 as slow as the VERY FAST query).

I assume that factor and = offset are=20 cached in the VERY FAST query, and not
in the slow one? If so, = why not=20 and how can I "force" it? Currently I need
only one function for=20 conversions.

Regards,
Davor

Hi,
show us the code of those two functions and explain analyze of = those=20 queries.

regards
Szymon Guz
------=_NextPart_000_0107_01CB1080.067DB0F0--