Add new "-q" logging option (quiet mode) while in initialize mode

(-i), producing only one progress message per 5 seconds along with
elapsed time and estimated remaining time.  Also add elapsed time and
estimated remaining time to the default logging(prints one message
each 100000 rows).
Patch contributed by Tomas Vondra, reviewed by Jeevan Chalke and
Tatsuo Ishii.

diff --git a/contrib/pgbench/pgbench.c b/contrib/pgbench/pgbench.c
index 43c7f9a7bda3291fa3b2542b0fc0c074bc8e2e8d..3ca120fa68b784e9b0b7d66f186f09945440e213 100644 (file)
--- a/contrib/pgbench/pgbench.c
+++ b/contrib/pgbench/pgbench.c
@@ -39,6 +39,7 @@
 #include "portability/instr_time.h"
 
 #include <ctype.h>
+#include <math.h>
 
 #ifndef WIN32
 #include <sys/time.h>
@@ -102,6 +103,7 @@ extern int  optind;
 #define MAXCLIENTS 1024
 #endif
 
+#define LOG_STEP_SECONDS   5   /* seconds between log messages */
 #define DEFAULT_NXACTS 10      /* default nxacts */
 
 int            nxacts = 0;         /* number of transactions per client */
@@ -150,6 +152,7 @@ char       *index_tablespace = NULL;
 #define naccounts  100000
 
 bool       use_log;            /* log transaction latencies to a file */
+bool       use_quiet;          /* quiet logging onto stderr */
 bool       is_connect;         /* establish connection for each transaction */
 bool       is_latencies;       /* report per-command latencies */
 int            main_pid;           /* main process id used in log filename */
@@ -359,6 +362,7 @@ usage(void)
           "  -n           do not run VACUUM after initialization\n"
           "  -F NUM       fill factor\n"
           "  -s NUM       scaling factor\n"
+          "  -q           quiet logging (one message each 5 seconds)\n"
           "  --foreign-keys\n"
           "               create foreign key constraints between tables\n"
           "  --index-tablespace=TABLESPACE\n"
@@ -1362,6 +1366,11 @@ init(bool is_no_vacuum)
    char        sql[256];
    int         i;
 
+   /* used to track elapsed time and estimate of the remaining time */
+   instr_time  start, diff;
+   double      elapsed_sec, remaining_sec;
+   int         log_interval = 1;
+
    if ((con = doConnect()) == NULL)
        exit(1);
 
@@ -1430,6 +1439,8 @@ init(bool is_no_vacuum)
    }
    PQclear(res);
 
+   INSTR_TIME_SET_CURRENT(start);
+
    for (i = 0; i < naccounts * scale; i++)
    {
        int         j = i + 1;
@@ -1441,10 +1452,42 @@ init(bool is_no_vacuum)
            exit(1);
        }
 
-       if (j % 100000 == 0)
-           fprintf(stderr, "%d of %d tuples (%d%%) done.\n",
-                   j, naccounts * scale,
-                   (int) (((int64) j * 100) / (naccounts * scale)));
+       /* If we want to stick with the original logging, print a message each
+        * 100k inserted rows. */
+       if ((! use_quiet) && (j % 100000 == 0))
+       {
+           INSTR_TIME_SET_CURRENT(diff);
+           INSTR_TIME_SUBTRACT(diff, start);
+
+           elapsed_sec = INSTR_TIME_GET_DOUBLE(diff);
+           remaining_sec = (scale * naccounts - j) * elapsed_sec / j;
+
+           fprintf(stderr, "%d of %d tuples (%d%%) done (elapsed %.2f s, remaining %.2f s).\n",
+                           j, naccounts * scale,
+                           (int) (((int64) j * 100) / (naccounts * scale)),
+                           elapsed_sec, remaining_sec);
+       }
+       /* let's not call the timing for each row, but only each 100 rows */
+       else if (use_quiet && (j % 100 == 0))
+       {
+           INSTR_TIME_SET_CURRENT(diff);
+           INSTR_TIME_SUBTRACT(diff, start);
+
+           elapsed_sec = INSTR_TIME_GET_DOUBLE(diff);
+           remaining_sec = (scale * naccounts - j) * elapsed_sec / j;
+
+           /* have we reached the next interval (or end)? */
+           if ((j == scale * naccounts) || (elapsed_sec >= log_interval * LOG_STEP_SECONDS)) {
+
+               fprintf(stderr, "%d of %d tuples (%d%%) done (elapsed %.2f s, remaining %.2f s).\n",
+                       j, naccounts * scale,
+                       (int) (((int64) j * 100) / (naccounts * scale)), elapsed_sec, remaining_sec);
+
+               /* skip to the next interval */
+               log_interval = (int)ceil(elapsed_sec/LOG_STEP_SECONDS);
+           }
+       }
+
    }
    if (PQputline(con, "\\.\n"))
    {
@@ -1987,7 +2030,7 @@ main(int argc, char **argv)
    state = (CState *) pg_malloc(sizeof(CState));
    memset(state, 0, sizeof(CState));
 
-   while ((c = getopt_long(argc, argv, "ih:nvp:dSNc:j:Crs:t:T:U:lf:D:F:M:", long_options, &optindex)) != -1)
+   while ((c = getopt_long(argc, argv, "ih:nvp:dqSNc:j:Crs:t:T:U:lf:D:F:M:", long_options, &optindex)) != -1)
    {
        switch (c)
        {
@@ -2095,6 +2138,9 @@ main(int argc, char **argv)
            case 'l':
                use_log = true;
                break;
+           case 'q':
+               use_quiet = true;
+               break;
            case 'f':
                ttype = 3;
                filename = pg_strdup(optarg);
@@ -2198,6 +2244,13 @@ main(int argc, char **argv)
        exit(1);
    }
 
+   /* -q may be used only with -i */
+   if (use_quiet && !is_init_mode)
+   {
+       fprintf(stderr, "quiet-logging is allowed only in initialization mode (-i)\n");
+       exit(1);
+   }
+
    /*
     * is_latencies only works with multiple threads in thread-based
     * implementations, not fork-based ones, because it supposes that the

diff --git a/doc/src/sgml/pgbench.sgml b/doc/src/sgml/pgbench.sgml
index 91530abe5b0ab737ca944bed6712760d1d84aae3..58686b1a8b5b7c135e89fc28789e966ed39a4cbb 100644 (file)
--- a/doc/src/sgml/pgbench.sgml
+++ b/doc/src/sgml/pgbench.sgml
@@ -189,6 +189,17 @@ pgbench <optional> <replaceable>options</> </optional> <replaceable>dbname</>
       </listitem>
      </varlistentry>
 
+     <varlistentry>
+      <term><option>-q</option></term>
+      <listitem>
+       <para>
+        Switch logging to quiet mode, producing only one progress message per 5
+        seconds. The default logging prints one message each 100000 rows, which
+        often outputs many lines per second (especially on good hardware).
+       </para>
+      </listitem>
+     </varlistentry>
+
      <varlistentry>
       <term><option>--foreign-keys</option></term>
       <listitem>