Received: from magus.postgresql.org (magus.postgresql.org [87.238.57.229]) by mail.postgresql.org (Postfix) with ESMTP id 06F00841FF2 for ; Wed, 25 Apr 2012 18:12:23 -0300 (ADT) Received: from nm6.bullet.mail.ac4.yahoo.com ([98.139.52.203]) by magus.postgresql.org with smtp (Exim 4.72) (envelope-from ) id 1SN9Va-0007cZ-6X for pgsql-performance@postgresql.org; Wed, 25 Apr 2012 21:12:22 +0000 Received: from [98.139.52.194] by nm6.bullet.mail.ac4.yahoo.com with NNFMP; 25 Apr 2012 21:12:04 -0000 Received: from [68.142.200.226] by tm7.bullet.mail.ac4.yahoo.com with NNFMP; 25 Apr 2012 21:12:04 -0000 Received: from [66.94.237.116] by t7.bullet.mud.yahoo.com with NNFMP; 25 Apr 2012 21:12:04 -0000 Received: from [127.0.0.1] by omp1021.access.mail.mud.yahoo.com with NNFMP; 25 Apr 2012 21:12:04 -0000 X-Yahoo-Newman-Property: ymail-3 X-Yahoo-Newman-Id: 22951.55999.bm@omp1021.access.mail.mud.yahoo.com Received: (qmail 84955 invoked by uid 60001); 25 Apr 2012 21:12:03 -0000 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yahoo.com; s=s1024; t=1335388323; bh=txPj6nIelRr/tL9dHi+J8Agz1S9Ez/dttkQ9n0wQ9/I=; h=X-YMail-OSG:Received:X-Mailer:References:Message-ID:Date:From:Reply-To:Subject:To:Cc:In-Reply-To:MIME-Version:Content-Type; b=WOgO7iTrXpjNsA/VewXipHjbTKfXvfFto5L8XhICdaG7LUI3eALCCAaju9y+mS4ftmQvqPcKZzDX4aiFbTX/5q/z30qT0uuXFj34dy0fwn2Sk2hHiU7k7QTUe4HL48O2bAysx8A8hj+vgDoNPTtWXrJn7eGgWD6DNb0NjNT55J8= DomainKey-Signature: a=rsa-sha1; q=dns; c=nofws; s=s1024; d=yahoo.com; h=X-YMail-OSG:Received:X-Mailer:References:Message-ID:Date:From:Reply-To:Subject:To:Cc:In-Reply-To:MIME-Version:Content-Type; b=0pMzAqh9/ZQjeH3mWV2Uq3az/vywXAfusMmUjMuoyOJyRoj5ARCxCyLfcJ6B1gDdTpnHkOfkw7zoZoKT29vNpGoExCSdhKT8NBQ6mvoVTIwWSuJHJOOqvp8sbnfM5HghKycZ1vVpGRAWRWS7yhEtID2ktvOTvCro0YeeQxIEQeg=; X-YMail-OSG: bK_WwAIVM1kqvSeuTFFcsGnhaP15P29PfWMLxfT8xR2eqVy VoVi8YK_IIYbGFIsHcsJzrye_vgHPz4JRJAl60tQb1nUfJNYjgQCBYQ_zg77 W5MKMb_Gmk8rrb4k6YCRbc7yZAeIysMqVC2Ru7kLcORia5_9TDuXipmQbFda kZtRzsu9U5e1ebzKlpbCm5IEPA8jfhjupa5mWxwYhyff1_xlBKHE3mUORhgP NU0522VTfU4dOx1oR.E.uWNE6EcL7KJP9jJl0ZK2y8Kdf9CrSQ5evbTYSpL3 Pg6tcgZeqsmxthNyyZrJjZvkvzzegbkfK384WMPM2QoBzGQndQQWFWr4TrhJ Qc4AGQsvk8OIM6yRtZfxMBs2OfoVo9Ld3UoO9gOVFCmdlchmmGMP7vAkWqC6 pA8ykzb9ghG.IzUVyvzY9v2Y0Dla8tJVfj3yC_t5iPEn_nNb2SuprdcFpqxm 5q7ECRjoSsopRfwSfjfsAUN.fCvLzNpzMYVIhFQKzyftJe1Kxr09Cf0Ttynj 309_0a2ItSWIrm.26R7x0EvY9StXai4aou4q1 Received: from [24.6.62.191] by web184517.mail.ne1.yahoo.com via HTTP; Wed, 25 Apr 2012 14:12:03 PDT X-Mailer: YahooMailWebService/0.8.117.340979 References: <1335379923.47084.YahooMailNeo@web184514.mail.ne1.yahoo.com> Message-ID: <1335388323.84458.YahooMailNeo@web184517.mail.ne1.yahoo.com> Date: Wed, 25 Apr 2012 14:12:03 -0700 (PDT) From: Venki Ramachandran Reply-To: Venki Ramachandran Subject: Re: Parallel Scaling of a pgplsql problem To: Samuel Gendler Cc: "pgsql-performance@postgresql.org" In-Reply-To: MIME-Version: 1.0 Content-Type: multipart/alternative; boundary="-1221105611-2116429009-1335388323=:84458" X-Pg-Spam-Score: -2.0 (--) X-Archive-Number: 201204/147 X-Sequence-Number: 46793 ---1221105611-2116429009-1335388323=:84458 Content-Type: text/plain; charset=iso-8859-1 Content-Transfer-Encoding: quoted-printable Another question (probably a silly mistake) while debugging this problem:= =0AI put in insert statements into the pgplsql code to collect the current_= timestamp and see where the code was spending most of it time....The output= is as follows:=0A=0A=A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 log_text =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 | =A0 =A0 =A0 =A0insertdatetime=0A------------------------------------= ---------------------------------------------------------------------------= ----------------------------------+-------------------------------=0A=A0INP= UT VARIABLES,Src,emp_id_1,emp_id_100,StartDate,2012-01-01,EndDate,2012-02-0= 1,Tou,DOnPk,CRR Type,ptp-obligations,MinPositivePirce,1.00 | 2012-04-25 20:= 56:42.691965+00=0A=A0Starting get_DAM_Value function =A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0| 2012-04-25 20:56:42.691965+00=0A=A0StartDate,2012= -01-01 01:00:00,EndDate,2012-02-02 00:00:00 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= | 2012-04-25 20:56:42.691965+00=0A=A0StartHr,vSrcprice,vSinkprice,vDiff,vA= vgValue,vTotalDAMValue,vPkTotal,vOffPkTotal =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0| 2012-04-25 20:56:42.691965+00=0A=A02012-01-01 01:0= 0:00,18.52,16.15,-2.370000,-2.370000,0.000000,0.000000,-2.370000 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 | 2012-04-25 20:56:42.691965+0= 0=0A=A02012-01-01 02:00:00,17.22,15.60,-1.620000,-1.620000,0.000000,0.00000= 0,-3.990000 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 | 2012-04-= 25 20:56:42.691965+00=0A=A02012-01-01 03:00:00,18.22,17.55,-0.670000,-0.670= 000,0.000000,0.000000,-4.660000 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0 | 2012-04-25 20:56:42.691965+00=0A=A02012-01-01 04:00:00,18.53,= 18.13,-0.400000,-0.400000,0.000000,0.000000,-5.060000 =A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 | 2012-04-25 20:56:42.691965+00=0A=A0...= =0A=A0...=0A=A0...=0A=A0...=0A=A02012-02-02 00:00:00,2,17.13,17.13,0.000000= ,0.000000,0.000000,-7940.250000,-5216.290000 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0| 2012-04-25 20:56:42.691965+00=0A=A02012-02-02 00:00:00,3,16.5= 4,16.54,0.000000,0.000000,0.000000,-7940.250000,-5216.290000 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0| 2012-04-25 20:56:42.691965+00=0A=A02012-02-02= 00:00:00,4,16.27,16.27,0.000000,0.000000,0.000000,-7940.250000,-5216.29000= 0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0| 2012-04-25 20:56:42.691965+00= =0A=A0TotalPEAKMVal,-7940.250000,NumIntervals,2034,AvgRTMVAlue,-3.903761 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 = =A0 =A0| 2012-04-25 20:56:42.691965+00=0A=A0OUTPUT VARIABLES,AvgPurValue,-2= .84,AvgSaleValue,-3.90,Profit,-1.06,ProfitPercentage,-106.00 =A0 =A0 =A0 = =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0 =A0= =A0 =A0 =A0 =A0 | 2012-04-25 20:56:42.691965+00=0A(3832 rows)=0A=0AWhy doe= sn't the current_timestamp value change within the pgpsql code? For every s= elect from a table to compute, I am inserting into my debug_log dummy table= . For all 3832 rows I have the same current_timestamp value which I was hop= ing to get by the following insert statement:=0Ainsert into debug_log ('som= e log text', current_timestamp);=0A=0ABut when I run this procedure from th= e psql command line, it takes 11 seconds....I gave a bigger date range than= what I stated as (40 ms) in my first post hence the change to 11 seconds.= =0A=0Adev=3D> select calc_comp('emp_id_1','emp_id_100','DAM-RTM',to_date('2= 012-01-01','yyyy-mm-dd'),to_date('2012-02-01','yyyy-mm-dd'),'DOnPk','ptp-ob= ligations',1.00, 0);=0A=A0 =A0 =A0 =A0 =A0crr_valuation =A0 =A0 =A0 =A0=A0= =0A-------------------------------=0A=A00||-2.84|-3.90|-1.06|-106.00|=0A(1 = row)=0A=0ATime: 11685.828 ms.=0A=0AThe last input value 1/0 while calling t= he above function controls, if any log line messages should be inserted or = not, 0=3Dinsert, 1 =3D do_not_insert. When I toggle the flag the overall ti= ming did not change. Does it not some time in ms to write 3832 rows to a ta= ble?=0AWhy is my current_timestamp value not changing. I was expecting the = difference between the last row's timestamp value MINUS the first row's tie= mstamp value to equal my 11.685 seconds. What is wrong here?=0A=0A=0A-Venki= =0A=0A=0A________________________________=0A From: Samuel Gendler =0ATo: Venki Ramachandran = =0ACc: "pgsql-performance@postgresql.org" =0ASent: Wednesday, April 25, 2012 12:36 PM=0ASubject: Re: [PERFORM] Para= llel Scaling of a pgplsql problem=0A =0A=0A=0A=0A=0AOn Wed, Apr 25, 2012 at= 11:52 AM, Venki Ramachandran wrote:=0A=0AHi= all:=0A>Can someone please guide me as to how to solve this problem? If th= is is the wrong forum, please let me know which one to post this one in. I = am new to Postgres (about 3 months into it)=0A>=0A>=0A>I have PostGres 9.0 = database in a AWS server (x-large) and a pgplsql program that does some com= putation. It takes in a date range and for one pair of personnel (two emplo= yees in a company) it calculates some values over the time period. It takes= about 40ms (milli seconds) to complete and give me the answer. All good so= far.=0A>=0A>=0A>Now I have to run the same pgplsql on all possible combina= tions of employees and with 542 employees that is about say 300,000 unique = pairs.=0A>=0A>=0A>So (300000 * 40)/(1000 * 60 * 60) =3D 3.33 hours and I ha= ve to rank them and show it on a screen. No user wants to wait for 3 hours,= =A0they can probably wait for 10 minutes (even that is too much for a UI a= pplication). How do I solve this scaling problem? Can I have multiple parel= lel sessions and each session have multiple/processes that do a pair each a= t 40 ms and then collate the results. Does PostGres or pgplsql have any par= allel computing capability.=0A=0AThe question is, how much of that 40ms is = spent performing the calculation, how much is spent querying, and how much = is function call overhead, and how much is round trip between the client an= d server with the query and results? =A0Depending upon the breakdown, it is= entirely possible that the actual per-record multiplier can be kept down t= o a couple of milliseconds if you restructure things to query data in bulk = and only call a single function to do the work. =A0If you get it down to 4m= s, that's a 20 minute query. =A0Get it down to 1ms and you're looking at on= ly 5 minutes for what would appear to be a fairly compute-intensive report = over a relatively large dataset. ---1221105611-2116429009-1335388323=:84458 Content-Type: text/html; charset=iso-8859-1 Content-Transfer-Encoding: quoted-printable
Another question (probabl= y a silly mistake) while debugging this problem:
I put in insert = statements into the pgplsql code to collect the current_timestamp and see w= here the code was spending most of it time....The output is as follows:

        &nb= sp;                     &= nbsp;                    =                 log_text   &n= bsp;                                         &nbs= p;                     &n= bsp; |        insertdatetime
