Re: pgbench logging broken by time logic changes

On Wed, 16 Jun 2021 21:11:41 +0200 (CEST)
Fabien COELHO <coelho@cri.ensmp.fr> wrote:

> 
> > pg_time_now(). This uses INSTR_TIME_SET_CURRENT in it, but this macro
> > can call clock_gettime(CLOCK_MONOTONIC[_RAW], ) instead of gettimeofday
> > or clock_gettime(CLOCK_REALTIME, ). When CLOCK_MONOTONIC[_RAW] is used,
> > clock_gettime doesn't return epoch time. Therefore, we can use
> > INSTR_TIME_SET_CURRENT aiming to calculate a duration, but we should
> > not have used this to get the current timestamp.
> >
> > I think we can fix this issue by using gettimeofday for logging as before
> > this was changed. I attached the patch.
> 
> I cannot say that I'm thrilled by having multiple tv stuff back in several 
> place. I can be okay with one, though. What about the attached? Does it 
> make sense?

At first, I also thought of fixing pg_time_now() to use gettimeofday() instead
of INSTR_TIME_SET_CURRENT, but I noticed that using INSTR_TIME_SET_CURRENT is
proper to measure time interval.  I mean, this macro uses
lock_gettime(CLOCK_MONOTONIC, ) if avilable, which give reliable interval
timing even in the face of changes to the system clock due to NTP.

The commit 547f04e7 changed all of INSTR_TIME_SET_CURRENT, gettimeofday(), and
time() to pg_now_time() which calls INSTR_TIME_SET_CURRENT in it. So, my patch
intented to revert these changes only about gettimeofday() and time(), and remain
changes about INSTR_TIME_SET_CURRENT.

I attached the updated patch because I forgot to revert pg_now_time() to time(NULL).

Another idea to fix is adding 'use_epoch' flag to pg_now_time() like below, 

 pg_time_now(bool use_epoch)
 {
     if (use_epoch)
      {
        struct timeval tv;
        gettimeofday(&tv, NULL);
        return tv.tv_sec * 1000000 + tv.tv_usec;
       }
     else
       {
         instr_time      now;
         INSTR_TIME_SET_CURRENT(now);
         return (pg_time_usec_t) INSTR_TIME_GET_MICROSEC(now);
       }
 }

or making an additional function that returns epoch time.


By the way, there is another advantage of using clock_gettime(). That is, this
returns precise results in nanoseconds. However, we can not benefit from it because
pg_time_now() converts the value to uint64 by using INSTR_TIME_GET_MICROSEC. So,
if we would like more precious statistics in pgbench, it might be better to use
INSTR_TIME_GET_MICROSEC instead of pg_time_now in other places.

Regards,
Yugo Nagata

-- 
Yugo NAGATA <nagata@sraoss.co.jp>