1 /*
2 * Copyright (c) 2017 Cyril Hrubis <chrubis@suse.cz>
3 *
4 * This program is free software: you can redistribute it and/or modify
5 * it under the terms of the GNU General Public License as published by
6 * the Free Software Foundation, either version 2 of the License, or
7 * (at your option) any later version.
8 *
9 * This program is distributed in the hope that it will be useful,
10 * but WITHOUT ANY WARRANTY; without even the implied warranty of
11 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
12 * GNU General Public License for more details.
13 *
14 * You should have received a copy of the GNU General Public License
15 * along with this program. If not, see <http://www.gnu.org/licenses/>.
16 */
17
18 #include <sys/prctl.h>
19 #include <stdlib.h>
20 #include <stdio.h>
21 #include <limits.h>
22
23 #define TST_NO_DEFAULT_MAIN
24 #include "tst_test.h"
25 #include "tst_clocks.h"
26 #include "tst_timer_test.h"
27
28 #define MAX_SAMPLES 500
29
30 static const char *scall;
31 static void (*setup)(void);
32 static void (*cleanup)(void);
33 static int (*sample)(int clk_id, long long usec);
34 static struct tst_test *test;
35
36 static long long *samples;
37 static unsigned int cur_sample;
38 static unsigned int monotonic_resolution;
39 static unsigned int timerslack;
40
41 static char *print_frequency_plot;
42 static char *file_name;
43 static char *str_sleep_time;
44 static char *str_sample_cnt;
45 static int sleep_time = -1;
46 static int sample_cnt;
47
print_line(char c,int len)48 static void print_line(char c, int len)
49 {
50 while (len-- > 0)
51 fputc(c, stderr);
52 }
53
ceilu(float f)54 static unsigned int ceilu(float f)
55 {
56 if (f - (int)f > 0)
57 return (unsigned int)f + 1;
58
59 return (unsigned int)f;
60 }
61
flooru(float f)62 static unsigned int flooru(float f)
63 {
64 return (unsigned int)f;
65 }
66
bucket_len(unsigned int bucket,unsigned int max_bucket,unsigned int cols)67 static float bucket_len(unsigned int bucket, unsigned int max_bucket,
68 unsigned int cols)
69 {
70 return 1.00 * bucket * cols / max_bucket;
71 }
72
73 static const char *table_heading = " Time: us ";
74
75 /*
76 * Line Header: '10023 | '
77 */
header_len(long long max_sample)78 static unsigned int header_len(long long max_sample)
79 {
80 unsigned int l = 1;
81
82 while (max_sample/=10)
83 l++;
84
85 return MAX(strlen(table_heading) + 2, l + 3);
86 }
87
frequency_plot(void)88 static void frequency_plot(void)
89 {
90 unsigned int cols = 80;
91 unsigned int rows = 20;
92 unsigned int i, buckets[rows];
93 long long max_sample = samples[0];
94 long long min_sample = samples[cur_sample-1];
95 unsigned int line_header_len = header_len(max_sample);
96 unsigned int plot_line_len = cols - line_header_len;
97 unsigned int bucket_size;
98
99 memset(buckets, 0, sizeof(buckets));
100
101 /*
102 * We work with discrete data buckets smaller than 1 does not make
103 * sense as well as it's a good idea to keep buckets integer sized
104 * to avoid scaling artifacts.
105 */
106 bucket_size = MAX(1u, ceilu(1.00 * (max_sample - min_sample)/(rows-1)));
107
108 for (i = 0; i < cur_sample; i++) {
109 unsigned int bucket;
110 bucket = flooru(1.00 * (samples[i] - min_sample)/bucket_size);
111 buckets[bucket]++;
112 }
113
114 unsigned int max_bucket = buckets[0];
115 for (i = 1; i < rows; i++)
116 max_bucket = MAX(max_bucket, buckets[i]);
117
118 fprintf(stderr, "\n%*s| Frequency\n", line_header_len - 2, table_heading);
119
120 print_line('-', cols);
121 fputc('\n', stderr);
122
123 unsigned int l, r;
124
125 for (l = 0; l < rows; l++) {
126 if (buckets[l])
127 break;
128 }
129
130 for (r = rows-1; r > l; r--) {
131 if (buckets[r])
132 break;
133 }
134
135 for (i = l; i <= r; i++) {
136 float len = bucket_len(buckets[i], max_bucket, plot_line_len);
137
138 fprintf(stderr, "%*lli | ",
139 line_header_len - 3, min_sample + bucket_size*i);
140 print_line('*', len);
141
142 if ((len - (int)len) >= 0.5)
143 fputc('+', stderr);
144 else if ((len - (int)len) >= 0.25)
145 fputc('-', stderr);
146 else if (len < 0.25 && buckets[i])
147 fputc('.', stderr);
148
149 fputc('\n', stderr);
150 }
151
152 print_line('-', cols);
153 fputc('\n', stderr);
154
155 float scale = 1.00 * plot_line_len / max_bucket;
156
157 fprintf(stderr,
158 "%*uus | 1 sample = %.5f '*', %.5f '+', %.5f '-', non-zero '.'\n",
159 line_header_len - 5, bucket_size, scale, scale * 2, scale * 4);
160
161 fputc('\n', stderr);
162 }
163
tst_timer_sample(void)164 void tst_timer_sample(void)
165 {
166 samples[cur_sample++] = tst_timer_elapsed_us();
167 }
168
cmp(const void * a,const void * b)169 static int cmp(const void *a, const void *b)
170 {
171 const long long *aa = a, *bb = b;
172
173 return *aa < *bb;
174 }
175
176 /*
177 * The threshold per one syscall is computed as a sum of:
178 *
179 * 400 us - accomodates for context switches, process
180 * migrations between CPUs on SMP, etc.
181 * 2*monotonic_resolution - accomodates for granurality of the CLOCK_MONOTONIC
182 * slack_per_scall - max of 0.1% of the sleep capped on 100ms or
183 * current->timer_slack_ns, which is slack allowed
184 * in kernel
185 *
186 * The formula for slack_per_scall applies to select() and *poll*() syscalls,
187 * the futex and *nanosleep() use only the timer_slack_ns, so we are a bit
188 * less strict here that we could be for these two for longer sleep times...
189 *
190 * We also allow for outliners, i.e. add some number to the threshold in case
191 * that the number of iteration is small. For large enoung number of iterations
192 * outliners are discarded and averaged out.
193 */
compute_threshold(long long requested_us,unsigned int nsamples)194 static long long compute_threshold(long long requested_us,
195 unsigned int nsamples)
196 {
197 unsigned int slack_per_scall = MIN(100000, requested_us / 1000);
198
199 slack_per_scall = MAX(slack_per_scall, timerslack);
200
201 return (400 + 2 * monotonic_resolution + slack_per_scall) * nsamples
202 + 3000/nsamples;
203 }
204
205 /*
206 * Returns number of samples to discard.
207 *
208 * We set it to either at least 1 if number of samples > 1 or 5%.
209 */
compute_discard(unsigned int nsamples)210 static unsigned int compute_discard(unsigned int nsamples)
211 {
212 if (nsamples == 1)
213 return 0;
214
215 return MAX(1u, nsamples / 20);
216 }
217
write_to_file(void)218 static void write_to_file(void)
219 {
220 unsigned int i;
221 FILE *f;
222
223 if (!file_name)
224 return;
225
226 f = fopen(file_name, "w");
227
228 if (!f) {
229 tst_res(TWARN | TERRNO,
230 "Failed to open '%s'", file_name);
231 return;
232 }
233
234 for (i = 0; i < cur_sample; i++)
235 fprintf(f, "%lli\n", samples[i]);
236
237 if (fclose(f)) {
238 tst_res(TWARN | TERRNO,
239 "Failed to close file '%s'", file_name);
240 }
241 }
242
243
244 /*
245 * Timer testing function.
246 *
247 * What we do here is:
248 *
249 * * Take nsamples measurements of the timer function, the function
250 * to be sampled is defined in the the actual test.
251 *
252 * * We sort the array of samples, then:
253 *
254 * - look for outliners which are samples where the sleep time has exceeded
255 * requested sleep time by an order of magnitude and, at the same time, are
256 * greater than clock resolution multiplied by three.
257 *
258 * - check for samples where the call has woken up too early which is a plain
259 * old bug
260 *
261 * - then we compute truncated mean and compare that with the requested sleep
262 * time increased by a threshold
263 */
do_timer_test(long long usec,unsigned int nsamples)264 void do_timer_test(long long usec, unsigned int nsamples)
265 {
266 long long trunc_mean, median;
267 unsigned int discard = compute_discard(nsamples);
268 unsigned int keep_samples = nsamples - discard;
269 long long threshold = compute_threshold(usec, keep_samples);
270 int i;
271 int failed = 0;
272
273 tst_res(TINFO,
274 "%s sleeping for %llius %u iterations, threshold %.2fus",
275 scall, usec, nsamples, 1.00 * threshold / (keep_samples));
276
277 cur_sample = 0;
278 for (i = 0; i < (int)nsamples; i++) {
279 if (sample(CLOCK_MONOTONIC, usec)) {
280 tst_res(TINFO, "sampling function failed, exitting");
281 return;
282 }
283 }
284
285 qsort(samples, nsamples, sizeof(samples[0]), cmp);
286
287 write_to_file();
288
289 for (i = 0; samples[i] > 10 * usec && i < (int)nsamples; i++) {
290 if (samples[i] <= 3 * monotonic_resolution)
291 break;
292 }
293
294 if (i > 0) {
295 tst_res(TINFO, "Found %i outliners in [%lli,%lli] range",
296 i, samples[0], samples[i-1]);
297 }
298
299 for (i = nsamples - 1; samples[i] < usec && i > -1; i--);
300
301 if (i < (int)nsamples - 1) {
302 tst_res(TFAIL, "%s woken up early %u times range: [%lli,%lli]",
303 scall, nsamples - 1 - i,
304 samples[i+1], samples[nsamples-1]);
305 failed = 1;
306 }
307
308 median = samples[nsamples/2];
309
310 trunc_mean = 0;
311
312 for (i = discard; i < (int)nsamples; i++)
313 trunc_mean += samples[i];
314
315 tst_res(TINFO,
316 "min %llius, max %llius, median %llius, trunc mean %.2fus (discarded %u)",
317 samples[nsamples-1], samples[0], median,
318 1.00 * trunc_mean / keep_samples, discard);
319
320 if (trunc_mean > (nsamples - discard) * usec + threshold) {
321 tst_res(TFAIL, "%s slept for too long", scall);
322
323 if (!print_frequency_plot)
324 frequency_plot();
325
326 failed = 1;
327 }
328
329 if (print_frequency_plot)
330 frequency_plot();
331
332 if (!failed)
333 tst_res(TPASS, "Measured times are within thresholds");
334 }
335
336 static void parse_timer_opts(void);
337
set_latency(void)338 static int set_latency(void)
339 {
340 int fd, latency = 0;
341
342 fd = open("/dev/cpu_dma_latency", O_WRONLY);
343 if (fd < 0)
344 return fd;
345
346 return write(fd, &latency, sizeof(latency));
347 }
348
timer_setup(void)349 static void timer_setup(void)
350 {
351 struct timespec t;
352 int ret;
353
354 tst_clock_getres(CLOCK_MONOTONIC, &t);
355
356 tst_res(TINFO, "CLOCK_MONOTONIC resolution %lins", (long)t.tv_nsec);
357
358 monotonic_resolution = t.tv_nsec / 1000;
359 timerslack = 50;
360
361 #ifdef PR_GET_TIMERSLACK
362 ret = prctl(PR_GET_TIMERSLACK);
363 if (ret < 0) {
364 tst_res(TINFO, "prctl(PR_GET_TIMERSLACK) = -1, using %uus",
365 timerslack);
366 } else {
367 timerslack = ret / 1000;
368 tst_res(TINFO, "prctl(PR_GET_TIMERSLACK) = %ius", timerslack);
369 }
370 #else
371 tst_res(TINFO, "PR_GET_TIMERSLACK not defined, using %uus",
372 timerslack);
373 #endif /* PR_GET_TIMERSLACK */
374
375 parse_timer_opts();
376
377 samples = SAFE_MALLOC(sizeof(long long) * MAX(MAX_SAMPLES, sample_cnt));
378
379 if (set_latency() < 0)
380 tst_res(TINFO, "Failed to set zero latency constraint: %m");
381
382 if (setup)
383 setup();
384 }
385
timer_cleanup(void)386 static void timer_cleanup(void)
387 {
388 free(samples);
389
390 if (cleanup)
391 cleanup();
392 }
393
394 static struct tst_timer_tcase {
395 long long usec;
396 unsigned int samples;
397 } tcases[] = {
398 {1000, 500},
399 {2000, 500},
400 {5000, 300},
401 {10000, 100},
402 {25000, 50},
403 {100000, 10},
404 {1000000, 2},
405 };
406
timer_test_fn(unsigned int n)407 static void timer_test_fn(unsigned int n)
408 {
409 do_timer_test(tcases[n].usec, tcases[n].samples);
410 }
411
single_timer_test(void)412 static void single_timer_test(void)
413 {
414 do_timer_test(sleep_time, sample_cnt);
415 }
416
417 static struct tst_option options[] = {
418 {"p", &print_frequency_plot, "-p Print frequency plot"},
419 {"s:", &str_sleep_time, "-s us Sleep time"},
420 {"n:", &str_sample_cnt, "-n uint Number of samples to take"},
421 {"f:", &file_name, "-f fname Write measured samples into a file"},
422 {NULL, NULL, NULL}
423 };
424
parse_timer_opts(void)425 static void parse_timer_opts(void)
426 {
427 if (str_sleep_time) {
428 if (tst_parse_int(str_sleep_time, &sleep_time, 0, INT_MAX)) {
429 tst_brk(TBROK,
430 "Invalid sleep time '%s'", str_sleep_time);
431 }
432 }
433
434 if (str_sample_cnt) {
435 if (tst_parse_int(str_sample_cnt, &sample_cnt, 1, INT_MAX)) {
436 tst_brk(TBROK,
437 "Invalid sample count '%s'", str_sample_cnt);
438 }
439 }
440
441 if (str_sleep_time || str_sample_cnt) {
442 if (sleep_time < 0)
443 sleep_time = 10000;
444
445 if (!sample_cnt)
446 sample_cnt = 500;
447
448 long long timeout = sleep_time * sample_cnt / 1000000;
449
450 tst_set_timeout(timeout + timeout/10);
451
452 test->test_all = single_timer_test;
453 test->test = NULL;
454 test->tcnt = 0;
455 }
456 }
457
tst_timer_test_setup(struct tst_test * timer_test)458 struct tst_test *tst_timer_test_setup(struct tst_test *timer_test)
459 {
460 setup = timer_test->setup;
461 cleanup = timer_test->cleanup;
462 scall = timer_test->scall;
463 sample = timer_test->sample;
464
465 timer_test->scall = NULL;
466 timer_test->setup = timer_setup;
467 timer_test->cleanup = timer_cleanup;
468 timer_test->test = timer_test_fn;
469 timer_test->tcnt = ARRAY_SIZE(tcases);
470 timer_test->sample = NULL;
471 timer_test->options = options;
472
473 test = timer_test;
474
475 return timer_test;
476 }
477