-------------------------------------------------------------------= ---------------------------------------------------------------------------= ---+-------------------------------
 = ;INPUT VARIABLES,Src,emp_id_1,emp_id_100,StartDate,2012-01-01,EndDate,2012-= 02-01,Tou,DOnPk,CRR Type,ptp-obligations,MinPositivePirce,1.00 | 2012-04-25= 20:56:42.691965+00
 Starting get_DA= M_Value function                 &n= bsp;                     =                      = ;                                         &nbs= p;                     &n= bsp;          | 2012-04-25 20:56:42.691965+00
 StartDate,2012-01-01 01:00:00,EndD= ate,2012-02-02 00:00:00               &n= bsp;                     =                      = ;                     &nb= sp;           | 2012-04-25 20:56:42.691965+00
 StartHr,vSrcprice,vSinkprice,vDiff,vAvgValue,vTotalDAMValue,vPk= Total,vOffPkTotal                 &= nbsp;                    =                          | 2012-04-25 20:56:42.691965+00
 2012-0= 1-01 01:00:00,18.52,16.15,-2.370000,-2.370000,0.000000,0.000000,-2.370000 &= nbsp;                    =                     &nbs= p;                     | = 2012-04-25 20:56:42.691965+00
 2012-01-01 02:00:00,17.22,15.= 60,-1.620000,-1.620000,0.000000,0.000000,-3.990000       &nb= sp;                     &= nbsp;                    =               | 2012-04-25 20:56:42.691= 965+00
 2012-01-01 03:00:00,18.22,17.55,-0.670000,-0.670000,= 0.000000,0.000000,-4.660000              = ;                                       &nbs= p;           | 2012-04-25 20:56:42.691965+00
