pgbench: Improve result outputs related to failed transactinos

Hi,

Hi,

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%)

Best reagards,
--
Tatsuo Ishii
SRA OSS K.K.
English: http://www.sraoss.co.jp/index_en/
Japanese:http://www.sraoss.co.jp

On Sun, 22 Sep 2024 17:59:34 +0900 (JST)
Tatsuo Ishii <ishii@postgresql.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@sraoss.co.jp>

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.

Thanks for the fix. Here is the new run with the v2 patch. The result
looks good to me.

src/bin/pgbench/pgbench -p 11002 -c1 -t 1 -f c.sql -f d.sql --failures-detailed -r 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: 1/1
number of failed transactions: 0 (0.000%)
number of serialization failures: 0 (0.000%)
number of deadlock failures: 0 (0.000%)
latency average = 2.434 ms
initial connection time = 2.117 ms
tps = 410.846343 (without initial connection time)
SQL script 1: c.sql
- weight: 1 (targets 50.0% of total)
- 1 transactions (100.0% of total)
- number of transactions actually pocessed: 1 (tps = 410.846343)
- number of failed transactions: 0 (0.000%)
- number of serialization failures: 0 (0.000%)
- number of deadlock failures: 0 (0.000%)
- latency average = 2.419 ms
- latency stddev = 0.000 ms
- statement latencies in milliseconds and failures:
0.187 0 begin;
0.153 0 set transaction isolation level serializable;
0.977 0 insert into t1 select max(i)+1,2 from t1;
1.102 0 end;
SQL script 2: d.sql
- weight: 1 (targets 50.0% of total)
- 0 transactions (0.0% of total)
- statement latencies in milliseconds and failures:
0.000 0 begin;
0.000 0 set transaction isolation level serializable;
0.000 0 insert into t1 select max(i)+1,2 from t1;
0.000 0 end;

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.

Okay for me as long as the patch is pushed to master branch.

A small comment on the comments in the patch: pgindent dislikes some
of the comment indentation styles. See attached pgindent.txt. Although
such a small defect would be fixed by committers when a patch gets
committed anyway, you might want to help committers beforehand.

Best reagards,
--
Tatsuo Ishii
SRA OSS K.K.
English: http://www.sraoss.co.jp/index_en/
Japanese:http://www.sraoss.co.jp

On Tue, 24 Sep 2024 19:00:04 +0900 (JST)
Tatsuo Ishii <ishii@postgresql.org> wrote:

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.

Thanks for the fix. Here is the new run with the v2 patch. The result
looks good to me.

src/bin/pgbench/pgbench -p 11002 -c1 -t 1 -f c.sql -f d.sql --failures-detailed -r 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: 1/1
number of failed transactions: 0 (0.000%)
number of serialization failures: 0 (0.000%)
number of deadlock failures: 0 (0.000%)
latency average = 2.434 ms
initial connection time = 2.117 ms
tps = 410.846343 (without initial connection time)
SQL script 1: c.sql
- weight: 1 (targets 50.0% of total)
- 1 transactions (100.0% of total)
- number of transactions actually pocessed: 1 (tps = 410.846343)
- number of failed transactions: 0 (0.000%)
- number of serialization failures: 0 (0.000%)
- number of deadlock failures: 0 (0.000%)
- latency average = 2.419 ms
- latency stddev = 0.000 ms
- statement latencies in milliseconds and failures:
0.187 0 begin;
0.153 0 set transaction isolation level serializable;
0.977 0 insert into t1 select max(i)+1,2 from t1;
1.102 0 end;
SQL script 2: d.sql
- weight: 1 (targets 50.0% of total)
- 0 transactions (0.0% of total)
- statement latencies in milliseconds and failures:
0.000 0 begin;
0.000 0 set transaction isolation level serializable;
0.000 0 insert into t1 select max(i)+1,2 from t1;
0.000 0 end;

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.

Okay for me as long as the patch is pushed to master branch.

