Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1nnnm5-0000sR-1b for pgsql-hackers@arkaria.postgresql.org; Sun, 08 May 2022 20:45:05 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1nnnm2-0004Mg-52 for pgsql-hackers@arkaria.postgresql.org; Sun, 08 May 2022 20:45:02 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1nnnm1-0004MF-HG for pgsql-hackers@lists.postgresql.org; Sun, 08 May 2022 20:45:01 +0000 Received: from xvm-110-146.dc2.ghst.net ([46.226.110.146] helo=fetter.org) by magus.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1nnnlu-0004BA-Dp for pgsql-hackers@postgresql.org; Sun, 08 May 2022 20:45:00 +0000 Received: by fetter.org (Postfix, from userid 1001) id 8468E4186E; Sun, 8 May 2022 22:44:52 +0200 (CEST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=fetter.org; s=default; t=1652042692; bh=Mze5jfUf2Vgfn0qQzLnN1lTYcW+x4h5riMjI2UdXyc4=; h=Date:From:To:Subject:From; b=gThpW98nE3haZOkh/dO9/OfqqXN6NQRthsEWbz7o7/LPC11ISVbR7Wza+MCHU3+Nr 6Eh1sltxJ/w2eTaxlTQNg6TUZqwNDcELhqtFwnojEyT7ajWz7+BySVF3hLC82papfm TiacGBkxJzx6ODDDj3olX25kuJKIfFkh3xibtQJBLeZQ+nXNucwS7tW45NYT9DCqlg hiT6B+q8ANT0XAmER6Q5iCr49pheia1Gevkw7VfKyKYj2j0syKbaGGCaYZcg8uZ4ff Hd/6tYu3jMFZUw5WG6GNvoHywXTRqnbUnMGKG3UFrbWxeG1VxTOcMocyAHQQC92qOq cWoSz9n7dE+dQ== Date: Sun, 8 May 2022 20:44:51 +0000 From: David Fetter To: PostgreSQL Development Subject: Finer grain log timestamps Message-ID: <20220508204451.GC11333@fetter.org> MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="TB36FDmn/VVEgNH/" Content-Disposition: inline User-Agent: Mutt/1.9.4 (2018-02-28) List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk --TB36FDmn/VVEgNH/ Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Folks, Please find attached a patch to change the sub-second granularity of log timestamps from milliseconds to microseconds. I started out working on a longer patch that will give people more choices than whole seconds and microseconds, but there were a lot of odd corner cases, including what I believe might have been a requirement for C11, should be wish to get sub-microsecond granularity. Best, David. -- David Fetter http://fetter.org/ Phone: +1 415 235 3778 Remember to vote! Consider donating to Postgres: http://www.postgresql.org/about/donate --TB36FDmn/VVEgNH/ Content-Type: text/x-diff; charset=us-ascii Content-Disposition: attachment; filename="v1-0001-Change-log-timestamps-from-milli-to-microseconds.patch" From f4881d1669526597bdf608c7c59858f88314f8d1 Mon Sep 17 00:00:00 2001 From: David Fetter Date: Sun, 8 May 2022 13:24:33 -0700 Subject: [PATCH v1] Change log timestamps from milli- to microseconds --- doc/src/sgml/config.sgml | 12 ++++++------ src/backend/utils/error/elog.c | 14 +++++++------- 2 files changed, 13 insertions(+), 13 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 %t - Time stamp without milliseconds + Time stamp at second resolution no %m - Time stamp with milliseconds + Time stamp with microseconds no %n - Time stamp with milliseconds (as a Unix epoch) + Time stamp with microseconds (as a Unix epoch) no @@ -7526,7 +7526,7 @@ log_line_prefix = '%m [%p] %q%u@%d/%a ' This option emits log lines in comma-separated-values (CSV) 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 ' 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; timestamp string - Time stamp with milliseconds + Time stamp with microseconds user 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 --TB36FDmn/VVEgNH/--