Thread: Performance analysis of plpgsql code
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
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/
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
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
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/
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:
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/