On Mon, Feb 13, 2012 at 08:28:03PM -0500, Tom Lane wrote: > Robert Haas <robertmh...@gmail.com> writes: > > Instead of or in addition to a fixed number operations per test, maybe > > we should cut off each test after a certain amount of wall-clock time, > > like 15 seconds. > > +1, I was about to suggest the same thing. Running any of these tests > for a fixed number of iterations will result in drastic degradation of > accuracy as soon as the machine's behavior changes noticeably from what > you were expecting. Run them for a fixed time period instead. Or maybe > do a few, then check elapsed time and estimate a number of iterations to > use, if you're worried about the cost of doing gettimeofday after each > write.
Good idea, and it worked out very well. I changed the -o loops parameter to -s seconds which calls alarm() after (default) 2 seconds, and then once the operation completes, computes a duration per operation. The test now runs in 30 seconds and produces similar output to the longer version. -- Bruce Momjian <br...@momjian.us> http://momjian.us EnterpriseDB http://enterprisedb.com + It's impossible for everything to be true. +
diff --git a/contrib/pg_test_fsync/pg_test_fsync.c b/contrib/pg_test_fsync/pg_test_fsync.c new file mode 100644 index 3fcb087..8554426 *** a/contrib/pg_test_fsync/pg_test_fsync.c --- b/contrib/pg_test_fsync/pg_test_fsync.c *************** *** 27,41 **** #define NA_FORMAT "%18s" #define OPS_FORMAT "%9.3f ops/sec" static const char *progname; ! static int ops_per_test = 2000; static int needs_unlink = 0; static char full_buf[XLOG_SEG_SIZE], *buf, *filename = FSYNC_FILENAME; static struct timeval start_t, stop_t; static void handle_args(int argc, char *argv[]); --- 27,50 ---- #define NA_FORMAT "%18s" #define OPS_FORMAT "%9.3f ops/sec" + #define START_TIMER \ + do { \ + alarm_triggered = false; \ + alarm(secs_per_test); \ + gettimeofday(&start_t, NULL); \ + } while (0) + + static const char *progname; ! static int secs_per_test = 2; static int needs_unlink = 0; static char full_buf[XLOG_SEG_SIZE], *buf, *filename = FSYNC_FILENAME; static struct timeval start_t, stop_t; + static bool alarm_triggered = false; static void handle_args(int argc, char *argv[]); *************** static void test_sync(int writes_per_op) *** 46,57 **** static void test_open_syncs(void); static void test_open_sync(const char *msg, int writes_size); static void test_file_descriptor_sync(void); static void signal_cleanup(int sig); #ifdef HAVE_FSYNC_WRITETHROUGH static int pg_fsync_writethrough(int fd); #endif ! static void print_elapse(struct timeval start_t, struct timeval stop_t); static void die(const char *str); --- 55,67 ---- static void test_open_syncs(void); static void test_open_sync(const char *msg, int writes_size); static void test_file_descriptor_sync(void); + static void process_alarm(int sig); static void signal_cleanup(int sig); #ifdef HAVE_FSYNC_WRITETHROUGH static int pg_fsync_writethrough(int fd); #endif ! static void print_elapse(struct timeval start_t, struct timeval stop_t, int ops); static void die(const char *str); *************** main(int argc, char *argv[]) *** 65,70 **** --- 75,81 ---- /* Prevent leaving behind the test file */ signal(SIGINT, signal_cleanup); signal(SIGTERM, signal_cleanup); + signal(SIGALRM, process_alarm); #ifdef SIGHUP /* Not defined on win32 */ signal(SIGHUP, signal_cleanup); *************** handle_args(int argc, char *argv[]) *** 96,102 **** { static struct option long_options[] = { {"filename", required_argument, NULL, 'f'}, ! {"ops-per-test", required_argument, NULL, 'o'}, {NULL, 0, NULL, 0} }; int option; /* Command line option */ --- 107,113 ---- { static struct option long_options[] = { {"filename", required_argument, NULL, 'f'}, ! {"secs-per-test", required_argument, NULL, 's'}, {NULL, 0, NULL, 0} }; int option; /* Command line option */ *************** handle_args(int argc, char *argv[]) *** 117,123 **** } } ! while ((option = getopt_long(argc, argv, "f:o:", long_options, &optindex)) != -1) { switch (option) --- 128,134 ---- } } ! while ((option = getopt_long(argc, argv, "f:s:", long_options, &optindex)) != -1) { switch (option) *************** handle_args(int argc, char *argv[]) *** 126,133 **** filename = strdup(optarg); break; ! case 'o': ! ops_per_test = atoi(optarg); break; default: --- 137,144 ---- filename = strdup(optarg); break; ! case 's': ! secs_per_test = atoi(optarg); break; default: *************** handle_args(int argc, char *argv[]) *** 148,154 **** exit(1); } ! printf("%d operations per test\n", ops_per_test); #if PG_O_DIRECT != 0 printf("O_DIRECT supported on this platform for open_datasync and open_sync.\n"); #else --- 159,165 ---- exit(1); } ! printf("%d seconds per test\n", secs_per_test); #if PG_O_DIRECT != 0 printf("O_DIRECT supported on this platform for open_datasync and open_sync.\n"); #else *************** test_sync(int writes_per_op) *** 220,227 **** { if ((tmpfile = open(filename, O_RDWR | O_DSYNC | PG_O_DIRECT, 0)) == -1) die("could not open output file"); ! gettimeofday(&start_t, NULL); ! for (ops = 0; ops < ops_per_test; ops++) { for (writes = 0; writes < writes_per_op; writes++) if (write(tmpfile, buf, XLOG_BLCKSZ) != XLOG_BLCKSZ) --- 231,238 ---- { if ((tmpfile = open(filename, O_RDWR | O_DSYNC | PG_O_DIRECT, 0)) == -1) die("could not open output file"); ! START_TIMER; ! for (ops = 0; alarm_triggered == false; ops++) { for (writes = 0; writes < writes_per_op; writes++) if (write(tmpfile, buf, XLOG_BLCKSZ) != XLOG_BLCKSZ) *************** test_sync(int writes_per_op) *** 231,237 **** } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t); } #else printf(NA_FORMAT, "n/a\n"); --- 242,248 ---- } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t, ops); } #else printf(NA_FORMAT, "n/a\n"); *************** test_sync(int writes_per_op) *** 246,253 **** #ifdef HAVE_FDATASYNC if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); ! gettimeofday(&start_t, NULL); ! for (ops = 0; ops < ops_per_test; ops++) { for (writes = 0; writes < writes_per_op; writes++) if (write(tmpfile, buf, XLOG_BLCKSZ) != XLOG_BLCKSZ) --- 257,264 ---- #ifdef HAVE_FDATASYNC if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); ! START_TIMER; ! for (ops = 0; alarm_triggered == false; ops++) { for (writes = 0; writes < writes_per_op; writes++) if (write(tmpfile, buf, XLOG_BLCKSZ) != XLOG_BLCKSZ) *************** test_sync(int writes_per_op) *** 258,264 **** } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t); #else printf(NA_FORMAT, "n/a\n"); #endif --- 269,275 ---- } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t, ops); #else printf(NA_FORMAT, "n/a\n"); #endif *************** test_sync(int writes_per_op) *** 271,278 **** if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); ! gettimeofday(&start_t, NULL); ! for (ops = 0; ops < ops_per_test; ops++) { for (writes = 0; writes < writes_per_op; writes++) if (write(tmpfile, buf, XLOG_BLCKSZ) != XLOG_BLCKSZ) --- 282,289 ---- if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); ! START_TIMER; ! for (ops = 0; alarm_triggered == false; ops++) { for (writes = 0; writes < writes_per_op; writes++) if (write(tmpfile, buf, XLOG_BLCKSZ) != XLOG_BLCKSZ) *************** test_sync(int writes_per_op) *** 284,290 **** } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t); /* * If fsync_writethrough is available, test as well --- 295,301 ---- } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t, ops); /* * If fsync_writethrough is available, test as well *************** test_sync(int writes_per_op) *** 295,302 **** #ifdef HAVE_FSYNC_WRITETHROUGH if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); ! gettimeofday(&start_t, NULL); ! for (ops = 0; ops < ops_per_test; ops++) { for (writes = 0; writes < writes_per_op; writes++) if (write(tmpfile, buf, XLOG_BLCKSZ) != XLOG_BLCKSZ) --- 306,313 ---- #ifdef HAVE_FSYNC_WRITETHROUGH if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); ! START_TIMER; ! for (ops = 0; alarm_triggered == false; ops++) { for (writes = 0; writes < writes_per_op; writes++) if (write(tmpfile, buf, XLOG_BLCKSZ) != XLOG_BLCKSZ) *************** test_sync(int writes_per_op) *** 308,314 **** } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t); #else printf(NA_FORMAT, "n/a\n"); #endif --- 319,325 ---- } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t, ops); #else printf(NA_FORMAT, "n/a\n"); #endif *************** test_sync(int writes_per_op) *** 327,334 **** } else { ! gettimeofday(&start_t, NULL); ! for (ops = 0; ops < ops_per_test; ops++) { for (writes = 0; writes < writes_per_op; writes++) if (write(tmpfile, buf, XLOG_BLCKSZ) != XLOG_BLCKSZ) --- 338,345 ---- } else { ! START_TIMER; ! for (ops = 0; alarm_triggered == false; ops++) { for (writes = 0; writes < writes_per_op; writes++) if (write(tmpfile, buf, XLOG_BLCKSZ) != XLOG_BLCKSZ) *************** test_sync(int writes_per_op) *** 338,344 **** } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t); } #else printf(NA_FORMAT, "n/a\n"); --- 349,355 ---- } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t, ops); } #else printf(NA_FORMAT, "n/a\n"); *************** test_open_sync(const char *msg, int writ *** 385,392 **** printf(NA_FORMAT, "n/a*\n"); else { ! gettimeofday(&start_t, NULL); ! for (ops = 0; ops < ops_per_test; ops++) { for (writes = 0; writes < 16 / writes_size; writes++) if (write(tmpfile, buf, writes_size * 1024) != --- 396,403 ---- printf(NA_FORMAT, "n/a*\n"); else { ! START_TIMER; ! for (ops = 0; alarm_triggered == false; ops++) { for (writes = 0; writes < 16 / writes_size; writes++) if (write(tmpfile, buf, writes_size * 1024) != *************** test_open_sync(const char *msg, int writ *** 397,403 **** } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t); } #else printf(NA_FORMAT, "n/a\n"); --- 408,414 ---- } gettimeofday(&stop_t, NULL); close(tmpfile); ! print_elapse(start_t, stop_t, ops); } #else printf(NA_FORMAT, "n/a\n"); *************** test_file_descriptor_sync(void) *** 427,434 **** printf(LABEL_FORMAT, "write, fsync, close"); fflush(stdout); ! gettimeofday(&start_t, NULL); ! for (ops = 0; ops < ops_per_test; ops++) { if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); --- 438,445 ---- printf(LABEL_FORMAT, "write, fsync, close"); fflush(stdout); ! START_TIMER; ! for (ops = 0; alarm_triggered == false; ops++) { if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); *************** test_file_descriptor_sync(void) *** 447,453 **** close(tmpfile); } gettimeofday(&stop_t, NULL); ! print_elapse(start_t, stop_t); /* * Now open, write, close, open again and fsync This simulates processes --- 458,464 ---- close(tmpfile); } gettimeofday(&stop_t, NULL); ! print_elapse(start_t, stop_t, ops); /* * Now open, write, close, open again and fsync This simulates processes *************** test_file_descriptor_sync(void) *** 456,463 **** printf(LABEL_FORMAT, "write, close, fsync"); fflush(stdout); ! gettimeofday(&start_t, NULL); ! for (ops = 0; ops < ops_per_test; ops++) { if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); --- 467,474 ---- printf(LABEL_FORMAT, "write, close, fsync"); fflush(stdout); ! START_TIMER; ! for (ops = 0; alarm_triggered == false; ops++) { if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); *************** test_file_descriptor_sync(void) *** 472,478 **** close(tmpfile); } gettimeofday(&stop_t, NULL); ! print_elapse(start_t, stop_t); } --- 483,489 ---- close(tmpfile); } gettimeofday(&stop_t, NULL); ! print_elapse(start_t, stop_t, ops); } *************** test_non_sync(void) *** 489,496 **** printf(LABEL_FORMAT, "write"); fflush(stdout); ! gettimeofday(&start_t, NULL); ! for (ops = 0; ops < ops_per_test; ops++) { if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); --- 500,507 ---- printf(LABEL_FORMAT, "write"); fflush(stdout); ! START_TIMER; ! for (ops = 0; alarm_triggered == false; ops++) { if ((tmpfile = open(filename, O_RDWR, 0)) == -1) die("could not open output file"); *************** test_non_sync(void) *** 499,505 **** close(tmpfile); } gettimeofday(&stop_t, NULL); ! print_elapse(start_t, stop_t); } static void --- 510,516 ---- close(tmpfile); } gettimeofday(&stop_t, NULL); ! print_elapse(start_t, stop_t, ops); } static void *************** pg_fsync_writethrough(int fd) *** 533,548 **** * print out the writes per second for tests */ static void ! print_elapse(struct timeval start_t, struct timeval stop_t) { double total_time = (stop_t.tv_sec - start_t.tv_sec) + (stop_t.tv_usec - start_t.tv_usec) * 0.000001; ! double per_second = ops_per_test / total_time; printf(OPS_FORMAT "\n", per_second); } static void die(const char *str) { fprintf(stderr, "%s: %s\n", str, strerror(errno)); --- 544,565 ---- * print out the writes per second for tests */ static void ! print_elapse(struct timeval start_t, struct timeval stop_t, int ops) { double total_time = (stop_t.tv_sec - start_t.tv_sec) + (stop_t.tv_usec - start_t.tv_usec) * 0.000001; ! double per_second = ops / total_time; printf(OPS_FORMAT "\n", per_second); } static void + process_alarm(int sig) + { + alarm_triggered = true; + } + + static void die(const char *str) { fprintf(stderr, "%s: %s\n", str, strerror(errno)); diff --git a/doc/src/sgml/pgtestfsync.sgml b/doc/src/sgml/pgtestfsync.sgml new file mode 100644 index 2889059..ba9f0c1 *** a/doc/src/sgml/pgtestfsync.sgml --- b/doc/src/sgml/pgtestfsync.sgml *************** pg_test_fsync [options] *** 47,59 **** </varlistentry> <varlistentry> ! <term><option>-o</option></term> ! <term><option>--ops-per-test</option></term> <listitem> <para> ! Specifies the number of operations per test. The more operations per test, the greater the test's accuracy, but the longer it takes ! to run. The default is 2000. </para> </listitem> </varlistentry> --- 47,59 ---- </varlistentry> <varlistentry> ! <term><option>-s</option></term> ! <term><option>--secs-per-test</option></term> <listitem> <para> ! Specifies the number of seconds for each test. The more time per test, the greater the test's accuracy, but the longer it takes ! to run. The default is 2 seconds. </para> </listitem> </varlistentry>
-- Sent via pgsql-hackers mailing list (pgsql-hackers@postgresql.org) To make changes to your subscription: http://www.postgresql.org/mailpref/pgsql-hackers