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

Reply via email to