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
main(int argc,char * argv[])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
handle_args(int argc,char * argv[])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",
96 test_duration),
97 test_duration);
98 }
99 else
100 {
101 fprintf(stderr,
102 _("%s: duration must be a positive integer (duration is \"%d\")\n"),
103 progname, test_duration);
104 fprintf(stderr, _("Try \"%s --help\" for more information.\n"),
105 progname);
106 exit(1);
107 }
108 }
109
110 static uint64
test_timing(int32 duration)111 test_timing(int32 duration)
112 {
113 uint64 total_time;
114 int64 time_elapsed = 0;
115 uint64 loop_count = 0;
116 uint64 prev,
117 cur;
118 instr_time start_time,
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;
133 INSTR_TIME_SET_CURRENT(temp);
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
output(uint64 loop_count)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 }
204