From e574f2a029d707201aad307983fa74972aceab4a Mon Sep 17 00:00:00 2001 From: Tatsuo Ishii Date: Fri, 6 Apr 2007 09:16:16 +0000 Subject: [PATCH] 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. --- contrib/pgbench/README.pgbench | 29 ++++++++++++++++++++++++----- contrib/pgbench/README.pgbench_jis | 27 +++++++++++++++++++++++++-- contrib/pgbench/pgbench.c | 5 +++-- 3 files changed, 52 insertions(+), 9 deletions(-) diff --git a/contrib/pgbench/README.pgbench b/contrib/pgbench/README.pgbench index 7fc683cef0..ef040c094d 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 5afa932436..e06587a879 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$NCpJs$,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$Otxn_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)