Date: Tue, 14 Jun 2022 00:05:45 +0000
From: David Fetter <david@fetter.org>
To: Tom Lane <tgl@sss.pgh.pa.us>
Cc: Robert Haas <robertmhaas@gmail.com>,
	PostgreSQL Development <pgsql-hackers@postgresql.org>
Subject: Re: Finer grain log timestamps
Message-ID: <20220614000545.GE12494@fetter.org>
References: <20220508204451.GC11333@fetter.org>
 <CA+TgmoYx_2v3wGzqWWNuC05bDOYyHubODfFUoj8nrvSajRjCYA@mail.gmail.com>
 <3920623.1655151762@sss.pgh.pa.us>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <3920623.1655151762@sss.pgh.pa.us>
User-Agent: Mutt/1.9.4 (2018-02-28)
Archived-At: 
 <https://www.postgresql.org/message-id/20220614000545.GE12494%40fetter.org>
Precedence: bulk

On Mon, Jun 13, 2022 at 04:22:42PM -0400, Tom Lane wrote:
> Robert Haas <robertmhaas@gmail.com> writes:
> > On Sun, May 8, 2022 at 4:45 PM David Fetter <david@fetter.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