Re: Finer grain log timestamps

On Mon, Jun 13, 2022 at 04:22:42PM -0400, Tom Lane wrote:
> Robert Haas <robertmhaas(at)gmail(dot)com> writes:
> > On Sun, May 8, 2022 at 4:45 PM David Fetter <david(at)fetter(dot)org> wrote:
> >> Please find attached a patch to change the sub-second granularity of
> >> log timestamps from milliseconds to microseconds.
>
> > Why is this a good idea?
>
> I can imagine that some people would have a use for microsecond
> resolution in log files, and I can also imagine that as machines
> get faster more people will want that.

Your imagination matches situations I've seen in production where
there was some ambiguity as to what happened when inside a millisecond
boundary, and I'm sure I'm not alone in this. I've gotten this
request from at least three people who to my knowledge knew nothing
about each other, and as I recall, the first time someone brought it
up to me was over five years back.

> As against that, this will bloat log files by a non-microscopic
> amount, and it's pretty likely to break some log-scanning tools too.

Three bytes per line, and log-scanning parsers that finicky are
already breaking all the time, respectively.

> It's unclear to me that that's a tradeoff we should force on
> everyone.

The tradeoff we're forcing on people at the moment is a loss of
precision they didn't ask for, implemented by some extra instructions
they didn't ask us to execute in a part of the code that's a hot path
at exactly the times when the machine is busiest.

> I think a proposal less likely to have push-back would be to invent
> a different log_line_prefix %-escape to produce microseconds.
> Sadly, "%u" is already taken, but perhaps we could use "%U"?
>
> A different line of thought is to extend %t to provide a precision
> field a la sprintf, so that for example "%.3t" is equivalent to
> "%m" and "%.6t" does what David wants, and we won't have to
> search for a new escape letter when the day arrives that
> somebody wants nanosecond resolution. The same could be done
> with %n, avoiding the need to find a different escape letter
> for that.

I'll build this more sprintf-like thing if not doing so prevents the
change from happening, but frankly, I don't really see a point in it
because the next "log timestamps at some random negative power of 10
second granularity" requirement I see will be the first.

Best,
David.
--
David Fetter <david(at)fetter(dot)org> http://fetter.org/
Phone: +1 415 235 3778

Remember to vote!
Consider donating to Postgres: http://www.postgresql.org/about/donate