pg.ddx.io  pgsql-performance@postgresql.org mailing list archive  
help / color / mirror / Atom feed
Performance analysis of plpgsql code
8+ messages / 4 participants
[nested] [flat]

* Performance analysis of plpgsql code
@ 2005-06-27 23:30  Karl O. Pinc <kop@meme.com>
  0 siblings, 1 reply; 8+ messages in thread

From: Karl O. Pinc @ 2005-06-27 23:30 UTC (permalink / raw)
  To: pgsql-performance

Hi,

I'm having a hard time finding the poorly performing
statements in my plpgsql procedures, many of which
are triggers.  Am I missing something?

I can get the query plans by starting up a new
connection and doing:
SET DEBUG_PRINT_PLAN TO TRUE;
SET CLIENT_MIN_MESSAGES TO DEBUG1;
And then running code that exercises my functions.
Then I can find the queries that, in theory,
could have problems.  But problems remain
after this.

What I'd really like is a SET variable (or maybe
a clause in CREATE FUNCTION) that causes any
functions compiled to issue EXPLAIN ANALYZE output
and the query text itself, to be RAISEd.
Then I could watch the performance as it ran.

Short of that I think I'm going to be reduced to
writing a C function that returns the real
system time so I can spatter my code with
RAISE statements that indicate actual execution
time.

Is there a better approach?
Does anybody have such a C function handy?


Karl <kop@meme.com>
Free Software:  "You don't pay back, you pay forward."
                  -- Robert A. Heinlein




^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: Performance analysis of plpgsql code
@ 2005-06-27 23:33  Michael Fuhr <mike@fuhr.org>
  parent: Karl O. Pinc <kop@meme.com>
  0 siblings, 1 reply; 8+ messages in thread

From: Michael Fuhr @ 2005-06-27 23:33 UTC (permalink / raw)
  To: Karl O. Pinc <kop@meme.com>; +Cc: pgsql-performance

On Mon, Jun 27, 2005 at 11:30:45PM +0000, Karl O. Pinc wrote:
> 
> Short of that I think I'm going to be reduced to
> writing a C function that returns the real
> system time so I can spatter my code with
> RAISE statements that indicate actual execution
> time.

See timeofday().

http://www.postgresql.org/docs/8.0/static/functions-datetime.html#FUNCTIONS-DATETIME-CURRENT

-- 
Michael Fuhr
http://www.fuhr.org/~mfuhr/



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: Performance analysis of plpgsql code
@ 2005-06-28 01:15  Michael Glaesemann <grzm@myrealbox.com>
  parent: Karl O. Pinc <kop@meme.com>
  1 sibling, 0 replies; 8+ messages in thread

From: Michael Glaesemann @ 2005-06-28 01:15 UTC (permalink / raw)
  To: Karl O. Pinc <kop@meme.com>; +Cc: pgsql-performance


On Jun 28, 2005, at 10:54 AM, Karl O. Pinc wrote:

>
> On 06/27/2005 06:33:03 PM, Michael Fuhr wrote:
>
>> On Mon, Jun 27, 2005 at 11:30:45PM +0000, Karl O. Pinc wrote:
>> >
>> > Short of that I think I'm going to be reduced to
>> > writing a C function that returns the real
>> > system time so I can spatter my code with
>> > RAISE statements that indicate actual execution
>> > time.
>> See timeofday().
>>
>
> That only gives you the time at the start of the transaction,
> so you get no indication of how long anything in the
> transaction takes.

I recommend you look again.

<http://www.postgresql.org/docs/8.0/interactive/functions- 
datetime.html#FUNCTIONS-DATETIME-CURRENT>

Michael Glaesemann
grzm myrealbox com



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: Performance analysis of plpgsql code
@ 2005-06-28 01:34  Michael Fuhr <mike@fuhr.org>
  parent: Karl O. Pinc <kop@meme.com>
  1 sibling, 1 reply; 8+ messages in thread

