On Sun, 22 Sep 2024 17:59:34 +0900 (JST)
Tatsuo Ishii <is...@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 <nag...@sraoss.co.jp>
>From 9dad5acfafc8fbc6ba2108202e3baa3bb9266b1b Mon Sep 17 00:00:00 2001
From: Yugo Nagata <nag...@sraoss.co.jp>
Date: Thu, 19 Sep 2024 01:37:54 +0900
Subject: [PATCH v2] pgbench: Improve result outputs related to failed
 transactions

Previously, per-script statistics were never output when all
transactions are failed due to serialization or deadlock errors.
However, it is reasonable to report such information if there
are ones even when there are no successful transaction since
these failed transactions are now objects to be reported.

Meanwhile, if the total number of successful, skipped, and
failed transactions is zero, we don't have to report the number
of failed transactions as similar to the number of skipped
transactions, which avoids to print "NaN%" in lines on failed
transaction reports.

Also, the number of transactions in per-script results now
includes skipped and failed transactions. It prevents to print
"total of NaN%" when any transactions are not successfully
processed. The number of transactions actually processed per-script
and TPS based on it are now output explicitly in a separate line.
---
 src/bin/pgbench/pgbench.c | 78 +++++++++++++++++++++------------------
 1 file changed, 43 insertions(+), 35 deletions(-)

diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index 61618f2e18..da2770b9f1 100644
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -6391,6 +6391,13 @@ printResults(StatsData *total,
 			   total->cnt);
 	}
 
+	/*
+	 * Remaining stats are nonsensical if we failed to execute any xacts
+	 * due to others than serialization or deadlock errors
+	 */
+	if (total_cnt <= 0)
+		return;
+
 	printf("number of failed transactions: " INT64_FORMAT " (%.3f%%)\n",
 		   failures, 100.0 * failures / total_cnt);
 
@@ -6412,10 +6419,6 @@ printResults(StatsData *total,
 		printf("total number of retries: " INT64_FORMAT "\n", total->retries);
 	}
 
-	/* Remaining stats are nonsensical if we failed to execute any xacts */
-	if (total->cnt + total->skipped <= 0)
-		return;
-
 	if (throttle_delay && latency_limit)
 		printf("number of transactions skipped: " INT64_FORMAT " (%.3f%%)\n",
 			   total->skipped, 100.0 * total->skipped / total_cnt);
@@ -6483,45 +6486,50 @@ printResults(StatsData *total,
 
 				printf("SQL script %d: %s\n"
 					   " - weight: %d (targets %.1f%% of total)\n"
-					   " - " INT64_FORMAT " transactions (%.1f%% of total, tps = %f)\n",
+					   " - " INT64_FORMAT " transactions (%.1f%% of total)\n",
 					   i + 1, sql_script[i].desc,
 					   sql_script[i].weight,
 					   100.0 * sql_script[i].weight / total_weight,
-					   sstats->cnt,
-					   100.0 * sstats->cnt / total->cnt,
-					   sstats->cnt / bench_duration);
-
-				printf(" - number of failed transactions: " INT64_FORMAT " (%.3f%%)\n",
-					   script_failures,
-					   100.0 * script_failures / script_total_cnt);
+					   script_total_cnt,
+					   100.0 * script_total_cnt / total_cnt);
 
-				if (failures_detailed)
+				if (script_total_cnt > 0)
 				{
-					printf(" - number of serialization failures: " INT64_FORMAT " (%.3f%%)\n",
-						   sstats->serialization_failures,
-						   (100.0 * sstats->serialization_failures /
-							script_total_cnt));
-					printf(" - number of deadlock failures: " INT64_FORMAT " (%.3f%%)\n",
-						   sstats->deadlock_failures,
-						   (100.0 * sstats->deadlock_failures /
-							script_total_cnt));
-				}
+					printf(" - number of transactions actually pocessed: " INT64_FORMAT " (tps = %f)\n",
+						   sstats->cnt, sstats->cnt / bench_duration);
 
-				/* it can be non-zero only if max_tries is not equal to one */
-				if (max_tries != 1)
-				{
-					printf(" - number of transactions retried: " INT64_FORMAT " (%.3f%%)\n",
-						   sstats->retried,
-						   100.0 * sstats->retried / script_total_cnt);
-					printf(" - total number of retries: " INT64_FORMAT "\n",
-						   sstats->retries);
-				}
+					printf(" - number of failed transactions: " INT64_FORMAT " (%.3f%%)\n",
+						   script_failures,
+						   100.0 * script_failures / script_total_cnt);
+
+					if (failures_detailed)
+					{
+						printf(" - number of serialization failures: " INT64_FORMAT " (%.3f%%)\n",
+							   sstats->serialization_failures,
+							   (100.0 * sstats->serialization_failures /
+								script_total_cnt));
+						printf(" - number of deadlock failures: " INT64_FORMAT " (%.3f%%)\n",
+							   sstats->deadlock_failures,
+							   (100.0 * sstats->deadlock_failures /
+								script_total_cnt));
+					}
 
-				if (throttle_delay && latency_limit && script_total_cnt > 0)
-					printf(" - number of transactions skipped: " INT64_FORMAT " (%.3f%%)\n",
-						   sstats->skipped,
-						   100.0 * sstats->skipped / script_total_cnt);
+					/* it can be non-zero only if max_tries is not equal to one */
+					if (max_tries != 1)
+					{
+						printf(" - number of transactions retried: " INT64_FORMAT " (%.3f%%)\n",
+							   sstats->retried,
+							   100.0 * sstats->retried / script_total_cnt);
+						printf(" - total number of retries: " INT64_FORMAT "\n",
+							   sstats->retries);
+					}
 
+					if (throttle_delay && latency_limit)
+						printf(" - number of transactions skipped: " INT64_FORMAT " (%.3f%%)\n",
+							   sstats->skipped,
+							   100.0 * sstats->skipped / script_total_cnt);
+
+				}
 				printSimpleStats(" - latency", &sstats->latency);
 			}
 
-- 
2.34.1

Reply via email to