microsecond log timestamps

Started by Ed Loehralmost 25 years ago9 messagesgeneral
Jump to latest
#1Ed Loehr
eloehr@austin.rr.com

Someone probably had a good reason for doing this, but looking at
backend/utils/error/elog.c line 592 in 7.1, it looks like the pre-7.1
capability for microsecond timestamp granularity (e.g.,
20010511.14:23:49.325) in tprintf_timestamp() was removed in favor of a
coarser 1-second resolution using time_t in print_timestamp()? Is that
correct? If not, what am I missing?

If so, is anyone aware of an existing patch to give sub-second log
timestamp capability? Microsecond granularity has been very helpful for
query timing.

Regards,
Ed Loehr

#2Ed Loehr
eloehr@austin.rr.com
In reply to: Ed Loehr (#1)
Re: microsecond log timestamps

If so, is anyone aware of an existing patch to give sub-second log
timestamp capability?

I guess one could just substitute the old tprintf_timestamp() from
pre-7.1. code...

Regards,
Ed Loehr

#3Tom Lane
tgl@sss.pgh.pa.us
In reply to: Ed Loehr (#1)
Re: microsecond log timestamps

Ed Loehr <eloehr@austin.rr.com> writes:

Someone probably had a good reason for doing this, but looking at
backend/utils/error/elog.c line 592 in 7.1, it looks like the pre-7.1
capability for microsecond timestamp granularity (e.g.,
20010511.14:23:49.325) in tprintf_timestamp() was removed in favor of a
coarser 1-second resolution using time_t in print_timestamp()? Is that
correct? If not, what am I missing?

If so, is anyone aware of an existing patch to give sub-second log
timestamp capability? Microsecond granularity has been very helpful for
query timing.

I can't see any good reason that print_timestamp() shouldn't use
gettimeofday() rather than time(); certainly there's no portability
argument for it, because we use gettimeofday in several other places.

Feel free to submit a patch...

regards, tom lane

#4Ed Loehr
eloehr@austin.rr.com
In reply to: Ed Loehr (#1)
Re: microsecond log timestamps

Tom Lane wrote:

Ed Loehr <eloehr@austin.rr.com> writes:

Someone probably had a good reason for doing this, but looking at
backend/utils/error/elog.c line 592 in 7.1, it looks like the pre-7.1
capability for microsecond timestamp granularity (e.g.,
20010511.14:23:49.325) in tprintf_timestamp() was removed in favor of a
coarser 1-second resolution using time_t in print_timestamp()? Is that
correct? If not, what am I missing?

If so, is anyone aware of an existing patch to give sub-second log
timestamp capability? Microsecond granularity has been very helpful for
query timing.

I can't see any good reason that print_timestamp() shouldn't use
gettimeofday() rather than time(); certainly there's no portability
argument for it, because we use gettimeofday in several other places.

Feel free to submit a patch...

The attached patch restores pre-7.1 millisecond-granularity log
timestamps (except that it also adds a 4-digit year, which was not in
pre-7.1). It is meant to be applied to
postgresql-7.1/src/backend/utils/error/elog.c.

Regards,
Ed Loehr

Attachments:

elog.c.patch-7.1text/plain; charset=us-ascii; name=elog.c.patch-7.1Download+30-31
#5Peter Eisentraut
peter_e@gmx.net
In reply to: Ed Loehr (#4)
Re: [PATCHES] Re: microsecond log timestamps

Ed Loehr writes:

The attached patch restores pre-7.1 millisecond-granularity log
timestamps (except that it also adds a 4-digit year, which was not in
pre-7.1). It is meant to be applied to
postgresql-7.1/src/backend/utils/error/elog.c.

I am opposed to the unreadable, non-standard timestamp format. I also
don't see the point of microsecond granularity. There are much better
ways to time a query. (Or at least we could provide some.)

--
Peter Eisentraut peter_e@gmx.net http://funkturm.homeip.net/~peter

#6Vince Vielhaber
vev@michvhf.com
In reply to: Peter Eisentraut (#5)
Re: [PATCHES] Re: microsecond log timestamps

On Sun, 13 May 2001, Peter Eisentraut wrote:

Ed Loehr writes:

The attached patch restores pre-7.1 millisecond-granularity log
timestamps (except that it also adds a 4-digit year, which was not in
pre-7.1). It is meant to be applied to
postgresql-7.1/src/backend/utils/error/elog.c.

I am opposed to the unreadable, non-standard timestamp format. I also
don't see the point of microsecond granularity. There are much better
ways to time a query. (Or at least we could provide some.)

How about using the TAI format? http://cr.yp.to/libtai/tai64.html

Vince.
--
==========================================================================
Vince Vielhaber -- KA8CSH email: vev@michvhf.com http://www.pop4.net
56K Nationwide Dialup from $16.00/mo at Pop4 Networking
Online Campground Directory http://www.camping-usa.com
Online Giftshop Superstore http://www.cloudninegifts.com
==========================================================================

#7Tom Lane
tgl@sss.pgh.pa.us
In reply to: Peter Eisentraut (#5)
Re: [PATCHES] Re: microsecond log timestamps

Peter Eisentraut <peter_e@gmx.net> writes:

I am opposed to the unreadable, non-standard timestamp format.

I didn't see the point of Ed's arbitrary change in YMD format, but
what's wrong with adding fractional seconds? Our own timestamp code
is willing to format fractional seconds, so we can hardly call it
nonstandard.

I also don't see the point of microsecond granularity.

What Ed implemented (which is what was in 7.0 and before) is millisecond
resolution, which does seem worthwhile; certainly one-second resolution
is pretty coarse on some machines these days.

I was thinking of keeping the YMD display format the same but otherwise
adopting the patch.

regards, tom lane

#8Ed Loehr
eloehr@austin.rr.com
In reply to: Peter Eisentraut (#5)
Re: [PATCHES] Re: microsecond log timestamps

Tom Lane wrote:

Peter Eisentraut <peter_e@gmx.net> writes:

I am opposed to the unreadable, non-standard timestamp format.

I didn't see the point of Ed's arbitrary change in YMD format, but
what's wrong with adding fractional seconds? Our own timestamp code
is willing to format fractional seconds, so we can hardly call it
nonstandard.

Out of respect to existing log-processing programs, I tried to adhere to
the pgsql traditional (pre-7.1) format, except that I'd added a 4-digit
year I'd been patching since 6.5.2, which probably ended up breaking them
anyway.

I also don't see the point of microsecond granularity.

What Ed implemented (which is what was in 7.0 and before) is millisecond
resolution, which does seem worthwhile; certainly one-second resolution
is pretty coarse on some machines these days.

Yes, microsecond was a typo. I meant milliseconds.

I was thinking of keeping the YMD display format the same but otherwise
adopting the patch.

That'd be an improvement. Unfortunately, the ISO 8601 standard is not
much more readable:

2001-05-13T10:19:44,085-05:00

That's a literal 'T' designating the time portion and a comma separating
seconds and milliseconds (http://www.iso.ch/markete/8601.pdf).

Regards,
Ed Loehr

#9Thomas Lockhart
lockhart@alumni.caltech.edu
In reply to: Peter Eisentraut (#5)
Re: [PATCHES] Re: microsecond log timestamps

That'd be an improvement. Unfortunately, the ISO 8601 standard is not
much more readable:
2001-05-13T10:19:44,085-05:00
That's a literal 'T' designating the time portion and a comma separating
seconds and milliseconds (http://www.iso.ch/markete/8601.pdf).

No disagreement here, but f-y'all-i the standard says that the 'T' is
allowed to be omitted if acceptable to both parties handling the data.

- Thomas