Refactor code to print pgbench progress reports.

threadRun() function is very long and deeply-nested. Extract the code to
print progress reports to a separate function, to make it slightly easier
to read.

Author: Fabien Coelho
Discussion: https://www.postgresql.org/message-id/alpine.DEB.2.21.1903101225270.17271%40lancre

diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index dde058729db63c50e0c5405f236c73cc8d23836f..b1afe44817b070ba7d2c07ba79623d939e43611c 100644 (file)
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -4893,6 +4893,99 @@ addScript(ParsedScript script)
        num_scripts++;
 }
 
+/*
+ * Print progress report.
+ *
+ * On entry, *last and *last_report contain the statistics and time of last
+ * progress report.  On exit, they are updated with the new stats.
+ */
+static void
+printProgressReport(TState *thread, int64 test_start, int64 now,
+                                       StatsData *last, int64 *last_report)
+{
+       /* generate and show report */
+       int64           run = now - *last_report,
+                               ntx;
+       double          tps,
+                               total_run,
+                               latency,
+                               sqlat,
+                               lag,
+                               stdev;
+       char            tbuf[315];
+       StatsData       cur;
+
+       /*
+        * Add up the statistics of all threads.
+        *
+        * XXX: No locking.  There is no guarantee that we get an atomic snapshot
+        * of the transaction count and latencies, so these figures can well be
+        * off by a small amount.  The progress report's purpose is to give a
+        * quick overview of how the test is going, so that shouldn't matter too
+        * much.  (If a read from a 64-bit integer is not atomic, you might get a
+        * "torn" read and completely bogus latencies though!)
+        */
+       initStats(&cur, 0);
+       for (int i = 0; i < nthreads; i++)
+       {
+               mergeSimpleStats(&cur.latency, &thread[i].stats.latency);
+               mergeSimpleStats(&cur.lag, &thread[i].stats.lag);
+               cur.cnt += thread[i].stats.cnt;
+               cur.skipped += thread[i].stats.skipped;
+       }
+
+       /* we count only actually executed transactions */
+       ntx = (cur.cnt - cur.skipped) - (last->cnt - last->skipped);
+       total_run = (now - test_start) / 1000000.0;
+       tps = 1000000.0 * ntx / run;
+       if (ntx > 0)
+       {
+               latency = 0.001 * (cur.latency.sum - last->latency.sum) / ntx;
+               sqlat = 1.0 * (cur.latency.sum2 - last->latency.sum2) / ntx;
+               stdev = 0.001 * sqrt(sqlat - 1000000.0 * latency * latency);
+               lag = 0.001 * (cur.lag.sum - last->lag.sum) / ntx;
+       }
+       else
+       {
+               latency = sqlat = stdev = lag = 0;
+       }
+
+       if (progress_timestamp)
+       {
+               /*
+                * On some platforms the current system timestamp is available in
+                * now_time, but rather than get entangled with that, we just eat the
+                * cost of an extra syscall in all cases.
+                */
+               struct timeval tv;
+
+               gettimeofday(&tv, NULL);
+               snprintf(tbuf, sizeof(tbuf), "%ld.%03ld s",
+                                (long) tv.tv_sec, (long) (tv.tv_usec / 1000));
+       }
+       else
+       {
+               /* round seconds are expected, but the thread may be late */
+               snprintf(tbuf, sizeof(tbuf), "%.1f s", total_run);
+       }
+
+       fprintf(stderr,
+                       "progress: %s, %.1f tps, lat %.3f ms stddev %.3f",
+                       tbuf, tps, latency, stdev);
+
+       if (throttle_delay)
+       {
+               fprintf(stderr, ", lag %.3f ms", lag);
+               if (latency_limit)
+                       fprintf(stderr, ", " INT64_FORMAT " skipped",
+                                       cur.skipped - last->skipped);
+       }
+       fprintf(stderr, "\n");
+
+       *last = cur;
+       *last_report = now;
+}
+
 static void
 printSimpleStats(const char *prefix, SimpleStats *ss)
 {
@@ -6199,89 +6292,7 @@ threadRun(void *arg)
                        now = INSTR_TIME_GET_MICROSEC(now_time);
                        if (now >= next_report)
                        {
-                               /* generate and show report */
-                               StatsData       cur;
-                               int64           run = now - last_report,
-                                                       ntx;
-                               double          tps,
-                                                       total_run,
-                                                       latency,
-                                                       sqlat,
-                                                       lag,
-                                                       stdev;
-                               char            tbuf[315];
-
-                               /*
-                                * Add up the statistics of all threads.
-                                *
-                                * XXX: No locking. There is no guarantee that we get an
-                                * atomic snapshot of the transaction count and latencies, so
-                                * these figures can well be off by a small amount. The
-                                * progress report's purpose is to give a quick overview of
-                                * how the test is going, so that shouldn't matter too much.
-                                * (If a read from a 64-bit integer is not atomic, you might
-                                * get a "torn" read and completely bogus latencies though!)
-                                */
-                               initStats(&cur, 0);
-                               for (i = 0; i < nthreads; i++)
-                               {
-                                       mergeSimpleStats(&cur.latency, &thread[i].stats.latency);
-                                       mergeSimpleStats(&cur.lag, &thread[i].stats.lag);
-                                       cur.cnt += thread[i].stats.cnt;
-                                       cur.skipped += thread[i].stats.skipped;
-                               }
-
-                               /* we count only actually executed transactions */
-                               ntx = (cur.cnt - cur.skipped) - (last.cnt - last.skipped);
-                               total_run = (now - thread_start) / 1000000.0;
-                               tps = 1000000.0 * ntx / run;
-                               if (ntx > 0)
-                               {
-                                       latency = 0.001 * (cur.latency.sum - last.latency.sum) / ntx;
-                                       sqlat = 1.0 * (cur.latency.sum2 - last.latency.sum2) / ntx;
-                                       stdev = 0.001 * sqrt(sqlat - 1000000.0 * latency * latency);
-                                       lag = 0.001 * (cur.lag.sum - last.lag.sum) / ntx;
-                               }
-                               else
-                               {
-                                       latency = sqlat = stdev = lag = 0;
-                               }
-
-                               if (progress_timestamp)
-                               {
-                                       /*
-                                        * On some platforms the current system timestamp is
-                                        * available in now_time, but rather than get entangled
-                                        * with that, we just eat the cost of an extra syscall in
-                                        * all cases.
-                                        */
-                                       struct timeval tv;
-
-                                       gettimeofday(&tv, NULL);
-                                       snprintf(tbuf, sizeof(tbuf), "%ld.%03ld s",
-                                                        (long) tv.tv_sec, (long) (tv.tv_usec / 1000));
-                               }
-                               else
-                               {
-                                       /* round seconds are expected, but the thread may be late */
-                                       snprintf(tbuf, sizeof(tbuf), "%.1f s", total_run);
-                               }
-
-                               fprintf(stderr,
-                                               "progress: %s, %.1f tps, lat %.3f ms stddev %.3f",
-                                               tbuf, tps, latency, stdev);
-
-                               if (throttle_delay)
-                               {
-                                       fprintf(stderr, ", lag %.3f ms", lag);
-                                       if (latency_limit)
-                                               fprintf(stderr, ", " INT64_FORMAT " skipped",
-                                                               cur.skipped - last.skipped);
-                               }
-                               fprintf(stderr, "\n");
-
-                               last = cur;
-                               last_report = now;
+                               printProgressReport(thread, thread_start, now, &last, &last_report);
 
                                /*
                                 * Ensure that the next report is in the future, in case