Thread: Timestamps Look Incorrect?

I think I have a stored procedure that is running longer than it should, and
am trying to time how long each section of a stored procedure is taking the
most time. I have used localtimestamp, now(), and
to_char(localtimestamp,'HH24:MI:SS.US') to display current time at different
points in the stored procedure; even though I have requested microseconds,
all of the results being returned are all the same: the time that is shown
on the very first  RAISE NOTICE is exactly the same as the last one, even
though I stored the time into different variables.

Sample of statements being used to capture and display time:
select into current_date_time to_char(localtimestamp,'HH24:MI:SS.US');
RAISE NOTICE 'Beginning at    %',current_date_time;
    :
select into current_date_time10 to_char(localtimestamp,'HH24:MI:SS.US');
RAISE NOTICE 'LINK TYPE(5)    %',current_date_time10;

Results I am getting:
NOTICE:  Beginning at    05:59:51.462000
NOTICE:  End SECTION 1   05:59:51.462000
NOTICE:  End SECTION 2   05:59:51.462000
NOTICE:  End SECTION 3   05:59:51.462000
NOTICE:  COMPUTE BYTES(4) 05:59:51.462000
NOTICE:  PERCENTAGES(4)  05:59:51.462000
NOTICE:  ISNET(4)        05:59:51.462000
NOTICE:  NEIGHBOR CHG(4)  05:59:51.462000
NOTICE:  INTERFACE(5)    05:59:51.462000
NOTICE:  REMOTE SITE(5)  05:59:51.462000
NOTICE:  LINK TYPE(5)    05:59:51.462000
Query returned successfully: 1 rows affected, 250 ms execution time.

It almost looks like the system's time is not polled every time a request is
made for time.

Is there another way to do this?

Other than for current uses, not getting a correct timestamp is important to
my application as well.

I am running version 8.0.1 on Windows 2003.

"Lane Van Ingen" <lvaningen@esncc.com> writes:
> I have used localtimestamp, now(), and
> to_char(localtimestamp,'HH24:MI:SS.US') to display current time at different
> points in the stored procedure; even though I have requested microseconds,
> all of the results being returned are all the same: the time that is shown
> on the very first  RAISE NOTICE is exactly the same as the last one, even
> though I stored the time into different variables.

That's what it's supposed to do.  Please read the documentation:
http://www.postgresql.org/docs/8.0/static/functions-datetime.html#FUNCTIONS-DATETIME-CURRENT
You need to use timeofday() if you want to measure intra-transaction
intervals.

            regards, tom lane

On Sep 29, 2005, at 5:12 , Lane Van Ingen wrote:

> select into current_date_time10 to_char
> (localtimestamp,'HH24:MI:SS.US');
> RAISE NOTICE 'LINK TYPE(5)    %',current_date_time10;

<snip />

> It almost looks like the system's time is not polled every time a
> request is
> made for time.
>
> Is there another way to do this?


I suggest you read the documentation on date/time functions, in
particular:
http://www.postgresql.org/docs/current/static/functions-
datetime.html#FUNCTIONS-DATETIME-CURRENT

I think you'll find what you're looking for.

Michael Glaesemann
grzm myrealbox com