The attached adds two new command line switches to pgbench:
-x: Generate extended detail in the latency log, including a timestamp
for each transaction
-X: Do extra cleanup after the run (vacuum on all tables, checkpoint)
before stopping the clock. This gives substantially more consistancy in
results between runs. Most pgbench results I see people present are so
short that they're skewed considerably by whether there was a checkpoint
in the middle of the run. This also allows testing situations with
various autovacuum settings fairly.
There's an update to the README describing the features, as well as
correcting/extending some of the existing documentation.
I generated the patch from the 8.2.3 release. Since pgbench runs the same
way unless you pass it one of the new flags, I was hoping this would be
considered for the next 8.2 update. I have a series of additional scripts
I'll be releasing shortly that do interesting analysis of this extended
latency data from pgbench (graphs of TPS and latency, that sort of thing),
and I'd hate for that to only be available on 8.3.
--
* Greg Smith [EMAIL PROTECTED] http://www.gregsmith.com Baltimore, MD
Index: contrib/pgbench/README.pgbench
===================================================================
RCS file: /var/lib/pgsql/cvs/postgresql/contrib/pgbench/README.pgbench,v
retrieving revision 1.1.1.1
diff -u -r1.1.1.1 README.pgbench
--- contrib/pgbench/README.pgbench 11 Feb 2007 23:57:37 -0000 1.1.1.1
+++ contrib/pgbench/README.pgbench 12 Feb 2007 00:07:35 -0000
@@ -94,10 +94,14 @@
default is 1. NOTE: scaling factor should be at least
as large as the largest number of clients you intend
to test; else you'll mostly be measuring update contention.
+ Regular (not initializing) runs using one of the
+ built-in tests will detect scale based on the number of
+ branches in the database. For custom (-f) runs this can
+ be manually specified.
-D varname=value
- Define a variable. It can be refereed to by a script
- provided by using -f option. Multile -D options are allowed.
+ Define a variable. It can be refered to by a script
+ provided by using -f option. Multiple -D options are allowed.
-U login
Specify db user's login name if it is different from
@@ -143,6 +147,24 @@
where time is measured in microseconds.
+ -x
+ If a logfile is being generated with -l, use an
+ extended format for the log that is:
+
+ client_id transaction_no time file_no time-epoch time-us
+
+ where time is measured in microseconds, the file_no is
+ which test file was used (useful when multiple were
+ specified with -f), and time-epoch/time-us are a
+ UNIX epoch format timestamp followed by an offset
+ in microseconds (suitable for creating a ISO 8601
+ timestamp with a fraction of a second) of when
+ the transaction completed.
+
+ -X Perform extra cleanup after the test has completed
+ (vacuums and a checkpoint) to make test results
+ more uniform
+
-d
debug option.
Index: contrib/pgbench/pgbench.c
===================================================================
RCS file: /var/lib/pgsql/cvs/postgresql/contrib/pgbench/pgbench.c,v
retrieving revision 1.1.1.1
diff -u -r1.1.1.1 pgbench.c
--- contrib/pgbench/pgbench.c 11 Feb 2007 23:57:37 -0000 1.1.1.1
+++ contrib/pgbench/pgbench.c 12 Feb 2007 00:07:28 -0000
@@ -76,6 +76,10 @@
bool use_log; /* log transaction latencies to
a file */
+bool extended_log; /* provide extended detailed in
latency log */
+
+bool extra_cleanup; /* do database cleanup after
test is over */
+
int remains; /* number of remaining
clients */
int is_connect; /* establish connection
for each transaction */
@@ -455,7 +459,13 @@
diff = (int) (now.tv_sec - st->txn_begin.tv_sec) *
1000000.0 +
(int) (now.tv_usec - st->txn_begin.tv_usec);
- fprintf(LOGFILE, "%d %d %.0f\n", st->id, st->cnt, diff);
+ if (extended_log)
+ fprintf(LOGFILE, "%d %d %.0f %d %ld %ld\n",
+ st->id, st->cnt, diff,
+ st->use_file, now.tv_sec,now.tv_usec);
+ else
+ fprintf(LOGFILE, "%d %d %.0f\n",
+ st->id, st->cnt, diff);
}
if (commands[st->state]->type == SQL_COMMAND)
@@ -1112,10 +1122,10 @@
printResults(
int ttype, CState * state,
struct timeval * tv1, struct timeval * tv2,
- struct timeval * tv3)
+ struct timeval * tv3, struct timeval * tv4)
{
double t1,
- t2;
+ t2,t3;
int i;
int normal_xacts = 0;
char *s;
@@ -1123,12 +1133,14 @@
for (i = 0; i < nclients; i++)
normal_xacts += state[i].cnt;
- t1 = (tv3->tv_sec - tv1->tv_sec) * 1000000.0 + (tv3->tv_usec -
tv1->tv_usec);
+ t1 = (tv4->tv_sec - tv1->tv_sec) * 1000000.0 + (tv4->tv_usec -
tv1->tv_usec);
t1 = normal_xacts * 1000000.0 / t1;
- t2 = (tv3->tv_sec - tv2->tv_sec) * 1000000.0 + (tv3->tv_usec -
tv2->tv_usec);
+ t2 = (tv4->tv_sec - tv2->tv_sec) * 1000000.0 + (tv4->tv_usec -
tv2->tv_usec);
t2 = normal_xacts * 1000000.0 / t2;
+ t3 = (tv4->tv_sec - tv3->tv_sec) * 1000000.0 + (tv4->tv_usec -
tv3->tv_usec);
+
if (ttype == 0)
s = "TPC-B (sort of)";
else if (ttype == 2)
@@ -1143,6 +1155,10 @@
printf("number of clients: %d\n", nclients);
printf("number of transactions per client: %d\n", nxacts);
printf("number of transactions actually processed: %d/%d\n",
normal_xacts, nxacts * nclients);
+ if (extra_cleanup)
+ {
+ printf("seconds to cleanup after test = %f\n", t3);
+ }
printf("tps = %f (including connections establishing)\n", t1);
printf("tps = %f (excluding connections establishing)\n", t2);
}
@@ -1165,7 +1181,8 @@
struct timeval tv1; /* start up time */
struct timeval tv2; /* after establishing all
connections to the
* backend */
- struct timeval tv3; /* end time */
+ struct timeval tv3; /* time extra cleanup started */
+ struct timeval tv4; /* end time */
int i;
@@ -1199,7 +1216,7 @@
memset(state, 0, sizeof(*state));
- while ((c = getopt(argc, argv, "ih:nvp:dc:t:s:U:P:CNSlf:D:")) != -1)
+ while ((c = getopt(argc, argv, "ih:nvp:dc:t:s:U:P:CNSlf:D:xX")) != -1)
{
switch (c)
{
@@ -1280,6 +1297,12 @@
case 'l':
use_log = true;
break;
+ case 'x':
+ extended_log = true;
+ break;
+ case 'X':
+ extra_cleanup = true;
+ break;
case 'f':
ttype = 3;
filename = optarg;
@@ -1564,9 +1587,46 @@
if (remains <= 0)
{ /* all done ? */
disconnect_all(state);
+
+ gettimeofday(&tv3, NULL); /* time before
cleanup started */
+
+ if (extra_cleanup)
+ {
+ fprintf(stderr, "starting extra cleanup...");
+
+ res = PQexec(con, "vacuum branches");
+ if (PQresultStatus(res) != PGRES_COMMAND_OK)
+ {
+ fprintf(stderr, "%s",
PQerrorMessage(con));
+ }
+ PQclear(res);
+
+ res = PQexec(con, "vacuum tellers");
+ if (PQresultStatus(res) != PGRES_COMMAND_OK)
+ {
+ fprintf(stderr, "%s",
PQerrorMessage(con));
+ }
+ PQclear(res);
+
+ res = PQexec(con, "vacuum accounts");
+ if (PQresultStatus(res) != PGRES_COMMAND_OK)
+ {
+ fprintf(stderr, "%s",
PQerrorMessage(con));
+ }
+ PQclear(res);
+
+ res = PQexec(con, "checkpoint");
+ if (PQresultStatus(res) != PGRES_COMMAND_OK)
+ {
+ fprintf(stderr, "%s",
PQerrorMessage(con));
+ }
+ PQclear(res);
+
+ }
+
/* get end time */
- gettimeofday(&tv3, NULL);
- printResults(ttype, state, &tv1, &tv2, &tv3);
+ gettimeofday(&tv4, NULL);
+ printResults(ttype, state, &tv1, &tv2, &tv3, &tv4);
if (LOGFILE)
fclose(LOGFILE);
exit(0);
---------------------------(end of broadcast)---------------------------
TIP 7: You can help support the PostgreSQL project by donating at
http://www.postgresql.org/about/donate
