Enhance pgbench -l option to add timestamp. Patch contributed by Greg

Smith. Along with Japanese doc updation by Tasuo Ishii.

> This patch changes the way pgbench outputs its latency log files so that
> every transaction gets a timestamp and notes which transaction type was
> executed.  It's a one-line change that just dumps some additional
> information that was already sitting in that area of code. I also made a
> couple of documentation corrections and clarifications on some of the more
> confusing features of pgbench.
>
> It's straightforward to parse log files in this format to analyze what
> happened during the test at a higher level than was possible with the
> original format.  You can find some rough sample code to convert this
> latency format into CVS files and then into graphs at
> http://www.westnet.com/~gsmith/content/postgresql/pgbench.htm which I'll
> be expanding on once I get all my little patches sent in here.

3 files changed, 52 insertions, 9 deletions

diff --git a/contrib/pgbench/README.pgbench b/contrib/pgbench/README.pgbench
index 7fc683cef03..ef040c094d7 100644
--- a/contrib/pgbench/README.pgbench
+++ b/contrib/pgbench/README.pgbench
@@ -1,4 +1,4 @@
-$PostgreSQL: pgsql/contrib/pgbench/README.pgbench,v 1.16 2007/04/06 08:49:44 ishii Exp $
+$PostgreSQL: pgsql/contrib/pgbench/README.pgbench,v 1.17 2007/04/06 09:16:15 ishii Exp $
 
 pgbench README
 
@@ -96,10 +96,14 @@ o options
 		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 it can
+		be manually specified with this parameter.
 
 	-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
@@ -141,9 +145,22 @@ o options
 		with the name "pgbench_log.xxx", where xxx is the PID
 		of the pgbench process. The format of the log is:
 
-			client_id transaction_no time
+			client_id transaction_no time file_no time-epoch time-us
 
-		where time is measured in microseconds.
+		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.
+
+		Here are example outputs:
+
+		0 199 2241 0 1175850568 995598
+		0 200 2465 0 1175850568 998079
+		0 201 2513 0 1175850569 608
+		0 202 2038 0 1175850569 2663
 
 	-d
 		debug option.
@@ -165,6 +182,8 @@ o What is the "transaction" actually performed in pgbench?
 
   (7) end;
 
+If you specify -N, (4) and (5) aren't included in the transaction.
+
 o -f option
 
   This supports for reading transaction script from a specified
diff --git a/contrib/pgbench/README.pgbench_jis b/contrib/pgbench/README.pgbench_jis
index 5afa9324367..e06587a8791 100644
--- a/contrib/pgbench/README.pgbench_jis
+++ b/contrib/pgbench/README.pgbench_jis
@@ -1,4 +1,4 @@
-$PostgreSQL: pgsql/contrib/pgbench/README.pgbench_jis,v 1.17 2007/04/06 08:49:44 ishii Exp $
+$PostgreSQL: pgsql/contrib/pgbench/README.pgbench_jis,v 1.18 2007/04/06 09:16:16 ishii Exp $
 
 pgbench README
 