A small comment on the comments in the patch: pgindent dislikes some
of the comment indentation styles. See attached pgindent.txt. Although
such a small defect would be fixed by committers when a patch gets
committed anyway, you might want to help committers beforehand.

Thank you for your comments.
I've attached a updated patch that I applied pgindent.

Regards,
Yugo Nagata

Best reagards,
--
Tatsuo Ishii
SRA OSS K.K.
English: http://www.sraoss.co.jp/index_en/
Japanese:http://www.sraoss.co.jp

--
Yugo NAGATA <nagata@sraoss.co.jp>

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.

Thanks for the fix. Here is the new run with the v2 patch. The result
looks good to me.

src/bin/pgbench/pgbench -p 11002 -c1 -t 1 -f c.sql -f d.sql --failures-detailed -r 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: 1/1
number of failed transactions: 0 (0.000%)
number of serialization failures: 0 (0.000%)
number of deadlock failures: 0 (0.000%)
latency average = 2.434 ms
initial connection time = 2.117 ms
tps = 410.846343 (without initial connection time)
SQL script 1: c.sql
- weight: 1 (targets 50.0% of total)
- 1 transactions (100.0% of total)
- number of transactions actually pocessed: 1 (tps = 410.846343)
- number of failed transactions: 0 (0.000%)
- number of serialization failures: 0 (0.000%)
- number of deadlock failures: 0 (0.000%)
- latency average = 2.419 ms
- latency stddev = 0.000 ms
- statement latencies in milliseconds and failures:
0.187 0 begin;
0.153 0 set transaction isolation level serializable;
0.977 0 insert into t1 select max(i)+1,2 from t1;
1.102 0 end;
SQL script 2: d.sql
- weight: 1 (targets 50.0% of total)
- 0 transactions (0.0% of total)
- statement latencies in milliseconds and failures:
0.000 0 begin;
0.000 0 set transaction isolation level serializable;
0.000 0 insert into t1 select max(i)+1,2 from t1;
0.000 0 end;

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.

Okay for me as long as the patch is pushed to master branch.

A small comment on the comments in the patch: pgindent dislikes some
of the comment indentation styles. See attached pgindent.txt. Although
such a small defect would be fixed by committers when a patch gets
committed anyway, you might want to help committers beforehand.

Thank you for your comments.
I've attached a updated patch that I applied pgindent.

The patch looks good to me. If there's no objection, I will commit and
push the patch to master branch. I don't think this should be
back-patched since it modifies the user visible behavior of pgbench.

Best reagards,
--
Tatsuo Ishii
SRA OSS K.K.
English: http://www.sraoss.co.jp/index_en/
Japanese:http://www.sraoss.co.jp

Thanks for the fix. Here is the new run with the v2 patch. The result
looks good to me.

src/bin/pgbench/pgbench -p 11002 -c1 -t 1 -f c.sql -f d.sql --failures-detailed -r 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: 1/1
number of failed transactions: 0 (0.000%)
number of serialization failures: 0 (0.000%)
number of deadlock failures: 0 (0.000%)
latency average = 2.434 ms
initial connection time = 2.117 ms
tps = 410.846343 (without initial connection time)
SQL script 1: c.sql
- weight: 1 (targets 50.0% of total)
- 1 transactions (100.0% of total)
- number of transactions actually pocessed: 1 (tps = 410.846343)
- number of failed transactions: 0 (0.000%)
- number of serialization failures: 0 (0.000%)
- number of deadlock failures: 0 (0.000%)
- latency average = 2.419 ms
- latency stddev = 0.000 ms
- statement latencies in milliseconds and failures:
0.187 0 begin;
0.153 0 set transaction isolation level serializable;
0.977 0 insert into t1 select max(i)+1,2 from t1;
1.102 0 end;
SQL script 2: d.sql
- weight: 1 (targets 50.0% of total)
- 0 transactions (0.0% of total)
- statement latencies in milliseconds and failures:
0.000 0 begin;
0.000 0 set transaction isolation level serializable;
0.000 0 insert into t1 select max(i)+1,2 from t1;
0.000 0 end;

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.

