postgresql/contrib/pg_test_timing/pg_test_timing.c

/*
 *	pg_test_timing.c
 *		tests overhead of timing calls and their monotonicity:  that
 * 		they always move forward
 */

#include "postgres_fe.h"

#include "getopt_long.h"
#include "portability/instr_time.h"

static const char *progname;

static int32 test_duration = 3;

static void handle_args(int argc, char *argv[]);
static void test_timing(int32);

int
main(int argc, char *argv[])
{
	progname = get_progname(argv[0]);

	handle_args(argc, argv);

	test_timing(test_duration);

	return 0;
}

static void
handle_args(int argc, char *argv[])
{
	static struct option long_options[] = {
		{"duration", required_argument, NULL, 'd'},
		{NULL, 0, NULL, 0}
	};
	int option;			/* Command line option */
	int	optindex = 0;	/* used by getopt_long */

	if (argc > 1)
	{
		if (strcmp(argv[1], "--help") == 0 || strcmp(argv[1], "-h") == 0 ||
			strcmp(argv[1], "-?") == 0)
		{
			printf("Usage: %s [-d DURATION]\n", progname);
			exit(0);
		}
		if (strcmp(argv[1], "--version") == 0 || strcmp(argv[1], "-V") == 0)
		{
			puts("pg_test_timing (PostgreSQL) " PG_VERSION);
			exit(0);
		}
	}

	while ((option = getopt_long(argc, argv, "d:",
								 long_options, &optindex)) != -1)
	{
		switch (option)
		{
			case 'd':
				test_duration = atoi(optarg);
				break;

			default:
				fprintf(stderr, "Try \"%s --help\" for more information.\n",
						progname);
				exit(1);
				break;
		}
	}

	if (argc > optind)
	{
		fprintf(stderr,
				"%s: too many command-line arguments (first is \"%s\")\n",
				progname, argv[optind]);
		fprintf(stderr, "Try \"%s --help\" for more information.\n",
				progname);
		exit(1);
	}

	if (test_duration > 0)
	{
		printf("Testing timing overhead for %d seconds.\n", test_duration);
	}
	else
	{
		fprintf(stderr,
				"%s: duration must be a positive integer (duration is \"%d\")\n",
				progname, test_duration);
		fprintf(stderr, "Try \"%s --help\" for more information.\n",
				progname);
		exit(1);
	}
}

static void
test_timing(int32 duration)
{
	uint64 total_time;
	int64 time_elapsed = 0;
	uint64 loop_count = 0;
	uint64 prev, cur;
	int32 diff, i, bits, found;

	instr_time start_time, end_time, temp;

	static int64 histogram[32];
	char	buf[100];

	total_time = duration > 0 ? duration * 1000000 : 0;

	INSTR_TIME_SET_CURRENT(start_time);
	cur = INSTR_TIME_GET_MICROSEC(start_time);

	while (time_elapsed < total_time)
	{
		prev = cur;
		INSTR_TIME_SET_CURRENT(temp);
		cur = INSTR_TIME_GET_MICROSEC(temp);
		diff = cur - prev;

		if (diff < 0)
		{
			printf("Detected clock going backwards in time.\n");
			printf("Time warp: %d microseconds\n", diff);
			exit(1);
		}

		bits = 0;
		while (diff)
		{
			diff >>= 1;
			bits++;
		}
		histogram[bits]++;

		loop_count++;
		INSTR_TIME_SUBTRACT(temp, start_time);
		time_elapsed = INSTR_TIME_GET_MICROSEC(temp);
	}

	INSTR_TIME_SET_CURRENT(end_time);

	INSTR_TIME_SUBTRACT(end_time, start_time);

	printf("Per loop time including overhead: %0.2f nsec\n",
			INSTR_TIME_GET_DOUBLE(end_time) * 1e9 / loop_count);
	printf("Histogram of timing durations:\n");
	printf("%9s: %10s %9s\n", "< usec", "count", "percent");

	found = 0;
	for (i = 31; i >= 0; i--)
	{
		if (found || histogram[i])
		{
			found = 1;
			/* lame hack to work around INT64_FORMAT deficiencies */
			snprintf(buf, sizeof(buf), INT64_FORMAT, histogram[i]);
			printf("%9ld: %10s %8.5f%%\n", 1l << i, buf,
				   (double) histogram[i] * 100 / loop_count);
		}
	}
}