Thread: 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