Dne 30.08.2012 18:02, Robert Haas napsal:
On Fri, Aug 24, 2012 at 5:25 PM, Tomas Vondra <t...@fuzzy.cz> wrote:
This patch is a bit less polished (and more complex) than the other
pgbench patch I've sent a while back, and I'm not sure how to handle
the
Windows branch. That needs to be fixed during the commit fest.
What's the problem with the Windows branch?
Could you un-cuddle your brances to follow the PostgreSQL style, omit
braces around single-statement blocks, and remove the spurious
whitespace changes?
Done, or at least I don't see other formatting issues. Let me know if I
missed something.
Instead of having both use_log_agg and naggseconds, I think you can
get by with just having a single variable that is zero if aggregation
is not in use and is otherwise the aggregation period. On a related
note, you can't specify -A without an associated value, so there is
no
point in documenting a "default". As with your other patch, I
suggest
using a long option name like --latency-aggregate-interval and then
making the name of the variable in the code match the option name,
with s/-/_/g, for clarity.
Fixed. I've kept use_log_agg only and I've removed the default. Also
I've added one more check (that the total duration is a multiple of
the aggregation interval).
And just as with the sampling patch, I believe the "-l" should not be
enabled by default, but required. But if more people ask to enable it
whenever the aggregation or sampling is used, I'm fine with it.
Tomas
diff --git a/contrib/pgbench/pgbench.c b/contrib/pgbench/pgbench.c
index 00cab73..e044564 100644
--- a/contrib/pgbench/pgbench.c
+++ b/contrib/pgbench/pgbench.c
@@ -145,6 +145,7 @@ char *index_tablespace = NULL;
#define naccounts 100000
bool use_log; /* log transaction latencies to
a file */
+int use_log_agg; /* log aggregates instead of
individual transactions */
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 */
@@ -240,6 +241,18 @@ typedef struct
char *argv[MAX_ARGS]; /* command word list */
} Command;
+typedef struct
+{
+
+ long start_time; /* when does the interval start
*/
+ int cnt; /* number of transactions */
+ double min_duration; /* min/max durations */
+ double max_duration;
+ double sum; /* sum(duration),
sum(duration^2) - for estimates */
+ double sum2;
+
+} AggVals;
+
static Command **sql_files[MAX_FILES]; /* SQL script files */
static int num_files; /* number of script files */
static int num_commands = 0; /* total number of Command structs */
@@ -364,6 +377,8 @@ usage(void)
" -f FILENAME read transaction script from FILENAME\n"
" -j NUM number of threads (default: 1)\n"
" -l write transaction times to log file\n"
+ " --aggregate-interval NUM\n"
+ " aggregate data over NUM seconds\n"
" -M simple|extended|prepared\n"
" protocol for submitting queries to server
(default: simple)\n"
" -n do not run VACUUM before tests\n"
@@ -817,9 +832,22 @@ clientDone(CState *st, bool ok)
return false; /* always false */
}
+static
+void agg_vals_init(AggVals * aggs, instr_time start)
+{
+ aggs->cnt = 0;
+ aggs->sum = 0;
+ aggs->sum2 = 0;
+
+ aggs->min_duration = 3600 * 1000000.0; /* one hour */
+ aggs->max_duration = 0;
+
+ aggs->start_time = INSTR_TIME_GET_DOUBLE(start);
+}
+
/* return false iff client should be disconnected */
static bool
-doCustom(TState *thread, CState *st, instr_time *conn_time, FILE *logfile)
+doCustom(TState *thread, CState *st, instr_time *conn_time, FILE *logfile,
AggVals * agg)
{
PGresult *res;
Command **commands;
@@ -881,17 +909,70 @@ top:
diff = now;
INSTR_TIME_SUBTRACT(diff, st->txn_begin);
usec = (double) INSTR_TIME_GET_MICROSEC(diff);
-
+
+ /* should we aggregate the results or not? */
+ if (use_log_agg)
+ {
+
+ /* are we still in the same interval? if yes,
accumulate the
+ * values (print them otherwise) */
+ if (agg->start_time + use_log_agg >=
INSTR_TIME_GET_DOUBLE(now))
+ {
+
+ /* accumulate */
+ agg->cnt += 1;
+
+ agg->min_duration = (usec <
agg->min_duration) ? usec : agg->min_duration;
+ agg->max_duration = (usec >
agg->max_duration) ? usec : agg->max_duration;
+
+ agg->sum += usec;
+ agg->sum2 += usec * usec;
+
+ }
+ else
+ {
+
+ /* print */
+#ifndef WIN32
+ /* This is more than we really ought to
know about instr_time */
+ fprintf(logfile, "%ld %d %.0f %.0f %.0f
%.0f\n",
+
agg->start_time, agg->cnt, agg->sum, agg->sum2,
+
agg->min_duration, agg->max_duration);
+#else
+ /* On Windows, instr_time doesn't
provide a timestamp anyway */
+ // FIXME
+// fprintf(logfile, "%d %ld %.0f %d 0 0\n",
+// st->id,
aggvals.start_time, aggvals.cnt, usec, st->use_file);
+#endif
+ /* and now reset the values (include
the current) */
+ agg->cnt = 1;
+ agg->min_duration = usec;
+ agg->max_duration = usec;
+
+ agg->sum = usec;
+ agg->sum2 = usec * usec;
+
+ /* move to the next interval (there may
be transactions longer than
+ * the desired interval */
+ while (agg->start_time + use_log_agg <
INSTR_TIME_GET_DOUBLE(now))
+ agg->start_time =
agg->start_time + use_log_agg;
+ }
+
+ }
+ else
+ {
+ /* no, print raw transactions */
#ifndef WIN32
- /* This is more than we really ought to know about
instr_time */
- fprintf(logfile, "%d %d %.0f %d %ld %ld\n",
- st->id, st->cnt, usec, st->use_file,
- (long) now.tv_sec, (long) now.tv_usec);
+ /* This is more than we really ought to know
about instr_time */
+ fprintf(logfile, "%d %d %.0f %d %ld %ld\n",
+ st->id, st->cnt, usec,
st->use_file,
+ (long) now.tv_sec, (long)
now.tv_usec);
#else
- /* On Windows, instr_time doesn't provide a timestamp
anyway */
- fprintf(logfile, "%d %d %.0f %d 0 0\n",
- st->id, st->cnt, usec, st->use_file);
+ /* On Windows, instr_time doesn't provide a
timestamp anyway */
+ fprintf(logfile, "%d %d %.0f %d 0 0\n",
+ st->id, st->cnt, usec,
st->use_file);
#endif
+ }
}
if (commands[st->state]->type == SQL_COMMAND)
@@ -1918,6 +1999,7 @@ main(int argc, char **argv)
{"index-tablespace", required_argument, NULL, 3},
{"tablespace", required_argument, NULL, 2},
{"unlogged-tables", no_argument, &unlogged_tables, 1},
+ {"aggregate-interval", required_argument, NULL, 5},
{NULL, 0, NULL, 0}
};
@@ -2123,6 +2205,14 @@ main(int argc, char **argv)
case 3: /* index-tablespace */
index_tablespace = optarg;
break;
+ case 5:
+ use_log_agg = atoi(optarg);
+ if (use_log_agg <= 0)
+ {
+ fprintf(stderr, "invalid number of
seconds for aggregation: %d\n", use_log_agg);
+ exit(1);
+ }
+ break;
default:
fprintf(stderr, _("Try \"%s --help\" for more
information.\n"), progname);
exit(1);
@@ -2158,6 +2248,21 @@ main(int argc, char **argv)
exit(1);
}
+ if (use_log_agg > 0 && (! use_log)) {
+ fprintf(stderr, "log aggregation is allowed only when actually
logging transactions\n");
+ exit(1);
+ }
+
+ if ((duration > 0) && (use_log_agg > duration)) {
+ fprintf(stderr, "number of seconds for aggregation (%d) must
not be higher that test duration (%d)\n", use_log_agg, duration);
+ exit(1);
+ }
+
+ if ((duration > 0) && (use_log_agg > 0) && (duration % use_log_agg !=
0)) {
+ fprintf(stderr, "duration (%d) must be a multiple of
aggregation interval (%d)\n", duration, use_log_agg);
+ exit(1);
+ }
+
/*
* is_latencies only works with multiple threads in thread-based
* implementations, not fork-based ones, because it supposes that the
@@ -2416,7 +2521,9 @@ threadRun(void *arg)
int nstate = thread->nstate;
int remains = nstate; /* number of
remaining clients */
int i;
-
+
+ AggVals aggs;
+
result = xmalloc(sizeof(TResult));
INSTR_TIME_SET_ZERO(result->conn_time);
@@ -2452,6 +2559,8 @@ threadRun(void *arg)
INSTR_TIME_SET_CURRENT(result->conn_time);
INSTR_TIME_SUBTRACT(result->conn_time, thread->start_time);
+ agg_vals_init(&aggs, thread->start_time);
+
/* send start up queries in async manner */
for (i = 0; i < nstate; i++)
{
@@ -2460,7 +2569,7 @@ threadRun(void *arg)
int prev_ecnt = st->ecnt;
st->use_file = getrand(thread, 0, num_files - 1);
- if (!doCustom(thread, st, &result->conn_time, logfile))
+ if (!doCustom(thread, st, &result->conn_time, logfile, &aggs))
remains--; /* I've aborted */
if (st->ecnt > prev_ecnt && commands[st->state]->type ==
META_COMMAND)
@@ -2562,7 +2671,7 @@ threadRun(void *arg)
if (st->con && (FD_ISSET(PQsocket(st->con), &input_mask)
||
commands[st->state]->type == META_COMMAND))
{
- if (!doCustom(thread, st, &result->conn_time,
logfile))
+ if (!doCustom(thread, st, &result->conn_time,
logfile, &aggs))
remains--; /* I've aborted */
}
@@ -2589,7 +2698,6 @@ done:
return result;
}
-
/*
* Support for duration option: set timer_exceeded after so many seconds.
*/
@@ -2783,4 +2891,4 @@ pthread_join(pthread_t th, void **thread_return)
return 0;
}
-#endif /* WIN32 */
+#endif /* WIN32 */
\ No newline at end of file
diff --git a/doc/src/sgml/pgbench.sgml b/doc/src/sgml/pgbench.sgml
index 437fcea..47fa3ec 100644
--- a/doc/src/sgml/pgbench.sgml
+++ b/doc/src/sgml/pgbench.sgml
@@ -317,6 +317,18 @@ pgbench <optional> <replaceable>options</> </optional>
<replaceable>dbname</>
</varlistentry>
<varlistentry>
+ <term><option>--aggregate-interval</option>
<replaceable>seconds</></term>
+ <listitem>
+ <para>
+ Length of aggregation interval (in seconds). May be used only together
+ with <application>-l</application> - with this option, the log contains
+ per-interval summary (number of transactions, min/max latency and two
+ additional fields useful for variance estimation).
+ </para>
+ </listitem>
+ </varlistentry>
+
+ <varlistentry>
<term><option>-M</option> <replaceable>querymode</></term>
<listitem>
<para>
@@ -712,8 +724,9 @@ END;
<title>Per-Transaction Logging</title>
<para>
- With the <option>-l</> option, <application>pgbench</> writes the time
- taken by each transaction to a log file. The log file will be named
+ With the <option>-l</> option, and without the <option>-A</option>,
+ <application>pgbench</> writes the time taken by each transaction
+ to a log file. The log file will be named
<filename>pgbench_log.<replaceable>nnn</></filename>, where
<replaceable>nnn</> is the PID of the pgbench process.
If the <option>-j</> option is 2 or higher, creating multiple worker
@@ -750,6 +763,37 @@ END;
0 201 2513 0 1175850569 608
0 202 2038 0 1175850569 2663
</screen></para>
+
+ <title>Aggregated Logging</title>
+
+ <para>
+ With the <option>-A</option> option, the logs use a bit different format:
+
+<synopsis>
+<replaceable>interval_start</> <replaceable>num_of_transactions</>
<replaceable>latency_sum</> <replaceable>latency_2_sum</>
<replaceable>min_latency</> <replaceable>max_latency</>
+</synopsis>
+
+ where <replaceable>interval_start</> is the start of the interval (UNIX
epoch
+ format timestamp), <replaceable>num_of_transactions</> is the number of
transactions
+ within the interval, <replaceable>latency_sum</replaceable> is a sum of
latencies
+ (so you can compute average latency easily). The following two fields are
useful
+ for variance estimation - <replaceable>latency_sum</> is a sum of latencies
and
+ <replaceable>latency_2_sum</> is a sum of 2nd powers of latencies. The last
two
+ fields are <replaceable>min_latency</> - a minimum latency within the
interval, and
+ <replaceable>max_latency</> - maximum latency within the interval. A
transaction is
+ counted into the interval when it was committed.
+ </para>
+
+ <para>
+ Here is example outputs:
+<screen>
+1345828501 5601 1542744 483552416 61 2573
+1345828503 7884 1979812 565806736 60 1479
+1345828505 7208 1979422 567277552 59 1391
+1345828507 7685 1980268 569784714 60 1398
+1345828509 7073 1979779 573489941 236 1411
+</screen></para>
+
</refsect2>
<refsect2>
--
Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-hackers
