Movatterモバイル変換

[0]ホーム
URL:

Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

 Sign up
Appearance settings

Commit5614a0f

Browse files
committed
Fix pgbench timestamp bugs.
Commit547f04e changed pgbench to use microsecond accounting, butintroduced a couple of logging and aggregation bugs:1. We print Unix epoch timestamps so that you can correlate them withother logs, but these were inadvertently changed to use asystem-dependent reference epoch. Compute Unix timestamps, and beginaggregation intervals on the boundaries of whole Unix epoch seconds, asbefore.2. The user-supplied aggregation interval needed to be scaled.Back-patch to 14.Author: Fabien COELHO <coelho@cri.ensmp.fr>Author: Yugo NAGATA <nagata@sraoss.co.jp>Author: Kyotaro Horiguchi <horikyota.ntt@gmail.com>Reported-by: YoungHwan Joo <rulyox@gmail.com>Reported-by: Gregory Smith <gregsmithpgsql@gmail.com>Discussion:https://postgr.es/m/CAF7igB1r6wRfSCEAB-iZBKxkowWY6%2BdFF2jObSdd9%2BiVK%2BvHJg%40mail.gmail.comDiscussion:https://postgr.es/m/CAHLJuCW_8Vpcr0%3Dt6O_gozrg3wXXWXZXDioYJd3NhvKriqgpfQ%40mail.gmail.com
1 parent10a0797 commit5614a0f

File tree

1 file changed

+34
-9
lines changed

1 file changed

+34
-9
lines changed

‎src/bin/pgbench/pgbench.c‎

Lines changed: 34 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -343,6 +343,12 @@ typedef struct StatsData
343343
SimpleStatslag;
344344
}StatsData;
345345

346+
/*
347+
* For displaying Unix epoch timestamps, as some time functions may have
348+
* another reference.
349+
*/
350+
pg_time_usec_tepoch_shift;
351+
346352
/*
347353
* Struct to keep random state.
348354
*/
@@ -3772,16 +3778,17 @@ executeMetaCommand(CState *st, pg_time_usec_t *now)
37723778
* Print log entry after completing one transaction.
37733779
*
37743780
* We print Unix-epoch timestamps in the log, so that entries can be
3775-
* correlated against other logs. On some platforms this could be obtained
3776-
* from the caller, but rather than get entangled with that, we just eat
3777-
* the cost of an extra syscall in all cases.
3781+
* correlated against other logs.
3782+
*
3783+
* XXX We could obtain the time from the caller and just shift it here, to
3784+
* avoid the cost of an extra call to pg_time_now().
37783785
*/
37793786
staticvoid
37803787
doLog(TState*thread,CState*st,
37813788
StatsData*agg,boolskipped,doublelatency,doublelag)
37823789
{
37833790
FILE*logfile=thread->logfile;
3784-
pg_time_usec_tnow=pg_time_now();
3791+
pg_time_usec_tnow=pg_time_now()+epoch_shift;
37853792

37863793
Assert(use_log);
37873794

@@ -3796,17 +3803,19 @@ doLog(TState *thread, CState *st,
37963803
/* should we aggregate the results or not? */
37973804
if (agg_interval>0)
37983805
{
3806+
pg_time_usec_tnext;
3807+
37993808
/*
38003809
* Loop until we reach the interval of the current moment, and print
38013810
* any empty intervals in between (this may happen with very low tps,
38023811
* e.g. --rate=0.1).
38033812
*/
38043813

3805-
while (agg->start_time+agg_interval <=now)
3814+
while ((next=agg->start_time+agg_interval*INT64CONST(1000000)) <=now)
38063815
{
38073816
/* print aggregated report to logfile */
38083817
fprintf(logfile,INT64_FORMAT" "INT64_FORMAT" %.0f %.0f %.0f %.0f",
3809-
agg->start_time,
3818+
agg->start_time /1000000,/* seconds since Unix epoch */
38103819
agg->cnt,
38113820
agg->latency.sum,
38123821
agg->latency.sum2,
@@ -3825,7 +3834,7 @@ doLog(TState *thread, CState *st,
38253834
fputc('\n',logfile);
38263835

38273836
/* reset data and move to next interval */
3828-
initStats(agg,agg->start_time+agg_interval);
3837+
initStats(agg,next);
38293838
}
38303839

38313840
/* accumulate the current transaction */
@@ -5458,7 +5467,8 @@ printProgressReport(TState *threads, int64 test_start, pg_time_usec_t now,
54585467

54595468
if (progress_timestamp)
54605469
{
5461-
snprintf(tbuf,sizeof(tbuf),"%.3f s",PG_TIME_GET_DOUBLE(now));
5470+
snprintf(tbuf,sizeof(tbuf),"%.3f s",
5471+
PG_TIME_GET_DOUBLE(now+epoch_shift));
54625472
}
54635473
else
54645474
{
@@ -5808,6 +5818,14 @@ main(int argc, char **argv)
58085818
char*env;
58095819

58105820
intexit_code=0;
5821+
structtimevaltv;
5822+
5823+
/*
5824+
* Record difference between Unix time and instr_time time. We'll use
5825+
* this for logging and aggregation.
5826+
*/
5827+
gettimeofday(&tv,NULL);
5828+
epoch_shift=tv.tv_sec*INT64CONST(1000000)+tv.tv_usec-pg_time_now();
58115829

58125830
pg_logging_init(argv[0]);
58135831
progname=get_progname(argv[0]);
@@ -6637,7 +6655,14 @@ threadRun(void *arg)
66376655
thread->bench_start=start;
66386656
thread->throttle_trigger=start;
66396657

6640-
initStats(&aggs,start);
6658+
/*
6659+
* The log format currently has Unix epoch timestamps with whole numbers
6660+
* of seconds. Round the first aggregate's start time down to the nearest
6661+
* Unix epoch second (the very first aggregate might really have started a
6662+
* fraction of a second later, but later aggregates are measured from the
6663+
* whole number time that is actually logged).
6664+
*/
6665+
initStats(&aggs, (start+epoch_shift) /1000000*1000000);
66416666
last=aggs;
66426667

66436668
/* loop till all clients have terminated */

0 commit comments

Comments
 (0)
[8]ページ先頭
©2009-2025 Movatter.jp