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