=
 2012-01-01 04:00:00,18.53,18.13,-0.400000,-0.400000,0.000000,0.0= 00000,-5.060000                 &nb= sp;                     &= nbsp;                    =     | 2012-04-25 20:56:42.691965+00
 ...
 ...
 ...
 ...
 2012-02-02 00:00:00,2,17.13,17.13,0.00000= 0,0.000000,0.000000,-7940.250000,-5216.290000         &= nbsp;                    =                     &nbs= p;      | 2012-04-25 20:56:42.691965+00
 2012-02-02 00:0= 0:00,3,16.54,16.54,0.000000,0.000000,0.000000,-7940.250000,-5216.290000 &nb= sp;                     &= nbsp;                    =              | 2012-04-25 20:56:42.6919= 65+00
 2012-02-02 00:00:00,4,16.27,1= 6.27,0.000000,0.000000,0.000000,-7940.250000,-5216.290000     &nb= sp;                     &= nbsp;                    =          | 2012-04-25 20:56:42.691965+00
 TotalPEAKMVal,-7940.250000,NumIntervals,203= 4,AvgRTMVAlue,-3.903761               &n= bsp;                                         &nbs= p;                    | 2= 012-04-25 20:56:42.691965+00
 OUTPUT= VARIABLES,AvgPurValue,-2.84,AvgSaleValue,-3.90,Profit,-1.06,ProfitPercenta= ge,-106.00                   &= nbsp;                    =             | 2012-04-25 20:56:42.691965+00<= /font>
