Wrong result with pgbench -C option? - Mailing list pgsql-patches

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);