Re: pgbench: Improve result outputs related to failed transactinos

On Sun, 22 Sep 2024 17:59:34 +0900 (JST)
Tatsuo Ishii <ishii(at)postgresql(dot)org> wrote:

> > I would like to improve the following two points on the result outputs
> > of pgbench related to faild transaction. The patch is attached.
> >
> > (1) Output per-script statistics even when there are no successful
> > transaction if there is any failed transactions due to serialization
> > or deadlock errors.
> >
> > Previously, per-script statistics were never output when any transactions
> > are failed. However, it is reasonable to report per-script failed transactions
> > if they are due to serialization or deadlock errors, since these kinds of
> > failures are now objects to be reported.
> >
> > This is fixed by modifying the following condition to use "total_cnt <= 0".
> >
> > /* Remaining stats are nonsensical if we failed to execute any xacts */
> > if (total->cnt + total->skipped <= 0)
> > return;
> >
> > (2) Avoid to print "NaN%" in lines on failed transaction reports.
>
> This itself sounds good. However, in case (1) still "NaN%" are
> printed. This looks inconsistent.
>
> t-ishii$ src/bin/pgbench/pgbench -p 11002 -c1 -t 1 -f c.sql -f d.sql --failures-detailed test
> pgbench (18devel)
> starting vacuum...end.
> transaction type: multiple scripts
> scaling factor: 1
> query mode: simple
> number of clients: 1
> number of threads: 1
> maximum number of tries: 1
> number of transactions per client: 1
> number of transactions actually processed: 0/1
> number of failed transactions: 1 (100.000%)
> number of serialization failures: 1 (100.000%)
> number of deadlock failures: 0 (0.000%)
> latency average = 7023.604 ms (including failures)
> initial connection time = 4.964 ms
> tps = 0.000000 (without initial connection time)
> SQL script 1: c.sql
> - weight: 1 (targets 50.0% of total)
> - 0 transactions (NaN% of total, tps = 0.000000)
> SQL script 2: d.sql
> - weight: 1 (targets 50.0% of total)
> - 0 transactions (NaN% of total, tps = 0.000000)
> - number of failed transactions: 1 (100.000%)
> - number of serialization failures: 1 (100.000%)
> - number of deadlock failures: 0 (0.000%)

I overlooked the "NaN% of total" in per-script results.
I think this NaN also should be avoided.

I fixed the number of transactions in per-script results to include
skipped and failed transactions. It prevents to print "total of NaN%"
when any transactions are not successfully processed.

Although it breaks the back-compatibility, this seems reasonable
modification because not only succeeded transactions but also skips and
failures ones are now handled and reported for each script. Also, the
number of transactions actually processed per-script and TPS based on
it are now output explicitly in a separate line.

Here is an example of the results.

$ pgbench -f sleep.sql -f deadlock.sql --failures-detailed -t 2 -r -c 4 -j 4
pgbench (18devel)
starting vacuum...end.
transaction type: multiple scripts
scaling factor: 1
query mode: simple
number of clients: 4
number of threads: 4
maximum number of tries: 1
number of transactions per client: 2
number of transactions actually processed: 5/8
number of failed transactions: 3 (37.500%)
number of serialization failures: 0 (0.000%)
number of deadlock failures: 3 (37.500%)
latency average = 7532.531 ms (including failures)
initial connection time = 7.447 ms
tps = 0.331894 (without initial connection time)
SQL script 1: sleep.sql
- weight: 1 (targets 50.0% of total)
- 2 transactions (25.0% of total)
- number of transactions actually pocessed: 2 (tps = 0.132758)
- number of failed transactions: 0 (0.000%)
- number of serialization failures: 0 (0.000%)
- number of deadlock failures: 0 (0.000%)
- latency average = 1002.506 ms
- latency stddev = 0.320 ms
- statement latencies in milliseconds and failures:
1002.506 0 select pg_sleep(1)
SQL script 2: deadlock.sql
- weight: 1 (targets 50.0% of total)
- 6 transactions (75.0% of total)
- number of transactions actually pocessed: 3 (tps = 0.199136)
- number of failed transactions: 3 (50.000%)
- number of serialization failures: 0 (0.000%)
- number of deadlock failures: 3 (50.000%)
- latency average = 9711.271 ms
- latency stddev = 466.328 ms
- statement latencies in milliseconds and failures:
0.426 0 begin;
5352.229 0 lock b;
2003.416 0 select pg_sleep(2);
0.829 3 lock a;
8.774 0 end;

I've attached the updated patch.

Regards,
Yugo Nagata

--
Yugo NAGATA <nagata(at)sraoss(dot)co(dot)jp>