Обсуждение: Wrong result with pgbench -C option?
Hi,
I ran pgbench with -C option. Here is an output.
% pgbench -C -c 10 -t 100 bench
starting vacuum...end.
transaction type: TPC-B (sort of)
scaling factor: 1
number of clients: 10
number of transactions per client: 100
number of transactions actually processed: 1000/1000
tps = 83.209663 (including connections establishing)
tps = 83.209663 (excluding connections establishing)
The first tps was equal to the second tps. I think it is wrong because
pgbench with -C option connects per transaction.
The attached patch calculates total connection time. Here is an output
with revised pgbench.
% ./pgbench -C -c 10 -t 100 bench
starting vacuum...end.
transaction type: TPC-B (sort of)
scaling factor: 1
number of clients: 10
number of transactions per client: 100
number of transactions actually processed: 1000/1000
tps = 108.410991 (including connections establishing)
tps = 228.657561 (excluding connections establishing)
Regards,
--
Yoshiyuki Asaba
y-asaba@sraoss.co.jp
Index: pgbench.c
===================================================================
RCS file: /projects/cvsroot/pgsql/contrib/pgbench/pgbench.c,v
retrieving revision 1.74
diff -c -r1.74 pgbench.c
*** pgbench.c 15 Nov 2007 21:14:31 -0000 1.74
--- pgbench.c 6 Dec 2007 03:04:35 -0000
***************
*** 185,190 ****
--- 185,223 ----
"SELECT abalance FROM accounts WHERE aid = :aid;\n"
};
+ /* Connection overhead time */
+ static struct timeval conn_total_time = {0, 0};
+
+ /* Calculate total time */
+ static void
+ addTime(struct timeval *t1, struct timeval *t2, struct timeval *result)
+ {
+ int sec = t1->tv_sec + t2->tv_sec;
+ int usec = t1->tv_usec + t2->tv_usec;
+ if (usec >= 1000000)
+ {
+ usec -= 1000000;
+ sec++;
+ }
+ result->tv_sec = sec;
+ result->tv_usec = usec;
+ }
+
+ /* Calculate time difference */
+ static void
+ diffTime(struct timeval *t1, struct timeval *t2, struct timeval *result)
+ {
+ int sec = t1->tv_sec - t2->tv_sec;
+ int usec = t1->tv_usec - t2->tv_usec;
+ if (usec < 0)
+ {
+ usec += 1000000;
+ sec--;
+ }
+ result->tv_sec = sec;
+ result->tv_usec = usec;
+ }
+
static void
usage(void)
{
***************
*** 543,548 ****
--- 576,584 ----
if (st->con == NULL)
{
+ struct timeval t1, t2, t3;
+
+ gettimeofday(&t1, NULL);
if ((st->con = doConnect()) == NULL)
{
fprintf(stderr, "Client %d aborted in establishing connection.\n",
***************
*** 552,557 ****
--- 588,596 ----
st->con = NULL;
return;
}
+ gettimeofday(&t2, NULL);
+ diffTime(&t2, &t1, &t3);
+ addTime(&conn_total_time, &t3, &conn_total_time);
}
if (use_log && st->state == 0)
***************
*** 1162,1169 ****
static void
printResults(
int ttype, CState * state,
! struct timeval * tv1, struct timeval * tv2,
! struct timeval * tv3)
{
double t1,
t2;
--- 1201,1207 ----
static void
printResults(
int ttype, CState * state,
! struct timeval * start_time, struct timeval * end_time)
{
double t1,
t2;
***************
*** 1174,1183 ****
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 = normal_xacts * 1000000.0 / t1;
! t2 = (tv3->tv_sec - tv2->tv_sec) * 1000000.0 + (tv3->tv_usec - tv2->tv_usec);
t2 = normal_xacts * 1000000.0 / t2;
if (ttype == 0)
--- 1212,1222 ----
for (i = 0; i < nclients; i++)
normal_xacts += state[i].cnt;
! t1 = (end_time->tv_sec - start_time->tv_sec) * 1000000.0 + (end_time->tv_usec - start_time->tv_usec);
t1 = normal_xacts * 1000000.0 / t1;
! t2 = (end_time->tv_sec - start_time->tv_sec - conn_total_time.tv_sec) * 1000000.0 +
! (end_time->tv_usec - start_time->tv_usec - conn_total_time.tv_usec);
t2 = normal_xacts * 1000000.0 / t2;
if (ttype == 0)
***************
*** 1213,1222 ****
CState *state; /* status of clients */
! struct timeval tv1; /* start up time */
! struct timeval tv2; /* after establishing all connections to the
! * backend */
! struct timeval tv3; /* end time */
int i;
--- 1252,1259 ----
CState *state; /* status of clients */
! struct timeval start_time; /* start up time */
! struct timeval end_time; /* end time */
int i;
***************
*** 1533,1546 ****
PQfinish(con);
/* set random seed */
! gettimeofday(&tv1, NULL);
! srandom((unsigned int) tv1.tv_usec);
/* get start up time */
! gettimeofday(&tv1, NULL);
if (is_connect == 0)
{
/* make connections to the database */
for (i = 0; i < nclients; i++)
{
--- 1570,1585 ----
PQfinish(con);
/* set random seed */
! gettimeofday(&start_time, NULL);
! srandom((unsigned int) start_time.tv_usec);
/* get start up time */
! gettimeofday(&start_time, NULL);
if (is_connect == 0)
{
+ struct timeval t, now;
+
/* make connections to the database */
for (i = 0; i < nclients; i++)
{
***************
*** 1548,1558 ****
if ((state[i].con = doConnect()) == NULL)
exit(1);
}
}
- /* time after connections set up */
- gettimeofday(&tv2, NULL);
-
/* process bultin SQL scripts */
switch (ttype)
{
--- 1587,1598 ----
if ((state[i].con = doConnect()) == NULL)
exit(1);
}
+ /* time after connections set up */
+ gettimeofday(&now, NULL);
+ diffTime(&now, &start_time, &t);
+ addTime(&conn_total_time, &t, &conn_total_time);
}
/* process bultin SQL scripts */
switch (ttype)
{
***************
*** 1599,1606 ****
{ /* all done ? */
disconnect_all(state);
/* get end time */
! gettimeofday(&tv3, NULL);
! printResults(ttype, state, &tv1, &tv2, &tv3);
if (LOGFILE)
fclose(LOGFILE);
exit(0);
--- 1639,1646 ----
{ /* all done ? */
disconnect_all(state);
/* get end time */
! gettimeofday(&end_time, NULL);
! printResults(ttype, state, &start_time, &end_time);
if (LOGFILE)
fclose(LOGFILE);
exit(0);
This has been saved for the 8.4 release:
http://momjian.postgresql.org/cgi-bin/pgpatches_hold
---------------------------------------------------------------------------
Yoshiyuki Asaba wrote:
> Hi,
>
> I ran pgbench with -C option. Here is an output.
>
> % pgbench -C -c 10 -t 100 bench
> starting vacuum...end.
> transaction type: TPC-B (sort of)
> scaling factor: 1
> number of clients: 10
> number of transactions per client: 100
> number of transactions actually processed: 1000/1000
> tps = 83.209663 (including connections establishing)
> tps = 83.209663 (excluding connections establishing)
>
> The first tps was equal to the second tps. I think it is wrong because
> pgbench with -C option connects per transaction.
>
> The attached patch calculates total connection time. Here is an output
> with revised pgbench.
>
> % ./pgbench -C -c 10 -t 100 bench
> starting vacuum...end.
> transaction type: TPC-B (sort of)
> scaling factor: 1
> number of clients: 10
> number of transactions per client: 100
> number of transactions actually processed: 1000/1000
> tps = 108.410991 (including connections establishing)
> tps = 228.657561 (excluding connections establishing)
>
> Regards,
> --
> Yoshiyuki Asaba
> y-asaba@sraoss.co.jp
> Index: pgbench.c
> ===================================================================
> RCS file: /projects/cvsroot/pgsql/contrib/pgbench/pgbench.c,v
> retrieving revision 1.74
> diff -c -r1.74 pgbench.c
> *** pgbench.c 15 Nov 2007 21:14:31 -0000 1.74
> --- pgbench.c 6 Dec 2007 03:04:35 -0000
> ***************
> *** 185,190 ****
> --- 185,223 ----
> "SELECT abalance FROM accounts WHERE aid = :aid;\n"
> };
>
> + /* Connection overhead time */
> + static struct timeval conn_total_time = {0, 0};
> +
> + /* Calculate total time */
> + static void
> + addTime(struct timeval *t1, struct timeval *t2, struct timeval *result)
> + {
> + int sec = t1->tv_sec + t2->tv_sec;
> + int usec = t1->tv_usec + t2->tv_usec;
> + if (usec >= 1000000)
> + {
> + usec -= 1000000;
> + sec++;
> + }
> + result->tv_sec = sec;
> + result->tv_usec = usec;
> + }
> +
> + /* Calculate time difference */
> + static void
> + diffTime(struct timeval *t1, struct timeval *t2, struct timeval *result)
> + {
> + int sec = t1->tv_sec - t2->tv_sec;
> + int usec = t1->tv_usec - t2->tv_usec;
> + if (usec < 0)
> + {
> + usec += 1000000;
> + sec--;
> + }
> + result->tv_sec = sec;
> + result->tv_usec = usec;
> + }
> +
> static void
> usage(void)
> {
> ***************
> *** 543,548 ****
> --- 576,584 ----
>
> if (st->con == NULL)
> {
> + struct timeval t1, t2, t3;
> +
> + gettimeofday(&t1, NULL);
> if ((st->con = doConnect()) == NULL)
> {
> fprintf(stderr, "Client %d aborted in establishing connection.\n",
> ***************
> *** 552,557 ****
> --- 588,596 ----
> st->con = NULL;
> return;
> }
> + gettimeofday(&t2, NULL);
> + diffTime(&t2, &t1, &t3);
> + addTime(&conn_total_time, &t3, &conn_total_time);
> }
>
> if (use_log && st->state == 0)
> ***************
> *** 1162,1169 ****
> static void
> printResults(
> int ttype, CState * state,
> ! struct timeval * tv1, struct timeval * tv2,
> ! struct timeval * tv3)
> {
> double t1,
> t2;
> --- 1201,1207 ----
> static void
> printResults(
> int ttype, CState * state,
> ! struct timeval * start_time, struct timeval * end_time)
> {
> double t1,
> t2;
> ***************
> *** 1174,1183 ****
> 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 = normal_xacts * 1000000.0 / t1;
>
> ! t2 = (tv3->tv_sec - tv2->tv_sec) * 1000000.0 + (tv3->tv_usec - tv2->tv_usec);
> t2 = normal_xacts * 1000000.0 / t2;
>
> if (ttype == 0)
> --- 1212,1222 ----
> for (i = 0; i < nclients; i++)
> normal_xacts += state[i].cnt;
>
> ! t1 = (end_time->tv_sec - start_time->tv_sec) * 1000000.0 + (end_time->tv_usec - start_time->tv_usec);
> t1 = normal_xacts * 1000000.0 / t1;
>
> ! t2 = (end_time->tv_sec - start_time->tv_sec - conn_total_time.tv_sec) * 1000000.0 +
> ! (end_time->tv_usec - start_time->tv_usec - conn_total_time.tv_usec);
> t2 = normal_xacts * 1000000.0 / t2;
>
> if (ttype == 0)
> ***************
> *** 1213,1222 ****
>
> CState *state; /* status of clients */
>
> ! struct timeval tv1; /* start up time */
> ! struct timeval tv2; /* after establishing all connections to the
> ! * backend */
> ! struct timeval tv3; /* end time */
>
> int i;
>
> --- 1252,1259 ----
>
> CState *state; /* status of clients */
>
> ! struct timeval start_time; /* start up time */
> ! struct timeval end_time; /* end time */
>
> int i;
>
> ***************
> *** 1533,1546 ****
> PQfinish(con);
>
> /* set random seed */
> ! gettimeofday(&tv1, NULL);
> ! srandom((unsigned int) tv1.tv_usec);
>
> /* get start up time */
> ! gettimeofday(&tv1, NULL);
>
> if (is_connect == 0)
> {
> /* make connections to the database */
> for (i = 0; i < nclients; i++)
> {
> --- 1570,1585 ----
> PQfinish(con);
>
> /* set random seed */
> ! gettimeofday(&start_time, NULL);
> ! srandom((unsigned int) start_time.tv_usec);
>
> /* get start up time */
> ! gettimeofday(&start_time, NULL);
>
> if (is_connect == 0)
> {
> + struct timeval t, now;
> +
> /* make connections to the database */
> for (i = 0; i < nclients; i++)
> {
> ***************
> *** 1548,1558 ****
> if ((state[i].con = doConnect()) == NULL)
> exit(1);
> }
> }
>
> - /* time after connections set up */
> - gettimeofday(&tv2, NULL);
> -
> /* process bultin SQL scripts */
> switch (ttype)
> {
> --- 1587,1598 ----
> if ((state[i].con = doConnect()) == NULL)
> exit(1);
> }
> + /* time after connections set up */
> + gettimeofday(&now, NULL);
> + diffTime(&now, &start_time, &t);
> + addTime(&conn_total_time, &t, &conn_total_time);
> }
>
> /* process bultin SQL scripts */
> switch (ttype)
> {
> ***************
> *** 1599,1606 ****
> { /* all done ? */
> disconnect_all(state);
> /* get end time */
> ! gettimeofday(&tv3, NULL);
> ! printResults(ttype, state, &tv1, &tv2, &tv3);
> if (LOGFILE)
> fclose(LOGFILE);
> exit(0);
> --- 1639,1646 ----
> { /* all done ? */
> disconnect_all(state);
> /* get end time */
> ! gettimeofday(&end_time, NULL);
> ! printResults(ttype, state, &start_time, &end_time);
> if (LOGFILE)
> fclose(LOGFILE);
> exit(0);
>
> ---------------------------(end of broadcast)---------------------------
> TIP 6: explain analyze is your friend
--
Bruce Momjian <bruce@momjian.us> http://momjian.us
EnterpriseDB http://postgres.enterprisedb.com
+ If your life is a hard drive, Christ can be your backup. +
Patch applied. Thanks. -- Tatsuo Ishii SRA OSS, Inc. Japan > Hi, > > I ran pgbench with -C option. Here is an output. > > % pgbench -C -c 10 -t 100 bench > starting vacuum...end. > transaction type: TPC-B (sort of) > scaling factor: 1 > number of clients: 10 > number of transactions per client: 100 > number of transactions actually processed: 1000/1000 > tps = 83.209663 (including connections establishing) > tps = 83.209663 (excluding connections establishing) > > The first tps was equal to the second tps. I think it is wrong because > pgbench with -C option connects per transaction. > > The attached patch calculates total connection time. Here is an output > with revised pgbench. > > % ./pgbench -C -c 10 -t 100 bench > starting vacuum...end. > transaction type: TPC-B (sort of) > scaling factor: 1 > number of clients: 10 > number of transactions per client: 100 > number of transactions actually processed: 1000/1000 > tps = 108.410991 (including connections establishing) > tps = 228.657561 (excluding connections establishing) > > Regards, > -- > Yoshiyuki Asaba > y-asaba@sraoss.co.jp