(3832 rows)

Why doesn't the current_times= tamp value change within the pgpsql code? For every select from a table to = compute, I am inserting into my debug_log dummy table. For all 3832 rows I = have the sam= e current_timestamp value which I was hoping to get by the following insert statement:
insert into debug_log = ('some log text', current_timestamp);
But when I run this procedure from the = psql command line, it takes 11 seconds....I gave a bigger date range than w= hat I stated as (40 ms) in my first post hence the change to 11 seconds.

dev=3D> select calc_comp('emp_id_1','emp_id_100','DAM-RTM',to_date('201= 2-01-01','yyyy-mm-dd'),to_date('2012-02-01','yyyy-mm-dd'),'DOnPk','ptp-obli= gations',1.00, 0);
         crr_valuatio= n         
-----------------------------= --
 0||-2.84|-3.90|-1.06|-106.00|
(1 row)

Time: 11685.828 ms.

The last inpu= t value 1/0 while calling the above function controls, if any log line mess= ages should be inserted or not, 0=3Dinsert, 1 =3D do_not_insert. When I toggle = the flag the overall timing did not change. Does it not some time in ms to = write 3832 rows to a table?
Why is my current_timestamp value not= changing. I was expecting the difference between the last row's timestamp = value MINUS the first row's tiemstamp value to equal my 11.685 seconds. Wha= t is wrong here?


