Date: Sun, 8 May 2022 22:02:22 +0000
From: David Fetter <david@fetter.org>
To: Justin Pryzby <pryzby@telsasoft.com>
Cc: pgsql-hackers@postgresql.org
Subject: Re: Finer grain log timestamps
Message-ID: <20220508220222.GD11333@fetter.org>
References: <20220508204451.GC11333@fetter.org>
 <20220508211227.GP28830@telsasoft.com>
MIME-Version: 1.0
Content-Type: multipart/mixed; boundary="oC1+HKm2/end4ao3"
Content-Disposition: inline
In-Reply-To: <20220508211227.GP28830@telsasoft.com>
User-Agent: Mutt/1.9.4 (2018-02-28)
Archived-At: 
 <https://www.postgresql.org/message-id/20220508220222.GD11333%40fetter.org>
Precedence: bulk


--oC1+HKm2/end4ao3
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline

On Sun, May 08, 2022 at 04:12:27PM -0500, Justin Pryzby wrote:
> On Sun, May 08, 2022 at 08:44:51PM +0000, David Fetter wrote:
> >  CREATE TABLE postgres_log
> >  (
> > -  log_time timestamp(3) with time zone,
> > +  log_time timestamp(6) with time zone,
> 
> Please also update the corresponding thing in doc/src/sgml/file-fdw.sgml

Thanks for looking this over, and please find attached the next
version.

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

--oC1+HKm2/end4ao3
Content-Type: text/x-diff; charset=us-ascii
Content-Disposition: attachment;
 filename="v2-0001-Change-log-timestamps-from-milli-to-microseconds.patch"

From f6772fc0378879fd5c7fbf8cb320ee68f66341d2 Mon Sep 17 00:00:00 2001
From: David Fetter <david@fetter.org>
Date: Sun, 8 May 2022 13:24:33 -0700
Subject: [PATCH v2] 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 03986946a8..f00db09547 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..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];
 
 	/* 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(msbuf, ".%06d", saved_timeval.tv_usec );
+	memcpy(formatted_log_time + 19, msbuf, 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.35.1


--oC1+HKm2/end4ao3--