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

Commitc23bb6b

Browse files
committed
Fix some subtle problems in pgbench transaction stats counting.
With --latency-limit, transactions might get skipped even beyond thetransaction count limit specified by -t, throwing off the expectednumber of transactions and thus the denominator for later stats.Be sure to stop skipping transactions once -t is reached.Also, include skipped transactions in the "cnt" fields; this requiresdiscounting them again in a couple of places, but most places arebetter off with this definition. In particular this is needed toget correct overall stats for the combination of -R/-L/-t options.Merge some more processing into processXactStats() to simplify this.In passing, add a check that --progress-timestamp is specified onlywhen --progress is.We might consider back-patching this, but given that it only mattersfor a combination of options, and given the lack of field complaints,consensus seems to be not to bother.Fabien Coelho, reviewed by Nikolay ShaplovDiscussion:https://postgr.es/m/alpine.DEB.2.20.1704171422500.4025@lancre
1 parent9d36a38 commitc23bb6b

File tree

1 file changed

+43
-28
lines changed

1 file changed

+43
-28
lines changed

‎src/bin/pgbench/pgbench.c

Lines changed: 43 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -229,7 +229,7 @@ typedef struct SimpleStats
229229
typedefstructStatsData
230230
{
231231
time_tstart_time;/* interval start time, for aggregates */
232-
int64cnt;/* number of transactions */
232+
int64cnt;/* number of transactions, including skipped */
233233
int64skipped;/* number of transactions skipped under --rate
234234
* and --latency-limit */
235235
SimpleStatslatency;
@@ -329,7 +329,7 @@ typedef struct
329329
boolprepared[MAX_SCRIPTS];/* whether client prepared the script */
330330

331331
/* per client collected stats */
332-
int64cnt;/* transaction count */
332+
int64cnt;/*clienttransaction count, for -t */
333333
intecnt;/* error count */
334334
}CState;
335335

@@ -2062,10 +2062,11 @@ doCustom(TState *thread, CState *st, StatsData *agg)
20622062
}
20632063

20642064
/*
2065-
* If this --latency-limit is used, and this slot is already
2066-
* late so that the transaction will miss the latency limit
2067-
* even if it completed immediately, we skip this time slot
2068-
* and iterate till the next slot that isn't late yet.
2065+
* If --latency-limit is used, and this slot is already late
2066+
* so that the transaction will miss the latency limit even if
2067+
* it completed immediately, we skip this time slot and
2068+
* iterate till the next slot that isn't late yet. But don't
2069+
* iterate beyond the -t limit, if one is given.
20692070
*/
20702071
if (latency_limit)
20712072
{
@@ -2074,14 +2075,21 @@ doCustom(TState *thread, CState *st, StatsData *agg)
20742075
if (INSTR_TIME_IS_ZERO(now))
20752076
INSTR_TIME_SET_CURRENT(now);
20762077
now_us=INSTR_TIME_GET_MICROSEC(now);
2077-
while (thread->throttle_trigger<now_us-latency_limit)
2078+
while (thread->throttle_trigger<now_us-latency_limit&&
2079+
(nxacts <=0||st->cnt<nxacts))
20782080
{
20792081
processXactStats(thread,st,&now, true,agg);
20802082
/* next rendez-vous */
20812083
wait=getPoissonRand(thread,throttle_delay);
20822084
thread->throttle_trigger+=wait;
20832085
st->txn_scheduled=thread->throttle_trigger;
20842086
}
2087+
/* stop client if -t exceeded */
2088+
if (nxacts>0&&st->cnt >=nxacts)
2089+
{
2090+
st->state=CSTATE_FINISHED;
2091+
break;
2092+
}
20852093
}
20862094

20872095
st->state=CSTATE_THROTTLE;
@@ -2393,15 +2401,8 @@ doCustom(TState *thread, CState *st, StatsData *agg)
23932401
*/
23942402
caseCSTATE_END_TX:
23952403

2396-
/*
2397-
* transaction finished: calculate latency and log the
2398-
* transaction
2399-
*/
2400-
if (progress||throttle_delay||latency_limit||
2401-
per_script_stats||use_log)
2402-
processXactStats(thread,st,&now, false,agg);
2403-
else
2404-
thread->stats.cnt++;
2404+
/* transaction finished: calculate latency and do log */
2405+
processXactStats(thread,st,&now, false,agg);
24052406

24062407
if (is_connect)
24072408
{
@@ -2410,7 +2411,6 @@ doCustom(TState *thread, CState *st, StatsData *agg)
24102411
INSTR_TIME_SET_ZERO(now);
24112412
}
24122413