-Venki

From: Samuel Gendler <sgendler@ideasculptor.com> To: Venki Ramachandran <venki_ramachandran@yahoo.com>
Cc: "pgsql-performance@postgresql.org" <pgsql-performanc= e@postgresql.org>
Sent: Wednesday, April 25, 2012 12:36 PM
Subject: Re: [PERFORM] Parallel Scaling of a pgplsql pro= blem

=0A


On We= d, Apr 25, 2012 at 11:52 AM, Venki Ramachandran <venki_ramachandran@yahoo= .com> wrote:
=0A
Hi all:
Can someone please guide me as to how t= o solve this problem? If this is the wrong forum, please let me know which = one to post this one in. I am new to Postgres (about 3 months into it)=0A

I have PostGres 9.0 database in a AWS server (x-lar= ge) and a pgplsql program that does some computation. It takes in a date ra= nge and for one pair of personnel (two employees in a company) it calculate= s some values over the time period. It takes about 40ms (milli seconds) to = complete and give me the answer. All good so far.
=0A

Now I have to run the same pgplsql on all possible combinations of emplo= yees and with 542 employees that is about say 300,000 unique pairs.

So (300000 * 40)/(1000 * 60 * 60) =3D 3.33 hours and I ha= ve to rank them and show it on a screen. No=0A user wants to wait for 3 hou= rs,  they can probably wait for 10 minutes (even that is too much for = a UI application). How do I solve this scaling problem? Can I have multiple= parellel sessions and each session have multiple/processes that do a pair = each at 40 ms and then collate the results. Does PostGres or pgplsql have a= ny parallel computing capability.
=0A
The question is, how much of that 40ms is spent performing the = calculation, how much is spent querying, and how much is function call over= head, and how much is round trip between the client and server with the que= ry and results?  Depending upon the breakdown, it is entirely possible= that the actual per-record multiplier can be kept down to a couple of mill= iseconds if you restructure things to query data in bulk and only call a si= ngle function to do the work.  If you get it down to 4ms, that's a 20 = minute query.  Get it down to 1ms and you're looking at only 5 minutes= for what would appear to be a fairly compute-intensive report over a relat= ively large dataset.
=0A


=0A<= /div>

---1221105611-2116429009-1335388323=:84458--