Re: pgbench logging broken by time logic changes

On Wed, Jun 30, 2021 at 9:55 PM Fabien COELHO <coelho(at)cri(dot)ensmp(dot)fr> wrote:
> >> Fabien, thanks for the updated patch, I'm looking at it.
>
> After looking at it again, here is an update which ensure 64 bits on
> epoch_shift computation.

Hi Fabien,

The code in pgbench 13 aggregates into buckets that begin on the
boundaries of wall clock seconds, because it is triggered by changes
in time_t. In the current patch, we aggregate data into buckets that
begin on the boundaries of whole seconds since start_time. Those
boundaries are not aligned with wall clock seconds, and yet we print
out the times rounded to wall clock seconds.

With the following temporary hack:

static void
logAgg(FILE *logfile, StatsData *agg)
{
- fprintf(logfile, INT64_FORMAT " " INT64_FORMAT " %.0f %.0f %.0f %.0f",
- (agg->start_time + epoch_shift) / 1000000,
+ fprintf(logfile, /*INT64_FORMAT*/ "%f " INT64_FORMAT " %.0f
%.0f %.0f %.0f",
+ (agg->start_time + epoch_shift) / 1000000.0,

... you can see what I mean:

1625115080.840406 325 999256 3197232764 1450 6846

Perhaps we should round the start time of the first aggregate down to
the nearest wall clock second? That would mean that the first
aggregate misses a part of a second (as it does in pgbench 13), but
all later aggregates begin at the time we write in the log (as it does
in pgbench 13). That is, if we log 1625115080 we mean "all results >=
1625115080.000000". It's a small detail, but it could be important
for someone trying to correlate the log with other data. What do you
think?