tools/tests/jitter/timer_jitter.c

   1 /*
   2  * Copyright (c) 2009 Apple Inc. All rights reserved.
   3  *
   4  * @APPLE_OSREFERENCE_LICENSE_HEADER_START@
   5  *
   6  * This file contains Original Code and/or Modifications of Original Code
   7  * as defined in and that are subject to the Apple Public Source License
   8  * Version 2.0 (the 'License'). You may not use this file except in
   9  * compliance with the License. The rights granted to you under the License
  10  * may not be used to create, or enable the creation or redistribution of,
  11  * unlawful or unlicensed copies of an Apple operating system, or to
  12  * circumvent, violate, or enable the circumvention or violation of, any
  13  * terms of an Apple operating system software license agreement.
  14  *
  15  * Please obtain a copy of the License at
  16  * http://www.opensource.apple.com/apsl/ and read it before using this file.
  17  *
  18  * The Original Code and all software distributed under the License are
  19  * distributed on an 'AS IS' basis, WITHOUT WARRANTY OF ANY KIND, EITHER
  20  * EXPRESS OR IMPLIED, AND APPLE HEREBY DISCLAIMS ALL SUCH WARRANTIES,
  21  * INCLUDING WITHOUT LIMITATION, ANY WARRANTIES OF MERCHANTABILITY,
  22  * FITNESS FOR A PARTICULAR PURPOSE, QUIET ENJOYMENT OR NON-INFRINGEMENT.
  23  * Please see the License for the specific language governing rights and
  24  * limitations under the License.
  25  *
  26  * @APPLE_OSREFERENCE_LICENSE_HEADER_END@
  27  */
  28 #include <unistd.h>
  29 #include <stdio.h>
  30 #include <math.h>
  31 #include <sys/wait.h>
  32 #include <sys/kdebug.h>
  33 #include <sys/types.h>
  34 #include <sys/ptrace.h>
  35 #include <semaphore.h>
  36 #include <stdlib.h>
  37 #include <pthread.h>
  38 #include <fcntl.h>
  39 #include <errno.h>
  40 #include <err.h>
  41 #include <string.h>
  42
  43 #include <libkern/OSAtomic.h>
  44
  45 #include <mach/mach_time.h>
  46 #include <mach/mach.h>
  47 #include <mach/task.h>
  48 #include <mach/semaphore.h>
  49
  50 #include <libproc_internal.h>
  51
  52 #include <os/tsd.h> /* private header for _os_cpu_number */
  53
  54 typedef enum my_policy_type { MY_POLICY_REALTIME, MY_POLICY_TIMESHARE, MY_POLICY_FIXEDPRI } my_policy_type_t;
  55
  56 #define DEFAULT_MAX_SLEEP_NS    2000000000ll /* Two seconds */
  57 #define CONSTRAINT_NANOS        (20000000ll)    /* 20 ms */
  58 #define COMPUTATION_NANOS       (10000000ll)    /* 10 ms */
  59
  60 struct mach_timebase_info g_mti;
  61
  62 #define assert(truth, label) do { if(!(truth)) { printf("Thread %p: failure on line %d\n", pthread_self(), __LINE__); goto label; } } while (0)
  63
  64 struct second_thread_args {
  65         semaphore_t wakeup_semaphore;
  66         semaphore_t return_semaphore;
  67         uint64_t iterations;
  68         my_policy_type_t pol;
  69         double *wakeup_second_jitter_arr;
  70         uint64_t woke_on_same_cpu;
  71         uint64_t too_much;
  72         volatile uint64_t last_poke_time;
  73         volatile int cpuno;
  74 };
  75
  76 void *
  77 second_thread(void *args);
  78
  79 void
  80 print_usage()
  81 {
  82         printf("Usage: jitter [-w] [-s <random seed>] [-n <min sleep, ns>] [-m <max sleep, ns>] <realtime | timeshare | fixed> <num iterations> <traceworthy jitter, ns>\n");
  83 }
  84
  85 my_policy_type_t
  86 parse_thread_policy(const char *str)
  87 {
  88         if (strcmp(str, "timeshare") == 0) {
  89                 return MY_POLICY_TIMESHARE;
  90         } else if (strcmp(str, "realtime") == 0) {
  91                 return MY_POLICY_REALTIME;
  92         } else if (strcmp(str, "fixed") == 0) {
  93                 return MY_POLICY_FIXEDPRI;
  94         } else {
  95                 printf("Invalid thread policy %s\n", str);
  96                 exit(1);
  97         }
  98 }
  99
 100 int
 101 thread_setup(my_policy_type_t pol)
 102 {
 103         int res;
 104
 105         switch (pol) {
 106         case MY_POLICY_TIMESHARE:
 107         {
 108                 return 0;
 109         }
 110         case MY_POLICY_REALTIME:
 111         {
 112                 thread_time_constraint_policy_data_t pol;
 113
 114                 /* Hard-coded realtime parameters (similar to what Digi uses) */
 115                 pol.period = 100000;
 116                 pol.constraint =  CONSTRAINT_NANOS * g_mti.denom / g_mti.numer;
 117                 pol.computation = COMPUTATION_NANOS * g_mti.denom / g_mti.numer;
 118                 pol.preemptible = 0;         /* Ignored by OS */
 119
 120                 res = thread_policy_set(mach_thread_self(), THREAD_TIME_CONSTRAINT_POLICY, (thread_policy_t) &pol, THREAD_TIME_CONSTRAINT_POLICY_COUNT);
 121                 assert(res == 0, fail);
 122                 break;
 123         }
 124         case MY_POLICY_FIXEDPRI:
 125         {
 126                 thread_extended_policy_data_t pol;
 127                 pol.timeshare = 0;
 128
 129                 res = thread_policy_set(mach_thread_self(), THREAD_EXTENDED_POLICY, (thread_policy_t) &pol, THREAD_EXTENDED_POLICY_COUNT);
 130                 assert(res == 0, fail);
 131                 break;
 132         }
 133         default:
 134         {
 135                 printf("invalid policy type\n");
 136                 return 1;
 137         }
 138         }
 139
 140         return 0;
 141 fail:
 142         return 1;
 143 }
 144
 145 uint64_t
 146 get_random_sleep_length_abs_ns(uint64_t min_sleep_ns, uint64_t max_sleep_ns)
 147 {
 148         uint64_t tmp;
 149
 150         tmp = (uint32_t)random();
 151         tmp <<= 32;
 152         tmp |= (uint32_t)random();
 153
 154         /* Now use the random number to sleep amount within the window */
 155         tmp %= (max_sleep_ns - min_sleep_ns);
 156
 157         return min_sleep_ns + tmp;
 158 }
 159
 160 void
 161 compute_stats(double *values, uint64_t count, double *average_magnitudep, double *maxp, double *minp, double *stddevp)
 162 {
 163         uint64_t i;
 164         double _sum = 0;
 165         double _max = 0;
 166         double _min = (double)INT64_MAX;
 167         double _avg = 0;
 168         double _dev = 0;
 169
 170         for (i = 0; i < count; i++) {
 171                 _sum += fabs(values[i]);
 172                 _max = values[i] > _max ? values[i] : _max;
 173                 _min = values[i] < _min ? values[i] : _min;
 174         }
 175
 176         _avg = _sum / (double)count;
 177
 178         _dev = 0;
 179         for (i = 0; i < count; i++) {
 180                 _dev += pow((values[i] - _avg), 2);
 181         }
 182
 183         _dev /= count;
 184         _dev = sqrt(_dev);
 185
 186         *average_magnitudep = _avg;
 187         *maxp = _max;
 188         *minp = _min;
 189         *stddevp = _dev;
 190 }
 191
 192 void
 193 print_stats_us(const char *label, double avg, double max, double min, double stddev)
 194 {
 195         printf("Max %s: %.1lfus\n", label, max / 1000.0 * (((double)g_mti.numer) / ((double)g_mti.denom)));
 196         printf("Min %s: %.1lfus\n", label, min / 1000.0 * (((double)g_mti.numer) / ((double)g_mti.denom)));
 197         printf("Avg magnitude of %s: %.1lfus\n", label, avg / 1000.0 * (((double)g_mti.numer) / ((double)g_mti.denom)));
 198         printf("Stddev: %.1lfus\n", stddev / 1000.0 * (((double)g_mti.numer) / ((double)g_mti.denom)));
 199         putchar('\n');
 200 }
 201
 202 void
 203 print_stats_fract(const char *label, double avg, double max, double min, double stddev)
 204 {
 205         printf("Max %s jitter: %.1lf%%\n", label, max * 100);
 206         printf("Min %s jitter: %.1lf%%\n", label, min * 100);
 207         printf("Avg %s jitter: %.1lf%%\n", label, avg * 100);
 208         printf("Stddev: %.1lf%%\n", stddev * 100);
 209         putchar('\n');
 210 }
 211
 212 int
 213 main(int argc, char **argv)
 214 {
 215         uint64_t iterations, i;
 216         double *jitter_arr, *fraction_arr;
 217         double *wakeup_second_jitter_arr;
 218         uint64_t target_time;
 219         uint64_t sleep_length_abs;
 220         uint64_t min_sleep_ns = 0;
 221         uint64_t max_sleep_ns = DEFAULT_MAX_SLEEP_NS;
 222         uint64_t wake_time;
 223         unsigned random_seed;
 224         boolean_t need_seed = TRUE;
 225         char ch;
 226         int res;
 227         kern_return_t kret;
 228         my_policy_type_t pol;
 229         boolean_t wakeup_second_thread = FALSE;
 230         semaphore_t wakeup_semaphore, return_semaphore;
 231
 232         double avg, stddev, max, min;
 233         double avg_fract, stddev_fract, max_fract, min_fract;
 234         uint64_t too_much;
 235
 236         struct second_thread_args secargs;
 237         pthread_t secthread;
 238
 239         mach_timebase_info(&g_mti);
 240
 241         /* Seed random */
 242         opterr = 0;
 243         while ((ch = getopt(argc, argv, "m:n:hs:w")) != -1 && ch != '?') {
 244                 switch (ch) {
 245                 case 's':
 246                         /* Specified seed for random)() */
 247                         random_seed = (unsigned)atoi(optarg);
 248                         srandom(random_seed);
 249                         need_seed = FALSE;
 250                         break;
 251                 case 'm':
 252                         /* How long per timer? */
 253                         max_sleep_ns = strtoull(optarg, NULL, 10);
 254                         break;
 255                 case 'n':
 256                         /* How long per timer? */
 257                         min_sleep_ns = strtoull(optarg, NULL, 10);
 258                         break;
 259                 case 'w':
 260                         /* After each timed wait, wakeup another thread */
 261                         wakeup_second_thread = TRUE;
 262                         break;
 263                 case 'h':
 264                         print_usage();
 265                         exit(0);
 266                         break;
 267                 default:
 268                         fprintf(stderr, "Got unexpected result from getopt().\n");
 269                         exit(1);
 270                         break;
 271                 }
 272         }
 273
 274         argc -= optind;
 275         argv += optind;
 276
 277         if (argc != 3) {
 278                 print_usage();
 279                 exit(1);
 280         }
 281
 282         if (min_sleep_ns >= max_sleep_ns) {
 283                 print_usage();
 284                 exit(1);
 285         }
 286
 287         if (need_seed) {
 288                 srandom(time(NULL));
 289         }
 290
 291         /* What scheduling policy? */
 292         pol = parse_thread_policy(argv[0]);
 293
 294         /* How many timers? */
 295         iterations = strtoull(argv[1], NULL, 10);
 296
 297         /* How much jitter is so extreme that we should cut a trace point */
 298         too_much = strtoull(argv[2], NULL, 10);
 299
 300         /* Array for data */
 301         jitter_arr = (double*)malloc(sizeof(*jitter_arr) * iterations);
 302         if (jitter_arr == NULL) {
 303                 printf("Couldn't allocate array to store results.\n");
 304                 exit(1);
 305         }
 306
 307         fraction_arr = (double*)malloc(sizeof(*fraction_arr) * iterations);
 308         if (fraction_arr == NULL) {
 309                 printf("Couldn't allocate array to store results.\n");
 310                 exit(1);
 311         }
 312
 313         if (wakeup_second_thread) {
 314                 /* Array for data */
 315                 wakeup_second_jitter_arr = (double*)malloc(sizeof(*jitter_arr) * iterations);
 316                 if (wakeup_second_jitter_arr == NULL) {
 317                         printf("Couldn't allocate array to store results.\n");
 318                         exit(1);
 319                 }
 320
 321                 kret = semaphore_create(mach_task_self(), &wakeup_semaphore, SYNC_POLICY_FIFO, 0);
 322                 if (kret != KERN_SUCCESS) {
 323                         printf("Couldn't allocate semaphore %d\n", kret);
 324                         exit(1);
 325                 }
 326
 327                 kret = semaphore_create(mach_task_self(), &return_semaphore, SYNC_POLICY_FIFO, 0);
 328                 if (kret != KERN_SUCCESS) {
 329                         printf("Couldn't allocate semaphore %d\n", kret);
 330                         exit(1);
 331                 }
 332
 333
 334                 secargs.wakeup_semaphore = wakeup_semaphore;
 335                 secargs.return_semaphore = return_semaphore;
 336                 secargs.iterations = iterations;
 337                 secargs.pol = pol;
 338                 secargs.wakeup_second_jitter_arr = wakeup_second_jitter_arr;
 339                 secargs.woke_on_same_cpu = 0;
 340                 secargs.too_much = too_much;
 341                 secargs.last_poke_time = 0ULL;
 342                 secargs.cpuno = 0;
 343
 344                 res = pthread_create(&secthread, NULL, second_thread, &secargs);
 345                 if (res) {
 346                         err(1, "pthread_create");
 347                 }
 348
 349                 sleep(1); /* Time for other thread to start up */
 350         }
 351
 352         /* Set scheduling policy */
 353         res = thread_setup(pol);
 354         if (res != 0) {
 355                 printf("Couldn't set thread policy.\n");
 356                 exit(1);
 357         }
 358
 359         /*
 360          * Disable the wake monitor.  If we are
 361          * performing a large number of
 362          * iterations, the wake monitor may
 363          * cause this process to get suspended,
 364          * thus causing a large jitter value.
 365          */
 366         if (proc_disable_wakemon(getpid()) != KERN_SUCCESS) {
 367                 printf("Couldn't disable wake monitor.\n");
 368                 /* For now, do not exit; this call could be locked down */
 369         }
 370
 371         /*
 372          * Repeatedly pick a random timer length and
 373          * try to sleep exactly that long
 374          */
 375         for (i = 0; i < iterations; i++) {
 376                 sleep_length_abs = (uint64_t) (get_random_sleep_length_abs_ns(min_sleep_ns, max_sleep_ns) * (((double)g_mti.denom) / ((double)g_mti.numer)));
 377                 target_time = mach_absolute_time() + sleep_length_abs;
 378
 379                 /* Sleep */
 380                 kret = mach_wait_until(target_time);
 381                 wake_time = mach_absolute_time();
 382
 383                 jitter_arr[i] = (double)(wake_time - target_time);
 384                 fraction_arr[i] = jitter_arr[i] / ((double)sleep_length_abs);
 385
 386                 /* Too much: cut a tracepoint for a debugger */
 387                 if (jitter_arr[i] >= too_much) {
 388                         kdebug_trace(0xeeeee0 | DBG_FUNC_NONE, 0, 0, 0, 0);
 389                 }
 390
 391                 if (wakeup_second_thread) {
 392                         secargs.last_poke_time = mach_absolute_time();
 393                         secargs.cpuno = _os_cpu_number();
 394                         OSMemoryBarrier();
 395                         kret = semaphore_signal(wakeup_semaphore);
 396                         if (kret != KERN_SUCCESS) {
 397                                 errx(1, "semaphore_signal");
 398                         }
 399
 400                         kret = semaphore_wait(return_semaphore);
 401                         if (kret != KERN_SUCCESS) {
 402                                 errx(1, "semaphore_wait");
 403                         }
 404                 }
 405         }
 406
 407         /*
 408          * Compute statistics and output results.
 409          */
 410         compute_stats(jitter_arr, iterations, &avg, &max, &min, &stddev);
 411         compute_stats(fraction_arr, iterations, &avg_fract, &max_fract, &min_fract, &stddev_fract);
 412
 413         putchar('\n');
 414         print_stats_us("jitter", avg, max, min, stddev);
 415         print_stats_fract("%", avg_fract, max_fract, min_fract, stddev_fract);
 416
 417         if (wakeup_second_thread) {
 418                 res = pthread_join(secthread, NULL);
 419                 if (res) {
 420                         err(1, "pthread_join");
 421                 }
 422
 423                 compute_stats(wakeup_second_jitter_arr, iterations, &avg, &max, &min, &stddev);
 424
 425                 putchar('\n');
 426                 print_stats_us("second jitter", avg, max, min, stddev);
 427
 428                 putchar('\n');
 429                 printf("%llu/%llu (%.1f%%) wakeups on same CPU\n", secargs.woke_on_same_cpu, iterations,
 430                     100.0 * ((double)secargs.woke_on_same_cpu) / iterations);
 431         }
 432
 433         return 0;
 434 }
 435
 436 void *
 437 second_thread(void *args)
 438 {
 439         struct second_thread_args *secargs = (struct second_thread_args *)args;
 440         int res;
 441         uint64_t i;
 442         kern_return_t kret;
 443         uint64_t wake_time;
 444         int cpuno;
 445
 446         /* Set scheduling policy */
 447         res = thread_setup(secargs->pol);
 448         if (res != 0) {
 449                 printf("Couldn't set thread policy.\n");
 450                 exit(1);
 451         }
 452
 453         /*
 454          * Repeatedly pick a random timer length and
 455          * try to sleep exactly that long
 456          */
 457         for (i = 0; i < secargs->iterations; i++) {
 458                 /* Wake up when poked by main thread */
 459                 kret = semaphore_wait(secargs->wakeup_semaphore);
 460                 if (kret != KERN_SUCCESS) {
 461                         errx(1, "semaphore_wait %d", kret);
 462                 }
 463
 464                 wake_time = mach_absolute_time();
 465                 cpuno = _os_cpu_number();
 466                 if (wake_time < secargs->last_poke_time) {
 467                         /* Woke in past, unsynchronized mach_absolute_time()? */
 468
 469                         errx(1, "woke in past %llu (%d) < %llu (%d)", wake_time, cpuno, secargs->last_poke_time, secargs->cpuno);
 470                 }
 471
 472                 if (cpuno == secargs->cpuno) {
 473                         secargs->woke_on_same_cpu++;
 474                 }
 475
 476                 secargs->wakeup_second_jitter_arr[i] = (double)(wake_time - secargs->last_poke_time);
 477
 478                 /* Too much: cut a tracepoint for a debugger */
 479                 if (secargs->wakeup_second_jitter_arr[i] >= secargs->too_much) {
 480                         kdebug_trace(0xeeeee4 | DBG_FUNC_NONE, 0, 0, 0, 0);
 481                 }
 482
 483                 kret = semaphore_signal(secargs->return_semaphore);
 484                 if (kret != KERN_SUCCESS) {
 485                         errx(1, "semaphore_signal %d", kret);
 486                 }
 487         }
 488
 489         return NULL;
 490 }