Re: pgbench logging broken by time logic changes

On Wed, 16 Jun 2021 21:11:41 +0200 (CEST)
Fabien COELHO <coelho(at)cri(dot)ensmp(dot)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(at)sraoss(dot)co(dot)jp>