diff --git a/doc/src/sgml/ref/pgbench.sgml b/doc/src/sgml/ref/pgbench.sgml index ebdb4b3f46..d1818ff316 100644 --- a/doc/src/sgml/ref/pgbench.sgml +++ b/doc/src/sgml/ref/pgbench.sgml @@ -2401,7 +2401,9 @@ END; format is used for the log files: -interval_start num_transactions sum_latency sum_latency_2 min_latency max_latency { failures | serialization_failures deadlock_failures } sum_lag sum_lag_2 min_lag max_lag skipped retried retries +interval_start num_transactions sum_latency sum_latency_2 min_latency max_latency +sum_lag sum_lag_2 min_lag max_lag skipped +retried retries failures serialization_failures deadlock_failures where @@ -2417,41 +2419,55 @@ END; and max_latency is the maximum latency within the interval, failures is the number of transactions that ended - with a failed SQL command within the interval. If you use option - , instead of the sum of all failed - transactions you will get more detailed statistics for the failed - transactions grouped by the following types: - serialization_failures is the number of - transactions that got a serialization error and were not retried after this, - deadlock_failures is the number of transactions - that got a deadlock error and were not retried after this. + with a failed SQL command within the interval. + + The next fields, sum_lag, sum_lag_2, min_lag, - and max_lag, are only present if the - option is used. + and max_lag, only meaningful if the + option is used. Otherwise, they are all 0.0. They provide statistics about the time each transaction had to wait for the previous one to finish, i.e., the difference between each transaction's scheduled start time and the time it actually started. The next field, skipped, - is only present if the option is used, too. + is only meaningful if the option is used, too. Otherwise it is 0. It counts the number of transactions skipped because they would have started too late. - The retried and retries - fields are present only if the option is not - equal to 1. They report the number of retried transactions and the sum of all - retries after serialization or deadlock errors within the interval. - Each transaction is counted in the interval when it was committed. + + + The retried + and retries fields are only meaningful if + the option is not equal to 1. Otherwise they + are 0. They report the number of retried transactions and the sum of all + retries after serialization or deadlock errors within the interval. Each + transaction is counted in the interval when it was committed. + + + failures is the sum of all failed transactions. + If is specified, instead of the sum of + all failed transactions you will get more detailed statistics for the + failed transactions grouped by the following types: + serialization_failures is the number of + transactions that got a serialization error and were not retried after this, + deadlock_failures is the number of transactions + that got a deadlock error and were not retried after this. + If is not + specified, serialization_failures + and deadlock_failures are always 0. - Here is some example output: + Here is some example output with following options: -1345828501 5601 1542744 483552416 61 2573 0 -1345828503 7884 1979812 565806736 60 1479 0 -1345828505 7208 1979422 567277552 59 1391 0 -1345828507 7685 1980268 569784714 60 1398 0 -1345828509 7073 1979779 573489941 236 1411 0 - +pgbench --aggregate-interval=10 --time=20 --client=10 --log --rate=1000 +--latency-limit=10 --failures-detailed --max-tries=10 test + + + +1649114136 5815 27552565 177846919143 1078 21716 2756787 7264696105 0 9661 0 7854 31472 4022 4022 0 +1649114146 5958 28460110 182785513108 1083 20391 2539395 6411761497 0 7268 0 8127 32595 4101 4101 0 + + Notice that while the plain (unaggregated) log file shows which script diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c index acf3e56413..4d4b979e4f 100644 --- a/src/bin/pgbench/pgbench.c +++ b/src/bin/pgbench/pgbench.c @@ -4494,6 +4494,17 @@ doLog(TState *thread, CState *st, while ((next = agg->start_time + agg_interval * INT64CONST(1000000)) <= now) { + double lag_sum = 0.0; + double lag_sum2 = 0.0; + double lag_min = 0.0; + double lag_max = 0.0; + int64 skipped = 0; + int64 serialization_failures = 0; + int64 deadlock_failures = 0; + int64 serialization_or_deadlock_failures = 0; + int64 retried = 0; + int64 retries = 0; + /* print aggregated report to logfile */ fprintf(logfile, INT64_FORMAT " " INT64_FORMAT " %.0f %.0f %.0f %.0f", agg->start_time / 1000000, /* seconds since Unix epoch */ @@ -4503,27 +4514,41 @@ doLog(TState *thread, CState *st, agg->latency.min, agg->latency.max); - if (failures_detailed) - fprintf(logfile, " " INT64_FORMAT " " INT64_FORMAT, - agg->serialization_failures, - agg->deadlock_failures); - else - fprintf(logfile, " " INT64_FORMAT, getFailures(agg)); - if (throttle_delay) { - fprintf(logfile, " %.0f %.0f %.0f %.0f", - agg->lag.sum, - agg->lag.sum2, - agg->lag.min, - agg->lag.max); - if (latency_limit) - fprintf(logfile, " " INT64_FORMAT, agg->skipped); + lag_sum = agg->lag.sum; + lag_sum2 = agg->lag.sum2; + lag_min = agg->lag.min; + lag_max = agg->lag.max; } + fprintf(logfile, " %.0f %.0f %.0f %.0f", + lag_sum, + lag_sum2, + lag_min, + lag_max); + + if (latency_limit) + skipped = agg->skipped; + fprintf(logfile, " " INT64_FORMAT, skipped); + if (max_tries != 1) - fprintf(logfile, " " INT64_FORMAT " " INT64_FORMAT, - agg->retried, - agg->retries); + { + retried = agg->retried; + retries = agg->retries; + } + fprintf(logfile, " " INT64_FORMAT " " INT64_FORMAT, retried, retries); + + if (failures_detailed) + { + serialization_failures = agg->serialization_failures; + deadlock_failures = agg->deadlock_failures; + } + serialization_or_deadlock_failures = serialization_failures + deadlock_failures; + fprintf(logfile, " " INT64_FORMAT " " INT64_FORMAT " " INT64_FORMAT, + serialization_or_deadlock_failures, + serialization_failures, + deadlock_failures); + fputc('\n', logfile); /* reset data and move to next interval */