Date: Mon, 13 Jun 2022 07:03:27 +0000
From: David Fetter <david@fetter.org>
To: Dagfinn Ilmari =?iso-8859-1?Q?Manns=E5ker?= <ilmari@ilmari.org>
Cc: Justin Pryzby <pryzby@telsasoft.com>, pgsql-hackers@postgresql.org
Subject: Re: Finer grain log timestamps
Message-ID: <20220613070327.GC12494@fetter.org>
References: <20220508204451.GC11333@fetter.org>
 <20220508211227.GP28830@telsasoft.com>
 <20220508220222.GD11333@fetter.org>
 <875ymfnh09.fsf@wibble.ilmari.org>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="5/uDoXvLw7AC5HRs"
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
In-Reply-To: <875ymfnh09.fsf@wibble.ilmari.org>
User-Agent: Mutt/1.9.4 (2018-02-28)
Archived-At: 
 <https://www.postgresql.org/message-id/20220613070327.GC12494%40fetter.org>
Precedence: bulk


--5/uDoXvLw7AC5HRs
Content-Type: text/plain; charset=iso-8859-1
Content-Disposition: inline
Content-Transfer-Encoding: 8bit

On Mon, May 09, 2022 at 11:21:26AM +0100, Dagfinn Ilmari Mannsåker wrote:
> David Fetter <david@fetter.org> writes:
> 
> > diff --git src/backend/utils/error/elog.c src/backend/utils/error/elog.c
> > index 55ee5423af..4698e32ab7 100644
> > --- src/backend/utils/error/elog.c
> > +++ src/backend/utils/error/elog.c
> > @@ -2295,7 +2295,7 @@ char *
> >  get_formatted_log_time(void)
> >  {
> >  	pg_time_t	stamp_time;
> > -	char		msbuf[13];
> > +	char		msbuf[16];
> 
> Now that it holds microseconds (µs), not milliseconds (ms), should it
> not be renamed to `usbuf`?

Good point.

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

--5/uDoXvLw7AC5HRs
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
 filename="v3-0001-Change-log-timestamps-from-milli-to-microseconds.patch"

From 9283d9ae4d8d10876aee1da0753e7db4257e7a11 Mon Sep 17 00:00:00 2001
From: David Fetter <david@fetter.org>
Date: Mon, 13 Jun 2022 00:01:04 -0700
Subject: [PATCH v3] Change log timestamps from milli- to microseconds

---
 doc/src/sgml/config.sgml       | 12 ++++++------
 doc/src/sgml/file-fdw.sgml     |  2 +-
 src/backend/utils/error/elog.c | 14 +++++++-------
 3 files changed, 14 insertions(+), 14 deletions(-)

diff --git doc/src/sgml/config.sgml doc/src/sgml/config.sgml
index 5b7ce6531d..adc4fc090a 100644
--- doc/src/sgml/config.sgml
+++ doc/src/sgml/config.sgml
@@ -7174,17 +7174,17 @@ local0.*    /var/log/postgresql
             </row>
             <row>
              <entry><literal>%t</literal></entry>
-             <entry>Time stamp without milliseconds</entry>
+             <entry>Time stamp at second resolution</entry>
              <entry>no</entry>
             </row>
             <row>
              <entry><literal>%m</literal></entry>
-             <entry>Time stamp with milliseconds</entry>
+             <entry>Time stamp with microseconds</entry>
              <entry>no</entry>
             </row>
             <row>
              <entry><literal>%n</literal></entry>
-             <entry>Time stamp with milliseconds (as a Unix epoch)</entry>
+             <entry>Time stamp with microseconds (as a Unix epoch)</entry>
              <entry>no</entry>
             </row>
             <row>
@@ -7526,7 +7526,7 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
         This option emits log lines in comma-separated-values
         (<acronym>CSV</acronym>) format,
         with these columns:
-        time stamp with milliseconds,
+        time stamp with microseconds,
         user name,
         database name,
         process ID,
@@ -7557,7 +7557,7 @@ log_line_prefix = '%m [%p] %q%u@%d/%a '
 <programlisting>
 CREATE TABLE postgres_log
 (
-  log_time timestamp(3) with time zone,
+  log_time timestamp(6) with time zone,
   user_name text,
   database_name text,
   process_id integer,
@@ -7682,7 +7682,7 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
         <row>
          <entry><literal>timestamp</literal></entry>
          <entry>string</entry>
-         <entry>Time stamp with milliseconds</entry>
+         <entry>Time stamp with microseconds</entry>
         </row>
         <row>
          <entry><literal>user</literal></entry>
diff --git doc/src/sgml/file-fdw.sgml doc/src/sgml/file-fdw.sgml
index 5b98782064..c3efcbd679 100644
--- doc/src/sgml/file-fdw.sgml
+++ doc/src/sgml/file-fdw.sgml
@@ -242,7 +242,7 @@ CREATE SERVER pglog FOREIGN DATA WRAPPER file_fdw;
 
 <programlisting>
 CREATE FOREIGN TABLE pglog (
-  log_time timestamp(3) with time zone,
+  log_time timestamp(6) with time zone,
   user_name text,
   database_name text,
   process_id integer,
diff --git src/backend/utils/error/elog.c src/backend/utils/error/elog.c
index 55ee5423af..1ee49ce2be 100644
--- src/backend/utils/error/elog.c
+++ src/backend/utils/error/elog.c
@@ -2295,7 +2295,7 @@ char *
 get_formatted_log_time(void)
 {
 	pg_time_t	stamp_time;
-	char		msbuf[13];
+	char		usbuf[16];
 
 	/* leave if already computed */
 	if (formatted_log_time[0] != '\0')
@@ -2315,13 +2315,13 @@ get_formatted_log_time(void)
 	 * nonempty or CSV mode can be selected.
 	 */
 	pg_strftime(formatted_log_time, FORMATTED_TS_LEN,
-	/* leave room for milliseconds... */
-				"%Y-%m-%d %H:%M:%S     %Z",
+	/* leave room for microseconds... */
+				"%Y-%m-%d %H:%M:%S        %Z",
 				pg_localtime(&stamp_time, log_timezone));
 
 	/* 'paste' milliseconds into place... */
-	sprintf(msbuf, ".%03d", (int) (saved_timeval.tv_usec / 1000));
-	memcpy(formatted_log_time + 19, msbuf, 4);
+	sprintf(usbuf, ".%06d", saved_timeval.tv_usec );
+	memcpy(formatted_log_time + 19, usbuf, 7);
 
 	return formatted_log_time;
 }
@@ -2652,9 +2652,9 @@ log_line_prefix(StringInfo buf, ErrorData *edata)
 						saved_timeval_set = true;
 					}
 
-					snprintf(strfbuf, sizeof(strfbuf), "%ld.%03d",
+					snprintf(strfbuf, sizeof(strfbuf), "%ld.%06d",
 							 (long) saved_timeval.tv_sec,
-							 (int) (saved_timeval.tv_usec / 1000));
+							 saved_timeval.tv_usec);
 
 					if (padding != 0)
 						appendStringInfo(buf, "%*s", padding, strfbuf);
-- 
2.36.1


--5/uDoXvLw7AC5HRs--