At Tue, 8 Jun 2021 12:09:47 +0900, YoungHwan Joo <rulyox@gmail.com> wrote in
> Hello!
>
> While I was using pgbench from the master branch, I discovered an error on
> pgbench logs.
> When I run pgbench, the log file contains a lot of redundant 0s.
>
> I ran git bisect and found out that this error occured since the commit
> 547f04e7348b6ed992bd4a197d39661fe7c25097 (Mar 10, 2021).
Ugh! Thanks for the hunting!
The cause is that the time unit is changed to usec but the patch
forgot to convert agg_interval into the same unit in doLog. I tempted
to change it into pg_time_usec_t but it seems that it is better that
the unit is same with other similar variables like duration.
So I think that the attached fix works for you. (However, I'm not sure
the emitted log is correct or not, though..)
I didn't check for the similar bugs for other variables yet.
> I ran the tests below on the problematic commit and the commit before it.
> (I used Debian 10.9 and Ubuntu 20.04)
>
> =====
> ./pg_ctl -D /tmp/data init
> ./pg_ctl -D /tmp/data start
>
> ./pgbench -i -s 1 postgres
>
> ./pgbench -r -c 1 -j 1 -T 1 --aggregate-interval 1 -l --log-prefix
> pgbench-log postgres
> ./pgbench -r -c 2 -j 4 -T 60 --aggregate-interval 1 -l --log-prefix
> pgbench-log postgres
> ./pgbench -r -c 2 -j 4 -T 60 --aggregate-interval 10 -l --log-prefix
> pgbench-log postgres
> =====
>
> The result screenshots are in the attachments.
> (I didn't attach the problematic 60 second log file which was bigger than
> 1GB.)
>
> Please take a look at this issue.
>
> Thank you!
>
> Regards,
> YoungHwan
regards.
--
Kyotaro Horiguchi
NTT Open Source Software Center
diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index dc84b7b9b7..c68dfa1806 100644
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -3799,7 +3799,7 @@ doLog(TState *thread, CState *st,
* e.g. --rate=0.1).
*/
- while (agg->start_time + agg_interval <= now)
+ while (agg->start_time + agg_interval * 1000000 <= now)
{
/* print aggregated report to logfile */
fprintf(logfile, INT64_FORMAT " " INT64_FORMAT " %.0f %.0f %.0f %.0f",
@@ -3822,7 +3822,7 @@ doLog(TState *thread, CState *st,
fputc('\n', logfile);
/* reset data and move to next interval */
- initStats(agg, agg->start_time + agg_interval);
+ initStats(agg, agg->start_time + agg_interval * 1000000);
}
/* accumulate the current transaction */