From: Michael Fuhr @ 2005-06-28 01:34 UTC (permalink / raw)
  To: Karl O. Pinc <kop@meme.com>; +Cc: pgsql-performance

On Tue, Jun 28, 2005 at 01:54:08AM +0000, Karl O. Pinc wrote:
> On 06/27/2005 06:33:03 PM, Michael Fuhr wrote:
>
> >See timeofday().
> 
> That only gives you the time at the start of the transaction,
> so you get no indication of how long anything in the
> transaction takes.

Did you read the documentation or try it?  Perhaps you're thinking
of now(), current_timestamp, and friends, which don't advance during
a transaction; but as the documentation states, "timeofday() returns
the wall-clock time and does advance during transactions."

I just ran tests on versions of PostgreSQL going back to 7.2.8 and
in all of them timeofday() advanced during a transaction.  Does it
not work on your system?  If not then something's broken -- what
OS and version of PostgreSQL are you using?

-- 
Michael Fuhr
http://www.fuhr.org/~mfuhr/



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: Performance analysis of plpgsql code
@ 2005-06-28 01:54  Karl O. Pinc <kop@meme.com>
  parent: Michael Fuhr <mike@fuhr.org>
  0 siblings, 2 replies; 8+ messages in thread

From: Karl O. Pinc @ 2005-06-28 01:54 UTC (permalink / raw)
  To: Michael Fuhr <mike@fuhr.org>; +Cc: pgsql-performance


On 06/27/2005 06:33:03 PM, Michael Fuhr wrote:
> On Mon, Jun 27, 2005 at 11:30:45PM +0000, Karl O. Pinc wrote:
> >
> > Short of that I think I'm going to be reduced to
> > writing a C function that returns the real
> > system time so I can spatter my code with
> > RAISE statements that indicate actual execution
> > time.
> 
> See timeofday().

That only gives you the time at the start of the transaction,
so you get no indication of how long anything in the
transaction takes.


Karl <kop@meme.com>
Free Software:  "You don't pay back, you pay forward."
                  -- Robert A. Heinlein




^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: Performance analysis of plpgsql code
@ 2005-06-28 02:49  Michael Fuhr <mike@fuhr.org>
  parent: Karl O. Pinc <kop@meme.com>
  0 siblings, 0 replies; 8+ messages in thread

From: Michael Fuhr @ 2005-06-28 02:49 UTC (permalink / raw)
  To: Karl O. Pinc <kop@meme.com>; +Cc: pgsql-performance

On Tue, Jun 28, 2005 at 03:03:06AM +0000, Karl O. Pinc wrote:
> 
> For all your work a documentation patch is appended that
> I think is easier to read and might avoid this problem
> in the future.

Patches should go to the pgsql-patches list -- the people who review
and apply patches might not be following this thread.

-- 
Michael Fuhr
http://www.fuhr.org/~mfuhr/



^ permalink  raw  reply  [nested|flat] 8+ messages in thread

* Re: Performance analysis of plpgsql code
@ 2005-06-28 03:03  Karl O. Pinc <kop@meme.com>
  parent: Michael Fuhr <mike@fuhr.org>
  0 siblings, 1 reply; 8+ messages in thread

From: Karl O. Pinc @ 2005-06-28 03:03 UTC (permalink / raw)
  To: Michael Fuhr <mike@fuhr.org>; +Cc: pgsql-performance@postgresql.org, Michael Glaesemann <grzm@myrealbox.com>


On 06/27/2005 08:34:19 PM, Michael Fuhr wrote:
> On Tue, Jun 28, 2005 at 01:54:08AM +0000, Karl O. Pinc wrote:
> > On 06/27/2005 06:33:03 PM, Michael Fuhr wrote:
> >
> > >See timeofday().
> >
> > That only gives you the time at the start of the transaction,
> > so you get no indication of how long anything in the
> > transaction takes.
> 
> Did you read the documentation or try it?  Perhaps you're thinking
> of now(), current_timestamp, and friends, which don't advance during
> a transaction; but as the documentation states, "timeofday() returns
> the wall-clock time and does advance during transactions."

