Re: [GENERAL] microsecond log timestamps - Mailing list pgsql-patches

Tom Lane wrote:
>
> Ed Loehr <eloehr@austin.rr.com> writes:
> > Someone probably had a good reason for doing this, but looking at
> > backend/utils/error/elog.c line 592 in 7.1, it looks like the pre-7.1
> > capability for microsecond timestamp granularity (e.g.,
> > 20010511.14:23:49.325) in tprintf_timestamp() was removed in favor of a
> > coarser 1-second resolution using time_t in print_timestamp()?  Is that
> > correct?  If not, what am I missing?
>
> > If so, is anyone aware of an existing patch to give sub-second log
> > timestamp capability?  Microsecond granularity has been very helpful for
> > query timing.
>
> I can't see any good reason that print_timestamp() shouldn't use
> gettimeofday() rather than time(); certainly there's no portability
> argument for it, because we use gettimeofday in several other places.
>
> Feel free to submit a patch...

The attached patch restores pre-7.1 millisecond-granularity log
timestamps (except that it also adds a 4-digit year, which was not in
pre-7.1).  It is meant to be applied to
postgresql-7.1/src/backend/utils/error/elog.c.

Regards,
Ed Loehr*** /usr/src/postgresql-7.1/src/backend/utils/error/elog.c.dist    Fri May 11 17:42:28 2001
--- /usr/src/postgresql-7.1/src/backend/utils/error/elog.c    Sun May 13 00:45:53 2001
***************
*** 65,71 ****
  bool        Log_timestamp;
  bool        Log_pid;

! #define TIMESTAMP_SIZE 20        /* format `YYYY-MM-DD HH:MM:SS ' */
  #define PID_SIZE 9                /* format `[123456] ' */

  static const char *print_timestamp(void);
--- 65,71 ----
  bool        Log_timestamp;
  bool        Log_pid;

! #define TIMESTAMP_SIZE 22     /* format `YYYYMMDD.HH:MM:SS.sss ' */
  #define PID_SIZE 9                /* format `[123456] ' */

  static const char *print_timestamp(void);
***************
*** 575,599 ****


  /*
!  * Return a timestamp string like
!  *
!  *     "2000-06-04 13:12:03 "
   */
  static const char *
  print_timestamp(void)
  {
!     time_t        curtime;
!     static char buf[TIMESTAMP_SIZE + 1];
!
!     curtime = time(NULL);

!     strftime(buf, sizeof(buf),
!              "%Y-%m-%d %H:%M:%S ",
!              localtime(&curtime));
!
!     return buf;
  }
-


  /*
--- 575,602 ----


  /*
!  * Return a timestamp string like "20010119.17:25:59.902 "
   */
  static const char *
  print_timestamp(void)
  {
!     struct timeval  tv;
!     struct timezone tz = {0, 0};
!     struct tm      *time;
!     time_t          tm;
!     static char     timestamp[TIMESTAMP_SIZE + 1];
!
!     gettimeofday(&tv, &tz);
!     tm = tv.tv_sec;
!     time = localtime(&tm);
!
!     sprintf(timestamp, "%4d%02d%02d.%02d:%02d:%02d.%03d ",
!             time->tm_year + 1900, time->tm_mon + 1, time->tm_mday,
!             time->tm_hour, time->tm_min, time->tm_sec,
!             (int) (tv.tv_usec / 1000));

!     return timestamp;
  }


  /*