• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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