Age Owner Branch data TLA Line data Source code
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
4401 rhaas@postgresql.org 26 :CBC 5 : main(int argc, char *argv[])
27 : : {
28 : : uint64 loop_count;
29 : :
2739 peter_e@gmx.net 30 : 5 : set_pglocale_pgservice(argv[0], PG_TEXTDOMAIN("pg_test_timing"));
4401 rhaas@postgresql.org 31 : 5 : progname = get_progname(argv[0]);
32 : :
33 : 5 : handle_args(argc, argv);
34 : :
4247 bruce@momjian.us 35 :UBC 0 : loop_count = test_timing(test_duration);
36 : :
37 : 0 : output(loop_count);
38 : :
4401 rhaas@postgresql.org 39 : 0 : return 0;
40 : : }
41 : :
42 : : static void
4401 rhaas@postgresql.org 43 :CBC 5 : 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 */
4326 bruce@momjian.us 51 : 5 : int optindex = 0; /* used by getopt_long */
52 : : unsigned long optval; /* used for option parsing */
53 : : char *endptr;
54 : :
4401 rhaas@postgresql.org 55 [ + - ]: 5 : if (argc > 1)
56 : : {
3940 bruce@momjian.us 57 [ + + - + ]: 5 : if (strcmp(argv[1], "--help") == 0 || strcmp(argv[1], "-?") == 0)
58 : : {
2739 peter_e@gmx.net 59 : 1 : printf(_("Usage: %s [-d DURATION]\n"), progname);
4401 rhaas@postgresql.org 60 : 1 : exit(0);
61 : : }
62 [ + + - + ]: 4 : if (strcmp(argv[1], "--version") == 0 || strcmp(argv[1], "-V") == 0)
63 : : {
64 : 1 : puts("pg_test_timing (PostgreSQL) " PG_VERSION);
65 : 1 : exit(0);
66 : : }
67 : : }
68 : :
69 : 3 : while ((option = getopt_long(argc, argv, "d:",
70 [ + - ]: 3 : long_options, &optindex)) != -1)
71 : : {
72 [ + + ]: 3 : switch (option)
73 : : {
74 : 2 : case 'd':
1294 michael@paquier.xyz 75 : 2 : errno = 0;
76 : 2 : optval = strtoul(optarg, &endptr, 10);
77 : :
78 [ + + + - ]: 2 : if (endptr == optarg || *endptr != '\0' ||
79 [ + - - + ]: 1 : errno != 0 || optval != (unsigned int) optval)
80 : : {
81 : 1 : fprintf(stderr, _("%s: invalid argument for option %s\n"),
82 : : progname, "--duration");
83 : 1 : fprintf(stderr, _("Try \"%s --help\" for more information.\n"), progname);
84 : 1 : exit(1);
85 : : }
86 : :
87 : 1 : test_duration = (unsigned int) optval;
88 [ + - ]: 1 : if (test_duration == 0)
89 : : {
90 : 1 : fprintf(stderr, _("%s: %s must be in range %u..%u\n"),
91 : : progname, "--duration", 1, UINT_MAX);
92 : 1 : exit(1);
93 : : }
4401 rhaas@postgresql.org 94 :UBC 0 : break;
95 : :
4401 rhaas@postgresql.org 96 :CBC 1 : default:
2739 peter_e@gmx.net 97 : 1 : fprintf(stderr, _("Try \"%s --help\" for more information.\n"),
98 : : progname);
4401 rhaas@postgresql.org 99 : 1 : exit(1);
100 : : break;
101 : : }
102 : : }
103 : :
4401 rhaas@postgresql.org 104 [ # # ]:UBC 0 : if (argc > optind)
105 : : {
106 : 0 : fprintf(stderr,
2739 peter_e@gmx.net 107 : 0 : _("%s: too many command-line arguments (first is \"%s\")\n"),
4401 rhaas@postgresql.org 108 : 0 : progname, argv[optind]);
2739 peter_e@gmx.net 109 : 0 : fprintf(stderr, _("Try \"%s --help\" for more information.\n"),
110 : : progname);
4401 rhaas@postgresql.org 111 : 0 : exit(1);
112 : : }
113 : :
114 : :
1294 michael@paquier.xyz 115 : 0 : printf(ngettext("Testing timing overhead for %u second.\n",
116 : : "Testing timing overhead for %u seconds.\n",
117 : : test_duration),
118 : : test_duration);
4401 rhaas@postgresql.org 119 : 0 : }
120 : :
121 : : static uint64
1294 michael@paquier.xyz 122 : 0 : test_timing(unsigned int duration)
123 : : {
124 : : uint64 total_time;
4326 bruce@momjian.us 125 : 0 : int64 time_elapsed = 0;
126 : 0 : uint64 loop_count = 0;
127 : : uint64 prev,
128 : : cur;
129 : : instr_time start_time,
130 : : end_time,
131 : : temp;
132 : :
3388 andres@anarazel.de 133 [ # # ]: 0 : total_time = duration > 0 ? duration * INT64CONST(1000000) : 0;
134 : :
4401 rhaas@postgresql.org 135 : 0 : INSTR_TIME_SET_CURRENT(start_time);
136 : 0 : cur = INSTR_TIME_GET_MICROSEC(start_time);
137 : :
138 [ # # ]: 0 : while (time_elapsed < total_time)
139 : : {
140 : : int32 diff,
3973 bruce@momjian.us 141 : 0 : bits = 0;
142 : :
4401 rhaas@postgresql.org 143 : 0 : prev = cur;
144 : 0 : INSTR_TIME_SET_CURRENT(temp);
145 : 0 : cur = INSTR_TIME_GET_MICROSEC(temp);
146 : 0 : diff = cur - prev;
147 : :
148 : : /* Did time go backwards? */
149 [ # # ]: 0 : if (diff < 0)
150 : : {
2739 peter_e@gmx.net 151 : 0 : fprintf(stderr, _("Detected clock going backwards in time.\n"));
152 : 0 : fprintf(stderr, _("Time warp: %d ms\n"), diff);
4401 rhaas@postgresql.org 153 : 0 : exit(1);
154 : : }
155 : :
156 : : /* What is the highest bit in the time diff? */
157 [ # # ]: 0 : while (diff)
158 : : {
159 : 0 : diff >>= 1;
160 : 0 : bits++;
161 : : }
162 : :
163 : : /* Update appropriate duration bucket */
164 : 0 : histogram[bits]++;
165 : :
166 : 0 : loop_count++;
167 : 0 : INSTR_TIME_SUBTRACT(temp, start_time);
168 : 0 : time_elapsed = INSTR_TIME_GET_MICROSEC(temp);
169 : : }
170 : :
171 : 0 : INSTR_TIME_SET_CURRENT(end_time);
172 : :
173 : 0 : INSTR_TIME_SUBTRACT(end_time, start_time);
174 : :
2739 peter_e@gmx.net 175 : 0 : printf(_("Per loop time including overhead: %0.2f ns\n"),
176 : : INSTR_TIME_GET_DOUBLE(end_time) * 1e9 / loop_count);
177 : :
4247 bruce@momjian.us 178 : 0 : return loop_count;
179 : : }
180 : :
181 : : static void
182 : 0 : output(uint64 loop_count)
183 : : {
3973 184 : 0 : int64 max_bit = 31,
185 : : i;
2423 peter_e@gmx.net 186 : 0 : char *header1 = _("< us");
187 : 0 : char *header2 = /* xgettext:no-c-format */ _("% of total");
188 : 0 : char *header3 = _("count");
189 : 0 : int len1 = strlen(header1);
190 : 0 : int len2 = strlen(header2);
191 : 0 : int len3 = strlen(header3);
192 : :
193 : : /* find highest bit value */
4247 bruce@momjian.us 194 [ # # # # ]: 0 : while (max_bit > 0 && histogram[max_bit] == 0)
195 : 0 : max_bit--;
196 : :
2739 peter_e@gmx.net 197 : 0 : printf(_("Histogram of timing durations:\n"));
2423 198 : 0 : printf("%*s %*s %*s\n",
199 : : Max(6, len1), header1,
200 : : Max(10, len2), header2,
201 : : Max(10, len3), header3);
202 : :
4247 bruce@momjian.us 203 [ # # ]: 0 : for (i = 0; i <= max_bit; i++)
1774 peter@eisentraut.org 204 : 0 : 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]);
4401 rhaas@postgresql.org 208 : 0 : }
|
