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