2413-
++st->cnt;
24142414
if ((st->cnt >=nxacts&&duration <=0)||timer_exceeded)
24152415
{
24162416
/* exit success */
@@ -2540,35 +2540,45 @@ doLog(TState *thread, CState *st,
25402540
/*
25412541
* Accumulate and report statistics at end of a transaction.
25422542
*
2543-
* (This is also called when a transaction is late and thus skipped.)
2543+
* (This is also called when a transaction is late and thus skipped.
2544+
* Note that even skipped transactions are counted in the "cnt" fields.)
25442545
*/
25452546
staticvoid
25462547
processXactStats(TState*thread,CState*st,instr_time*now,
25472548
boolskipped,StatsData*agg)
25482549
{
25492550
doublelatency=0.0,
25502551
lag=0.0;
2552+
boolthread_details=progress||throttle_delay||latency_limit,
2553+
detailed=thread_details||use_log||per_script_stats;
25512554

2552-
if ((!skipped)&&INSTR_TIME_IS_ZERO(*now))
2553-
INSTR_TIME_SET_CURRENT(*now);
2554-
2555-
if (!skipped)
2555+
if (detailed&& !skipped)
25562556
{
2557+
if (INSTR_TIME_IS_ZERO(*now))
2558+
INSTR_TIME_SET_CURRENT(*now);
2559+
25572560
/* compute latency & lag */
25582561
latency=INSTR_TIME_GET_MICROSEC(*now)-st->txn_scheduled;
25592562
lag=INSTR_TIME_GET_MICROSEC(st->txn_begin)-st->txn_scheduled;
25602563
}
25612564

2562-
if (progress||throttle_delay||latency_limit)
2565+
if (thread_details)
25632566
{
2567+
/* keep detailed thread stats */
25642568
accumStats(&thread->stats,skipped,latency,lag);
25652569

25662570
/* count transactions over the latency limit, if needed */
25672571
if (latency_limit&&latency>latency_limit)
25682572
thread->latency_late++;
25692573
}
25702574
else
2575+
{
2576+
/* no detailed stats, just count */
25712577
thread->stats.cnt++;
2578+
}
2579+
2580+
/* client stat is just counting */
2581+
st->cnt++;
25722582

25732583
if (use_log)
25742584
doLog(thread,st,agg,skipped,latency,lag);
@@ -3534,7 +3544,7 @@ printResults(TState *threads, StatsData *total, instr_time total_time,
35343544
{
35353545
printf("number of transactions per client: %d\n",nxacts);
35363546
printf("number of transactions actually processed: "INT64_FORMAT"/%d\n",
3537-
total->cnt,nxacts*nclients);
3547+
total->cnt-total->skipped,nxacts*nclients);
35383548
}
35393549
else
35403550
{
@@ -3550,12 +3560,12 @@ printResults(TState *threads, StatsData *total, instr_time total_time,
35503560
if (throttle_delay&&latency_limit)
35513561
printf("number of transactions skipped: "INT64_FORMAT" (%.3f %%)\n",
35523562
total->skipped,
3553-
100.0*total->skipped /(total->skipped+total->cnt));
3563+
100.0*total->skipped /total->cnt);
35543564

35553565
if (latency_limit)
35563566
printf("number of transactions above the %.1f ms latency limit: %d (%.3f %%)\n",
35573567
latency_limit /1000.0,latency_late,
3558-
100.0*latency_late /(total->skipped+total->cnt));
3568+
100.0*latency_late /total->cnt);
35593569

35603570
if (throttle_delay||progress||latency_limit)
35613571
printSimpleStats("latency",&total->latency);
@@ -3604,8 +3614,7 @@ printResults(TState *threads, StatsData *total, instr_time total_time,
36043614
if (latency_limit)
36053615
printf(" - number of transactions skipped: "INT64_FORMAT" (%.3f%%)\n",
36063616
sql_script[i].stats.skipped,
3607-
100.0*sql_script[i].stats.skipped /
3608-
(sql_script[i].stats.skipped+sql_script[i].stats.cnt));
3617+
100.0*sql_script[i].stats.skipped /sql_script[i].stats.cnt);
36093618

36103619
if (num_scripts>1)
36113620
printSimpleStats(" - latency",&sql_script[i].stats.latency);
@@ -4144,6 +4153,12 @@ main(int argc, char **argv)
41444153
exit(1);
41454154
}
41464155

4156+
if (progress_timestamp&&progress==0)
4157+
{
4158+
fprintf(stderr,"--progress-timestamp is allowed only under --progress\n");
4159+
exit(1);
4160+
}
4161+
41474162
/*
41484163
* save main process id in the global variable because process id will be
41494164
* changed after fork.

0 commit comments

Comments
 (0)

[8]ページ先頭

©2009-2025 Movatter.jp