PostgreSQL Source Code  git master
pg_test_timing.c
Go to the documentation of this file.
1 /*
2  * pg_test_timing.c
3  * tests overhead of timing calls and their monotonicity: that
4  * they always move forward
5  */
6 
7 #include "postgres_fe.h"
8 
9 #include <limits.h>
10 
11 #include "getopt_long.h"
12 #include "portability/instr_time.h"
13 
14 static const char *progname;
15 
16 static unsigned int test_duration = 3;
17 
18 static void handle_args(int argc, char *argv[]);
19 static uint64 test_timing(unsigned int duration);
20 static void output(uint64 loop_count);
21 
22 /* record duration in powers of 2 microseconds */
23 long long int histogram[32];
24 
25 int
26 main(int argc, char *argv[])
27 {
28  uint64 loop_count;
29 
30  set_pglocale_pgservice(argv[0], PG_TEXTDOMAIN("pg_test_timing"));
31  progname = get_progname(argv[0]);
32 
33  handle_args(argc, argv);
34 
35  loop_count = test_timing(test_duration);
36 
37  output(loop_count);
38 
39  return 0;
40 }
41 
42 static void
43 handle_args(int argc, char *argv[])
44 {
45  static struct option long_options[] = {
46  {"duration", required_argument, NULL, 'd'},
47  {NULL, 0, NULL, 0}
48  };
49 
50  int option; /* Command line option */
51  int optindex = 0; /* used by getopt_long */
52  unsigned long optval; /* used for option parsing */
53  char *endptr;
54 
55  if (argc > 1)
56  {
57  if (strcmp(argv[1], "--help") == 0 || strcmp(argv[1], "-?") == 0)
58  {
59  printf(_("Usage: %s [-d DURATION]\n"), progname);
60  exit(0);
61  }
62  if (strcmp(argv[1], "--version") == 0 || strcmp(argv[1], "-V") == 0)
63  {
64  puts("pg_test_timing (PostgreSQL) " PG_VERSION);
65  exit(0);
66  }
67  }
68 
69  while ((option = getopt_long(argc, argv, "d:",
70  long_options, &optindex)) != -1)
71  {
72  switch (option)
73  {
74  case 'd':
75  errno = 0;
76  optval = strtoul(optarg, &endptr, 10);
77 
78  if (endptr == optarg || *endptr != '\0' ||
79  errno != 0 || optval != (unsigned int) optval)
80  {
81  fprintf(stderr, _("%s: invalid argument for option %s\n"),
82  progname, "--duration");
83  fprintf(stderr, _("Try \"%s --help\" for more information.\n"), progname);
84  exit(1);
85  }
86 
87  test_duration = (unsigned int) optval;
88  if (test_duration == 0)
89  {
90  fprintf(stderr, _("%s: %s must be in range %u..%u\n"),
91  progname, "--duration", 1, UINT_MAX);
92  exit(1);
93  }
94  break;
95 
96  default:
97  fprintf(stderr, _("Try \"%s --help\" for more information.\n"),
98  progname);
99  exit(1);
100  break;
101  }
102  }
103 
104  if (argc > optind)
105  {
106  fprintf(stderr,
107  _("%s: too many command-line arguments (first is \"%s\")\n"),
108  progname, argv[optind]);
109  fprintf(stderr, _("Try \"%s --help\" for more information.\n"),
110  progname);
111  exit(1);
112  }
113 
114 
115  printf(ngettext("Testing timing overhead for %u second.\n",
116  "Testing timing overhead for %u seconds.\n",
117  test_duration),
118  test_duration);
119 }
120 
121 static uint64
122 test_timing(unsigned int duration)
123 {
124  uint64 total_time;
125  int64 time_elapsed = 0;
126  uint64 loop_count = 0;
127  uint64 prev,
128  cur;
130  end_time,
131  temp;
132 
133  total_time = duration > 0 ? duration * INT64CONST(1000000) : 0;
134 
135  INSTR_TIME_SET_CURRENT(start_time);
136  cur = INSTR_TIME_GET_MICROSEC(start_time);
137 
138  while (time_elapsed < total_time)
139  {
140  int32 diff,
141  bits = 0;
142 
143  prev = cur;
145  cur = INSTR_TIME_GET_MICROSEC(temp);
146  diff = cur - prev;
147 
148  /* Did time go backwards? */
149  if (diff < 0)
150  {
151  fprintf(stderr, _("Detected clock going backwards in time.\n"));
152  fprintf(stderr, _("Time warp: %d ms\n"), diff);
153  exit(1);
154  }
155 
156  /* What is the highest bit in the time diff? */
157  while (diff)
158  {
159  diff >>= 1;
160  bits++;
161  }
162 
163  /* Update appropriate duration bucket */
164  histogram[bits]++;
165 
166  loop_count++;
167  INSTR_TIME_SUBTRACT(temp, start_time);
168  time_elapsed = INSTR_TIME_GET_MICROSEC(temp);
169  }
170 
171  INSTR_TIME_SET_CURRENT(end_time);
172 
173  INSTR_TIME_SUBTRACT(end_time, start_time);
174 
175  printf(_("Per loop time including overhead: %0.2f ns\n"),
176  INSTR_TIME_GET_DOUBLE(end_time) * 1e9 / loop_count);
177 
178  return loop_count;
179 }
180 
181 static void
182 output(uint64 loop_count)
183 {
184  int64 max_bit = 31,
185  i;
186  char *header1 = _("< us");
187  char *header2 = /* xgettext:no-c-format */ _("% of total");
188  char *header3 = _("count");
189  int len1 = strlen(header1);
190  int len2 = strlen(header2);
191  int len3 = strlen(header3);
192 
193  /* find highest bit value */
194  while (max_bit > 0 && histogram[max_bit] == 0)
195  max_bit--;
196 
197  printf(_("Histogram of timing durations:\n"));
198  printf("%*s %*s %*s\n",
199  Max(6, len1), header1,
200  Max(10, len2), header2,
201  Max(10, len3), header3);
202 
203  for (i = 0; i <= max_bit; i++)
204  printf("%*ld %*.5f %*lld\n",
205  Max(6, len1), 1l << i,
206  Max(10, len2) - 1, (double) histogram[i] * 100 / loop_count,
207  Max(10, len3), histogram[i]);
208 }
static uint64 test_timing(unsigned int duration)
const char * get_progname(const char *argv0)
Definition: path.c:453
static void output(uint64 loop_count)
int getopt_long(int argc, char *const argv[], const char *optstring, const struct option *longopts, int *longindex)
Definition: getopt_long.c:57
struct timeval instr_time
Definition: instr_time.h:150
struct cursor * cur
Definition: ecpg.c:28
#define printf(...)
Definition: port.h:221
#define INSTR_TIME_GET_DOUBLE(t)
Definition: instr_time.h:199
#define fprintf
Definition: port.h:219
int duration
Definition: pgbench.c:147
static time_t start_time
Definition: pg_ctl.c:99
signed int int32
Definition: c.h:363
int64 end_time
Definition: pgbench.c:148
#define required_argument
Definition: getopt_long.h:25
long long int histogram[32]
int optind
Definition: getopt.c:50
#define INSTR_TIME_SUBTRACT(x, y)
Definition: instr_time.h:170
int main(int argc, char *argv[])
#define ngettext(s, p, n)
Definition: c.h:1124
#define PG_TEXTDOMAIN(domain)
Definition: c.h:1157
#define Max(x, y)
Definition: c.h:922
#define INSTR_TIME_GET_MICROSEC(t)
Definition: instr_time.h:205
static void handle_args(int argc, char *argv[])
#define INSTR_TIME_SET_CURRENT(t)
Definition: instr_time.h:156
static const char * progname
void set_pglocale_pgservice(const char *argv0, const char *app)
Definition: exec.c:434
char * optarg
Definition: getopt.c:52
int i
#define _(x)
Definition: elog.c:88
static unsigned int test_duration