Re: pgbench logging broken by time logic changes

Hello Yugo-san,

>>> 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.

Ok, I was thinking that it was possible that there was this kind of
implication. Now, does it matter that much if a few transactions are
skewed by NTP from time to time? Having to deal with different time
functions in the same file seems painful.

> 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.

Hmmm.

> 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.

Yes, but when to call which version? How to avoid confusion? After giving
it some thoughts, ISTM that the best short-term decision is just to have
epoch everywhere, i.e. having now() to rely on gettimeofday, because:

- at least one user is unhappy with not having epoch in the log file,
and indeed it makes sense to be unhappy about that if they want to
correlated logs. So I agree to undo that, or provide an option to undo
it.

- having different times with different origins at different point in
the code makes it really hard to understand and maintain, and if we
trade maintainability for precision it should really be worth it, and
I'm not sure that working around NTP adjustment is worth it right now.

In the not so short term, I'd say that the best approach would be use
relative time internally and just to offset these with a global epoch
start time when displaying a timestamp.

> 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.

The INSTR_TIME macros are pretty ugly and inefficient, especially when
time arithmetic is involved because they re-implements 64 bits operations
based on 32 bit ints. I really wanted to get rid of that as much as
possible. From a database benchmarking perspective ISTM that µs is the
right smallest unit, given that a transaction implies significant delays
such as networks communications, parsing, and so on. So I do not think we
should ever need nanos.

In conclusion, ISTM that it is enough to simply change now to call
gettimeofday to fix the issue raised by Greg. This is patch v1 on the
thread.

--
Fabien.