@@ -76,6 +76,13 @@ pgbench $B$K$O$$$m$$$m$J%*%W%7%g%s$,$"$j$^$9!%(B
 		$B%G%U%)%k%H$N%9%1!<%j%s%0%U%!%/%?!<$O(B 1 $B$G$9!%(B
 		-f $B%*%W%7%g%s$G;XDj$7$?%U%!%$%k$+$i%9%1!<%j%s%0%U%!%/(B
 		$B%?!<$r;2>H$9$k$K$O(B scale $B$H$$$&JQ?tL>$r;HMQ$7$^$9!%(B
+		$BCm0U(B: $B%9%1!<%j%s%0%U%!%/%?!<$O>/$J$/$H$b(B -c $B$G;XDj$5$l$kF1;~@\(B
+		$BB3%f!<%6?t$HF1$8$+$=$l$h$j$bBg$-$/$7$F$/$@$5$$!%$G$J$$$H!$(B
+		pgbench$B$N7k2L$O(BUPDATE$B$N6%9g$KBg$-$/1F6A$5$l$F$7$^$$$^$9!%(B
+		$BAH9~$_$N%Y%s%A%^!<%/%Q%?!<%s$G$O!$(Bbraches$B$N?t(B(=braches$B%F!<%V%k(B
+		$B$N9T?t(B)$B$,<+F0E*$K%9%1!<%j%s%0%U%!%/%?!<$K@_Dj$5$l$^$9!%(B
+		$B%+%9%?%`%/%(%j(B(-f$B%*%W%7%g%s;HMQ(B)$B$G$O!$%9%1!<%j%s%0%U%!%/%?!<$O(B
+		$B<+F0@_Dj$5$l$^$;$s!%(B
 
 -D varname=value
 
@@ -130,10 +137,24 @@ pgbench $B$K$O$$$m$$$m$J%*%W%7%g%s$,$"$j$^$9!%(B
 		$B%+%l%s%H%G%#%l%/%H%j0J2<$N(Bpgbench_log.xxx$B$H$$$&%U%!%$(B
 		$B%k$G$9!%%U%!%$%k$N%U%)!<%^%C%H$O!$(B
 		
-			$B%/%i%$%"%s%H(BID	$B%H%i%s%6%/%7%g%sHV9f(B  $B;~4V(B
+			$B%/%i%$%"%s%H(BID	$B%H%i%s%6%/%7%g%sHV9f(B  $B;~4V(B $B%U%!%$%kHV9f(B Unix$B%?%$%`(B($BIC(B) $B%*%U%;%C%H(B
 
 		$B$H$J$C$F$$$^$9!%;~4V$O%^%$%/%mICC10L$G$9!%(B
 
+		$B%U%!%$%kHV9f$O%F%9%H$K;H$o$l$?%U%!%$%k$NHV9f$G$9(B(-f$B%*%W%7%g%s(B
+		$B$rJ#?t;XDj$7$?$H$-$KM-MQ$G$9(B)$B!%(B
+
+		$B!V(BUnix$B%?%$%`(B($BIC(B) $B%*%U%;%C%H!W$O!$%H%i%s%6%/%7%g%s$,40N;$7$?$H(B
+		$B$-$N(BUNIX$B%(%]%C%/%?%$%`$H%^%$%/%mICC10L$N%*%U%;%C%H$G$9(B(ISO
+		8601$B%?%$%`%9%?%s%W$HIC$NCf$NC<?t(B)$B!%(B
+
+		$B%m%0$N=PNONc$r<($7$^$9!%(B
+
+		0 199 2241 0 1175850568 995598
+		0 200 2465 0 1175850568 998079
+		0 201 2513 0 1175850569 608
+		0 202 2038 0 1175850569 2663
+
 -d		$B%G%P%C%0%*%W%7%g%s!%MM!9$J>pJs$,I=<($5$l$^$9!%(B
 
 $B"#%G!<%?%Y!<%9$N=i4|2=(B
@@ -198,6 +219,8 @@ pgbench $B$G$O!$0J2<$N%7!<%1%s%9$rA4It40N;$7$F(B1$B%H%i%s%6%/%7%g%s$H?t$($F(
 
 (7) end;
 
+-N$B%*%W%7%g%s$r;HMQ$9$k$H!$(B(4)(5)$B$O<B9T$5$l$^$;$s!%(B
+
 $B"#F~NO%U%!%$%k$N%U%)!<%^%C%H(B
 
 -f $B%*%W%7%g%s$r;XDj$7$F%H%i%s%6%/%7%g%s$K4^$^$l$k(B SQL $B%3%^%s%I$NFbMF$r(B
diff --git a/contrib/pgbench/pgbench.c b/contrib/pgbench/pgbench.c
index 369b7669f12..2ffd24b25b9 100644
--- a/contrib/pgbench/pgbench.c
+++ b/contrib/pgbench/pgbench.c
@@ -1,5 +1,5 @@
 /*
- * $PostgreSQL: pgsql/contrib/pgbench/pgbench.c,v 1.63 2007/04/06 08:49:44 ishii Exp $
+ * $PostgreSQL: pgsql/contrib/pgbench/pgbench.c,v 1.64 2007/04/06 09:16:16 ishii Exp $
  *
  * pgbench: a simple benchmark program for PostgreSQL
  * written by Tatsuo Ishii
@@ -469,7 +469,8 @@ top:
 			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);
+			fprintf(LOGFILE, "%d %d %.0f %d %ld %ld\n",
+				st->id, st->cnt, diff, st->use_file, now.tv_sec,now.tv_usec);
 		}
 
 		if (commands[st->state]->type == SQL_COMMAND)