Re: Wrong result with pgbench -C option?

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(at)sraoss(dot)co(dot)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(at)momjian(dot)us> http://momjian.us
EnterpriseDB http://postgres.enterprisedb.com

+ If your life is a hard drive, Christ can be your backup. +