Thread: Measuring execution time for sql called from PL/pgSQL

Hi,

I've got very slow insert performance on some
table which has trigger based on complex PL/pgSQL function.
Apparently insert is slow due some slow sql inside that function,
since CPU load is very high and disk usage is low during insert.
I run Red Hat 9
Anthlon 2.6
1GB ram
Fast IDE Disk

Setting following in postgres.conf apparently doesn't help:
log_statement = true
log_duration = true
since it logs only sql issued by client. It logs only once
per session the sql text but during call to the PL/pgSQL function,
but of course no duration.

Due the complexity of PL/pgSQL function trying to step by step
see the execution plans is very time consuming.

Q1) Is there any way to see which statements are called for PL/pgSQL
and their duration?

I've tried to measure the duration of sql with printing out
"localtimestamp"  but for some reason during the same pg/plsql call it
returns the same
value:

Example:
Following gets and prints out the localtimestamp value in the loop
create or replace function foobar()
  returns integer as '
  declare
    v timestamp;
  begin
    loop
    select localtimestamp into v;
    raise notice ''Timestamp: %'', v;
    end loop;
    return null;
  end; ' language 'plpgsql'
;

and as result of "select foobar();"

i constantly get the same value:
NOTICE:  Timestamp: 2003-12-12 01:51:35.768053
NOTICE:  Timestamp: 2003-12-12 01:51:35.768053
NOTICE:  Timestamp: 2003-12-12 01:51:35.768053
NOTICE:  Timestamp: 2003-12-12 01:51:35.768053
NOTICE:  Timestamp: 2003-12-12 01:51:35.768053

Q2) what i do wrong here and what is the "Proper Way" to measure
execution time of sql called inside PG/plSQL.

Thanks in advance

WBR
--
Aram

Dnia 2003-12-12 02:17, Użytkownik Aram Kananov napisał:
>     select localtimestamp into v;
>     raise notice ''Timestamp: %'', v;

Don't use localtimestamp, now() neither any transaction based time
function. They all return the same value among whole transaction. The
only time function, which can be used for performance tests is timeofday().

You can read more about time functions in manual.

Regards,
Tomasz Myrta

> I've tried to measure the duration of sql with printing out
> "localtimestamp"  but for some reason during the same pg/plsql call
> it returns the same value:

Aram,

From http://www.postgresql.org/docs/current/static/functions-datetime.html:

There is also the function timeofday(), which for historical reasons returns
a text string rather than a timestamp value:

SELECT timeofday();
 Result: Sat Feb 17 19:07:32.000126 2001 EST

It is important to know that CURRENT_TIMESTAMP and related functions return
the start time of the current transaction; their values do not change during
the transaction. This is considered a feature: the intent is to allow a
single transaction to have a consistent notion of the "current" time, so that
multiple modifications within the same transaction bear the same time stamp.
timeofday() returns the wall-clock time and does advance during transactions.

-David