From cf03ff6c4e6f3e6627ddc1cc0986b940828bcf98 Mon Sep 17 00:00:00 2001 From: Tatsuo Ishii Date: Mon, 7 Jan 2013 11:13:44 +0900 Subject: [PATCH] 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. --- contrib/pgbench/pgbench.c | 63 +++++++++++++++++++++++++++++++++++---- doc/src/sgml/pgbench.sgml | 11 +++++++ 2 files changed, 69 insertions(+), 5 deletions(-) diff --git a/contrib/pgbench/pgbench.c b/contrib/pgbench/pgbench.c index 43c7f9a7bd..3ca120fa68 100644 --- a/contrib/pgbench/pgbench.c +++ b/contrib/pgbench/pgbench.c @@ -39,6 +39,7 @@ #include "portability/instr_time.h" #include +#include #ifndef WIN32 #include @@ -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 91530abe5b..58686b1a8b 100644 --- a/doc/src/sgml/pgbench.sgml +++ b/doc/src/sgml/pgbench.sgml @@ -189,6 +189,17 @@ pgbench options dbname + + + + + 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). + + + + -- 2.39.5