1 /* 2 * Copyright (c) 2017 Cyril Hrubis <chrubis (at) 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 48 static void print_line(char c, int len) 49 { 50 while (len-- > 0) 51 fputc(c, stderr); 52 } 53 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 62 static unsigned int flooru(float f) 63 { 64 return (unsigned int)f; 65 } 66 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 */ 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 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 164 void tst_timer_sample(void) 165 { 166 samples[cur_sample++] = tst_timer_elapsed_us(); 167 } 168 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 */ 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 */ 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 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 */ 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 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 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 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 407 static void timer_test_fn(unsigned int n) 408 { 409 do_timer_test(tcases[n].usec, tcases[n].samples); 410 } 411 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 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 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
