On 6.1.2013 05:07, Tatsuo Ishii wrote:
>> On 6.1.2013 03:03, Tatsuo Ishii wrote:
>>> As a committer, I have looked into the patch. I noticed two things:
>>>
>>> 1) In the help you put '-q' option into "Common options" section. I
>>> think this should be moved to "Initialization options" section because
>>> the option is only applied while initializing.
>>
>> Good point, moved.
>
> In addition to this, I'd suggest to add checking -q is only possible
> with -i option since without -i, -q is meaningless.
Done.
>> There's one more thing I've just noticed - the original version of the
>> patch simply removed the old logging, but this one keeps both old and
>> quiet logging. But the old logging still uses this:
>>
>> fprintf(stderr, "%d of %d tuples (%d%%) done.\n", ....
>>
>> while the new logging does this
>>
>> fprintf(stderr, "%d of %d tuples (%d%%) done (elapsed %.2f s,
>> remaining %.2f s).\n",
>>
>> i.e. it prints additional info about elapsed/estimated time. Do we want
>> to keep it this way (i.e. not to mess with the old logging) or do we
>> want to add these new fields to the old logging too?
>>
>> I suggest to add it to the old logging, to keep the log messages the
>> same, the only difference being the logging frequency.
>
> If we do so, probably '-q' is not appropeate option name any more,
> since the only difference between old logging and new one is, the
> former is printed every 10000 lines while the latter is every 5
> seconds, which is not really "quiet". What do you think?
AFAIK the "5 second" logging is much quieter in most cases (and a bit
more verbose when the initialization gets very slower), so I think the
"quiet" logging is not a bad match although maybe there's a better name.
This change (adding the elapsed/remaining fields to the original loggin)
would be consistent with this name, because considering a single line,
the "-q" is more verbose right now.
So I'd stick with the "-q" option and added the fields to the original
logging. But I'm not opposing a different name, I just can't think of a
better one.
Tomas
diff --git a/contrib/pgbench/pgbench.c b/contrib/pgbench/pgbench.c
index e376452..39bd8a5 100644
--- 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,33 @@ init(bool is_no_vacuum)
exit(1);
}
- if (j % 100000 == 0)
+ /* If we want to stick with the original logging, print a
message each
+ * 100k inserted rows. */
+ if ((! use_quiet) && (j % 100000 == 0))
fprintf(stderr, "%d of %d tuples (%d%%) done.\n",
- j, naccounts * scale,
- (int) (((int64) j * 100) / (naccounts *
scale)));
+ j, naccounts * scale,
+ (int) (((int64) j *
100) / (naccounts * scale)));
+ /* 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 +2021,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 +2129,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 +2235,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 91530ab..58686b1 100644
--- a/doc/src/sgml/pgbench.sgml
+++ b/doc/src/sgml/pgbench.sgml
@@ -190,6 +190,17 @@ pgbench <optional> <replaceable>options</> </optional>
<replaceable>dbname</>
</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>
<para>
--
Sent via pgsql-hackers mailing list ([email protected])
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