Okay for me as long as the patch is pushed to master branch.

A small comment on the comments in the patch: pgindent dislikes some
of the comment indentation styles. See attached pgindent.txt. Although
such a small defect would be fixed by committers when a patch gets
committed anyway, you might want to help committers beforehand.

Thank you for your comments.
I've attached a updated patch that I applied pgindent.

The patch looks good to me. If there's no objection, I will commit and
push the patch to master branch. I don't think this should be
back-patched since it modifies the user visible behavior of pgbench.

Patch pushed.

Best reagards,
--
Tatsuo Ishii
SRA OSS K.K.
English: http://www.sraoss.co.jp/index_en/
Japanese:http://www.sraoss.co.jp

On Fri, 11 Oct 2024 13:54:54 +0900 (JST)
Tatsuo Ishii <ishii@postgresql.org> wrote:

Thanks for the fix. Here is the new run with the v2 patch. The result
looks good to me.

src/bin/pgbench/pgbench -p 11002 -c1 -t 1 -f c.sql -f d.sql --failures-detailed -r 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: 1/1
number of failed transactions: 0 (0.000%)
number of serialization failures: 0 (0.000%)
number of deadlock failures: 0 (0.000%)
latency average = 2.434 ms
initial connection time = 2.117 ms
tps = 410.846343 (without initial connection time)
SQL script 1: c.sql
- weight: 1 (targets 50.0% of total)
- 1 transactions (100.0% of total)
- number of transactions actually pocessed: 1 (tps = 410.846343)
- number of failed transactions: 0 (0.000%)
- number of serialization failures: 0 (0.000%)
- number of deadlock failures: 0 (0.000%)
- latency average = 2.419 ms
- latency stddev = 0.000 ms
- statement latencies in milliseconds and failures:
0.187 0 begin;
0.153 0 set transaction isolation level serializable;
0.977 0 insert into t1 select max(i)+1,2 from t1;
1.102 0 end;
SQL script 2: d.sql
- weight: 1 (targets 50.0% of total)
- 0 transactions (0.0% of total)
- statement latencies in milliseconds and failures:
0.000 0 begin;
0.000 0 set transaction isolation level serializable;
0.000 0 insert into t1 select max(i)+1,2 from t1;
0.000 0 end;

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.

Okay for me as long as the patch is pushed to master branch.

A small comment on the comments in the patch: pgindent dislikes some
of the comment indentation styles. See attached pgindent.txt. Although
such a small defect would be fixed by committers when a patch gets
committed anyway, you might want to help committers beforehand.

Thank you for your comments.
I've attached a updated patch that I applied pgindent.

The patch looks good to me. If there's no objection, I will commit and
push the patch to master branch. I don't think this should be
back-patched since it modifies the user visible behavior of pgbench.

Patch pushed.

Thanks!

Regards,
Yugo Nagata

--
Yugo NAGATA <nagata@sraoss.co.jp>

Hello Tatsuo-san,

11.10.2024 07:54, Tatsuo Ishii wrote:

...
- number of transactions actually pocessed: 1 (tps = 410.846343)
...

Patch pushed.

Please consider fixing a typo sneaked in that commit: pocessed -> processed?

Best regards,
Alexander

Hello Alexander,

Hello Tatsuo-san,

11.10.2024 07:54, Tatsuo Ishii wrote:

...
- number of transactions actually pocessed: 1 (tps = 410.846343)
...

Patch pushed.

Please consider fixing a typo sneaked in that commit: pocessed ->
processed?

Thank you for the report! I have pushed a fix.

Best reagards,
--
Tatsuo Ishii
SRA OSS K.K.
English: http://www.sraoss.co.jp/index_en/
Japanese:http://www.sraoss.co.jp