Very sorry.  I did not read through the complete documentation.

> I just ran tests on versions of PostgreSQL going back to 7.2.8 and
> in all of them timeofday() advanced during a transaction.

For all your work a documentation patch is appended that
I think is easier to read and might avoid this problem
in the future.  If you don't read all the way through the
current cvs version then you might think, as I did,
that timeofday() is a CURRENT_TIMESTAMP related function.

Sorry, but 3 lines wrap in the patch
in my email client.  :(


Karl <kop@meme.com>
Free Software:  "You don't pay back, you pay forward."
                  -- Robert A. Heinlein


inline patch 1: func.sgml.new (+0/-1 lines) download inline-1.patch--- func.sgml 2005-06-26 17:05:35.000000000 -0500 +++ func.sgml.new 2005-06-27 21:51:05.301097896 -0500 @@ -5787,15 +5787,6 @@ </para> <para> - There is also the function <function>timeofday()</function>, which
for historical - reasons returns a <type>text</type> string rather than a <type>timestamp</type> value: -<screen> -SELECT timeofday(); -<lineannotation>Result: </lineannotation><computeroutput>Sat Feb 17 19:07:32.000126 2001 EST</computeroutput> -</screen> - </para> - - <para> It is important to know that <function>CURRENT_TIMESTAMP</function> and related functions return the start time of the current transaction; their values do not @@ -5803,8 +5794,7 @@ the intent is to allow a single transaction to have a consistent notion of the <quote>current</quote> time, so that multiple modifications within the same transaction bear the same - time stamp. <function>timeofday()</function> - returns the wall-clock time and does advance during transactions. + time stamp. </para> <note> @@ -5815,6 +5805,18 @@ </note> <para> + There is also the function <function>timeofday()</function> which + returns the wall-clock time and advances during transactions. For + historical reasons <function>timeofday()</function> returns a + <type>text</type> string rather than a <type>timestamp</type> + value: +<screen> +SELECT timeofday(); +<lineannotation>Result: </lineannotation><computeroutput>Sat Feb 17 19:07:32.000126 2001 EST</computeroutput> +</screen> + </para> + + <para> All the date/time data types also accept the special literal value <literal>now</literal> to specify the current date and time. Thus, the following three all return the same result: ^ permalink raw reply [nested|flat] 8+ messages in thread

* Re: Fwd: Re: [PERFORM] Performance analysis of plpgsql code
@ 2005-06-29 01:53  Bruce Momjian <pgman@candle.pha.pa.us>
  0 siblings, 0 replies; 8+ messages in thread

From: Bruce Momjian @ 2005-06-29 01:53 UTC (permalink / raw)
  To: Karl O. Pinc <kop@meme.com>; +Cc: pgsql-patches@postgresql.org


Patch applied.  Thanks.  Your documentation changes can be viewed in
five minutes using links on the developer's page,
http://www.postgresql.org/developer/testing.


---------------------------------------------------------------------------


Karl O. Pinc wrote:
> 
> On 06/27/2005 10:03:06 PM, Karl O. Pinc wrote:
> 
> On 06/27/2005 08:34:19 PM, Michael Fuhr wrote:
> > On Tue, Jun 28, 2005 at 01:54:08AM +0000, Karl O. Pinc wrote:
> > > On 06/27/2005 06:33:03 PM, Michael Fuhr wrote:
> > >
> > > >See timeofday().
> > >
> > > That only gives you the time at the start of the transaction,
> > > so you get no indication of how long anything in the
> > > transaction takes.
> > 
> > Did you read the documentation or try it?  Perhaps you're thinking
> > of now(), current_timestamp, and friends, which don't advance during
> > a transaction; but as the documentation states, "timeofday() returns
> > the wall-clock time and does advance during transactions."
> 
> Very sorry.  I did not read through the complete documentation.
> 
> > I just ran tests on versions of PostgreSQL going back to 7.2.8 and
> > in all of them timeofday() advanced during a transaction.
> 
> For all your work a documentation patch is appended that
> I think is easier to read and might avoid this problem
> in the future.  If you don't read all the way through the
> current cvs version then you might think, as I did,
> that timeofday() is a CURRENT_TIMESTAMP related function.
> 
> Sorry, but 3 lines wrap in the patch
> in my email client.  :(
> 
> 
> Karl <kop@meme.com>
> Free Software:  "You don't pay back, you pay forward."
>                   -- Robert A. Heinlein
> 
> 
> --- func.sgml	2005-06-26 17:05:35.000000000 -0500
> +++ func.sgml.new	2005-06-27 21:51:05.301097896 -0500
> @@ -5787,15 +5787,6 @@
>      </para>
> 
>      <para>
> -    There is also the function <function>timeofday()</function>, which  
> for historical
> -    reasons returns a <type>text</type> string rather than a  
> <type>timestamp</type> value:
> -<screen>
> -SELECT timeofday();
> -<lineannotation>Result: </lineannotation><computeroutput>Sat Feb 17  
> 19:07:32.000126 2001 EST</computeroutput>
> -</screen>
> -   </para>
> -
> -   <para>
>       It is important to know that
>       <function>CURRENT_TIMESTAMP</function> and related functions  
> return
>       the start time of the current transaction; their values do not
> @@ -5803,8 +5794,7 @@
>       the intent is to allow a single transaction to have a consistent
>       notion of the <quote>current</quote> time, so that multiple
>       modifications within the same transaction bear the same
> -    time stamp. <function>timeofday()</function>
> -    returns the wall-clock time and does advance during transactions.
> +    time stamp.
>      </para>
> 
>      <note>
> @@ -5815,6 +5805,18 @@
>      </note>
> 
>      <para>
> +    There is also the function <function>timeofday()</function> which
> +    returns the wall-clock time and advances during transactions.  For
> +    historical reasons <function>timeofday()</function> returns a
> +    <type>text</type> string rather than a <type>timestamp</type>
> +    value:
> +<screen>
> +SELECT timeofday();
> +<lineannotation>Result: </lineannotation><computeroutput>Sat Feb 17  
> 19:07:32.000126 2001 EST</computeroutput>
> +</screen>
> +   </para>
> +
> +   <para>
>       All the date/time data types also accept the special literal value
>       <literal>now</literal> to specify the current date and time.   
> Thus,
>       the following three all return the same result:
> 
> 
> ---------------------------(end of broadcast)---------------------------
> TIP 4: Don't 'kill -9' the postmaster
> 
> 
> Karl <kop@meme.com>
> Free Software:  "You don't pay back, you pay forward."
>                   -- Robert A. Heinlein
> 
> 
> ---------------------------(end of broadcast)---------------------------
> TIP 7: don't forget to increase your free space map settings
> 

-- 
  Bruce Momjian                        |  http://candle.pha.pa.us
  pgman@candle.pha.pa.us               |  (610) 359-1001
  +  If your life is a hard drive,     |  13 Roberts Road
  +  Christ can be your backup.        |  Newtown Square, Pennsylvania 19073



^ permalink  raw  reply  [nested|flat] 8+ messages in thread


end of thread, other threads:[~2005-06-29 01:53 UTC | newest]

Thread overview: 8+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2005-06-27 23:30 Performance analysis of plpgsql code Karl O. Pinc <kop@meme.com>
2005-06-27 23:33 ` Michael Fuhr <mike@fuhr.org>
2005-06-28 01:54   ` Karl O. Pinc <kop@meme.com>
2005-06-28 01:15     ` Michael Glaesemann <grzm@myrealbox.com>
2005-06-28 01:34     ` Michael Fuhr <mike@fuhr.org>
2005-06-28 03:03       ` Karl O. Pinc <kop@meme.com>
2005-06-28 02:49         ` Michael Fuhr <mike@fuhr.org>
2005-06-29 01:53 Re: Fwd: Re: [PERFORM] Performance analysis of plpgsql code Bruce Momjian <pgman@candle.pha.pa.us>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox