tests/kqueue_timer_tests.c

   1 #include <sys/types.h>
   2 #include <sys/event.h>
   3 #include <sys/time.h>
   4 #include <assert.h>
   5 #include <errno.h>
   6 #include <stdio.h>
   7 #include <stdlib.h>
   8 #include <unistd.h>
   9 #include <mach/mach.h>
  10 #include <mach/task.h>
  11
  12 #include <TargetConditionals.h>
  13 #include <darwintest.h>
  14
  15 #ifndef NOTE_MACHTIME
  16 #define NOTE_MACHTIME   0x00000100
  17 #endif
  18
  19 static mach_timebase_info_data_t timebase_info;
  20
  21 static uint64_t
  22 nanos_to_abs(uint64_t nanos)
  23 {
  24         return nanos * timebase_info.denom / timebase_info.numer;
  25 }
  26 static uint64_t
  27 abs_to_nanos(uint64_t abs)
  28 {
  29         return abs * timebase_info.numer / timebase_info.denom;
  30 }
  31
  32 static int kq, passed, failed;
  33
  34 static struct timespec failure_timeout = { .tv_sec = 10, .tv_nsec = 0 };
  35
  36 /*
  37  * Wait for given kevent, which should return in 'expected' usecs.
  38  */
  39 static int
  40 do_simple_kevent(struct kevent64_s *kev, uint64_t expected)
  41 {
  42         int ret;
  43         int64_t elapsed_usecs;
  44         uint64_t delta_usecs;
  45         struct timespec timeout;
  46         struct timeval before, after;
  47
  48         /* time out after 1 sec extra delay */
  49         timeout.tv_sec = (expected / USEC_PER_SEC) + 1;
  50         timeout.tv_nsec = (expected % USEC_PER_SEC) * 1000;
  51
  52         T_SETUPBEGIN;
  53
  54         /* measure time for the kevent */
  55         gettimeofday(&before, NULL);
  56         ret = kevent64(kq, kev, 1, kev, 1, 0, &timeout);
  57         gettimeofday(&after, NULL);
  58
  59         if (ret < 1 || (kev->flags & EV_ERROR)) {
  60                 T_LOG("%s() failure: kevent returned %d, error %d\n", __func__, ret,
  61                     (ret == -1 ? errno : (int) kev->data));
  62                 return 0;
  63         }
  64
  65         T_SETUPEND;
  66
  67         /* did it work? */
  68         elapsed_usecs = (after.tv_sec - before.tv_sec) * (int64_t)USEC_PER_SEC +
  69             (after.tv_usec - before.tv_usec);
  70         delta_usecs = (uint64_t)llabs(elapsed_usecs - ((int64_t)expected));
  71
  72         /* failure if we're 30% off, or 50 mics late */
  73         if (delta_usecs > (30 * expected / 100.0) && delta_usecs > 50) {
  74                 T_LOG("\tfailure: expected %lld usec, measured %lld usec.\n",
  75                     expected, elapsed_usecs);
  76                 return 0;
  77         } else {
  78                 T_LOG("\tsuccess, measured %lld usec.\n", elapsed_usecs);
  79                 return 1;
  80         }
  81 }
  82
  83 static void
  84 test_absolute_kevent(int time, int scale)
  85 {
  86         struct timeval tv;
  87         struct kevent64_s kev;
  88         uint64_t nowus, expected, timescale = 0;
  89         int ret;
  90         int64_t deadline;
  91
  92         gettimeofday(&tv, NULL);
  93         nowus = (uint64_t)tv.tv_sec * USEC_PER_SEC + (uint64_t)tv.tv_usec;
  94
  95         T_SETUPBEGIN;
  96
  97         switch (scale) {
  98         case NOTE_MACHTIME:
  99                 T_LOG("Testing %d MATUs absolute timer...\n", time);
 100                 break;
 101         case NOTE_SECONDS:
 102                 T_LOG("Testing %d sec absolute timer...\n", time);
 103                 timescale = USEC_PER_SEC;
 104                 break;
 105         case NOTE_USECONDS:
 106                 T_LOG("Testing %d usec absolute timer...\n", time);
 107                 timescale = 1;
 108                 break;
 109         case 0:
 110                 T_LOG("Testing %d msec absolute timer...\n", time);
 111                 timescale = 1000;
 112                 break;
 113         default:
 114                 T_FAIL("Failure: scale 0x%x not recognized.\n", scale);
 115                 return;
 116         }
 117
 118         T_SETUPEND;
 119
 120         if (scale == NOTE_MACHTIME) {
 121                 expected = abs_to_nanos((uint64_t)time) / NSEC_PER_USEC;
 122                 deadline = (int64_t)mach_absolute_time() + time;
 123         } else {
 124                 expected = (uint64_t)time * timescale;
 125                 deadline = (int64_t)(nowus / timescale) + time;
 126         }
 127
 128         /* deadlines in the past should fire immediately */
 129         if (time < 0) {
 130                 expected = 0;
 131         }
 132
 133         EV_SET64(&kev, 1, EVFILT_TIMER, EV_ADD,
 134             NOTE_ABSOLUTE | scale, deadline, 0, 0, 0);
 135         ret = do_simple_kevent(&kev, expected);
 136
 137         if (ret) {
 138                 passed++;
 139                 T_PASS("%s time:%d, scale:0x%x", __func__, time, scale);
 140         } else {
 141                 failed++;
 142                 T_FAIL("%s time:%d, scale:0x%x", __func__, time, scale);
 143         }
 144 }
 145
 146 static void
 147 test_oneshot_kevent(int time, int scale)
 148 {
 149         int ret;
 150         uint64_t expected = 0;
 151         struct kevent64_s kev;
 152
 153         T_SETUPBEGIN;
 154
 155         switch (scale) {
 156         case NOTE_MACHTIME:
 157                 T_LOG("Testing %d MATUs interval timer...\n", time);
 158                 expected = abs_to_nanos((uint64_t)time) / NSEC_PER_USEC;
 159                 break;
 160         case NOTE_SECONDS:
 161                 T_LOG("Testing %d sec interval timer...\n", time);
 162                 expected = (uint64_t)time * USEC_PER_SEC;
 163                 break;
 164         case NOTE_USECONDS:
 165                 T_LOG("Testing %d usec interval timer...\n", time);
 166                 expected = (uint64_t)time;
 167                 break;
 168         case NOTE_NSECONDS:
 169                 T_LOG("Testing %d nsec interval timer...\n", time);
 170                 expected = (uint64_t)time / 1000;
 171                 break;
 172         case 0:
 173                 T_LOG("Testing %d msec interval timer...\n", time);
 174                 expected = (uint64_t)time * 1000;
 175                 break;
 176         default:
 177                 T_FAIL("Failure: scale 0x%x not recognized.\n", scale);
 178                 return;
 179         }
 180
 181         T_SETUPEND;
 182
 183         /* deadlines in the past should fire immediately */
 184         if (time < 0) {
 185                 expected = 0;
 186         }
 187
 188         EV_SET64(&kev, 2, EVFILT_TIMER, EV_ADD | EV_ONESHOT, scale, time,
 189             0, 0, 0);
 190         ret = do_simple_kevent(&kev, expected);
 191
 192         if (ret) {
 193                 passed++;
 194                 T_PASS("%s time:%d, scale:0x%x", __func__, time, scale);
 195         } else {
 196                 failed++;
 197                 T_FAIL("%s time:%d, scale:0x%x", __func__, time, scale);
 198         }
 199 }
 200
 201 /* Test that the timer goes ding multiple times */
 202 static void
 203 test_interval_kevent(int usec)
 204 {
 205         struct kevent64_s kev;
 206         int ret;
 207
 208         T_SETUPBEGIN;
 209
 210         uint64_t test_duration_us = USEC_PER_SEC; /* 1 second */
 211         uint64_t expected_pops;
 212
 213         if (usec < 0) {
 214                 expected_pops = 1; /* TODO: test 'and only once' */
 215         } else {
 216                 expected_pops = test_duration_us / (uint64_t)usec;
 217         }
 218
 219         T_LOG("Testing interval kevent at %d usec intervals (%lld pops/second)...\n",
 220             usec, expected_pops);
 221
 222         EV_SET64(&kev, 3, EVFILT_TIMER, EV_ADD, NOTE_USECONDS, usec, 0, 0, 0);
 223         ret = kevent64(kq, &kev, 1, NULL, 0, 0, NULL);
 224         if (ret != 0 || (kev.flags & EV_ERROR)) {
 225                 T_FAIL("%s() setup failure: kevent64 returned %d\n", __func__, ret);
 226                 failed++;
 227                 return;
 228         }
 229
 230         T_SETUPEND;
 231
 232         struct timeval before, after;
 233         uint64_t elapsed_usecs;
 234
 235         gettimeofday(&before, NULL);
 236
 237         uint64_t pops = 0;
 238
 239         for (uint32_t i = 0; i < expected_pops; i++) {
 240                 ret = kevent64(kq, NULL, 0, &kev, 1, 0, &failure_timeout);
 241                 if (ret != 1) {
 242                         T_FAIL("%s() failure: kevent64 returned %d\n", __func__, ret);
 243                         failed++;
 244                         return;
 245                 }
 246
 247                 //T_LOG("\t ding: %lld\n", kev.data);
 248
 249                 pops += (uint64_t)kev.data;
 250                 gettimeofday(&after, NULL);
 251                 elapsed_usecs = (uint64_t)((after.tv_sec - before.tv_sec) * (int64_t)USEC_PER_SEC +
 252                     (after.tv_usec - before.tv_usec));
 253
 254                 if (elapsed_usecs > test_duration_us) {
 255                         break;
 256                 }
 257         }
 258
 259         /* check how many times the timer fired: within 5%? */
 260         if (pops > expected_pops + (expected_pops / 20) ||
 261             pops < expected_pops - (expected_pops / 20)) {
 262                 T_FAIL("%s() usec:%d (saw %lld of %lld expected pops)", __func__, usec, pops, expected_pops);
 263                 failed++;
 264         } else {
 265                 T_PASS("%s() usec:%d (saw %lld pops)", __func__, usec, pops);
 266                 passed++;
 267         }
 268
 269         EV_SET64(&kev, 3, EVFILT_TIMER, EV_DELETE, 0, 0, 0, 0, 0);
 270         ret = kevent64(kq, &kev, 1, NULL, 0, 0, NULL);
 271         if (ret != 0) {
 272                 T_LOG("\tfailed to stop repeating timer: %d\n", ret);
 273         }
 274 }
 275
 276 /* Test that the repeating timer repeats even while not polling in kqueue */
 277 static void
 278 test_repeating_kevent(int usec)
 279 {
 280         struct kevent64_s kev;
 281         int ret;
 282
 283         T_SETUPBEGIN;
 284
 285         uint64_t test_duration_us = USEC_PER_SEC; /* 1 second */
 286
 287         uint64_t expected_pops = test_duration_us / (uint64_t)usec;
 288         T_LOG("Testing repeating kevent at %d usec intervals (%lld pops/second)...\n",
 289             usec, expected_pops);
 290
 291         EV_SET64(&kev, 4, EVFILT_TIMER, EV_ADD, NOTE_USECONDS, usec, 0, 0, 0);
 292         ret = kevent64(kq, &kev, 1, NULL, 0, 0, NULL);
 293         if (ret != 0) {
 294                 T_FAIL("%s() setup failure: kevent64 returned %d\n", __func__, ret);
 295                 failed++;
 296                 return;
 297         }
 298
 299         usleep((useconds_t)test_duration_us);
 300
 301         ret = kevent64(kq, NULL, 0, &kev, 1, 0, &failure_timeout);
 302         if (ret != 1 || (kev.flags & EV_ERROR)) {
 303                 T_FAIL("%s() setup failure: kevent64 returned %d\n", __func__, ret);
 304                 failed++;
 305                 return;
 306         }
 307
 308         T_SETUPEND;
 309
 310         uint64_t pops = (uint64_t) kev.data;
 311
 312         /* check how many times the timer fired: within 5%? */
 313         if (pops > expected_pops + (expected_pops / 20) ||
 314             pops < expected_pops - (expected_pops / 20)) {
 315                 T_FAIL("%s() usec:%d (saw %lld of %lld expected pops)", __func__, usec, pops, expected_pops);
 316                 failed++;
 317         } else {
 318                 T_PASS("%s() usec:%d (saw %lld pops)", __func__, usec, pops);
 319                 passed++;
 320         }
 321
 322         EV_SET64(&kev, 4, EVFILT_TIMER, EV_DELETE, 0, 0, 0, 0, 0);
 323         ret = kevent64(kq, &kev, 1, NULL, 0, 0, NULL);
 324         if (ret != 0) {
 325                 T_LOG("\tfailed to stop repeating timer: %d\n", ret);
 326         }
 327 }
 328
 329
 330 static void
 331 test_updated_kevent(int first, int second)
 332 {
 333         struct kevent64_s kev;
 334         int ret;
 335
 336         T_LOG("Testing update from %d to %d msecs...\n", first, second);
 337
 338         T_SETUPBEGIN;
 339
 340         EV_SET64(&kev, 4, EVFILT_TIMER, EV_ADD | EV_ONESHOT, 0, first, 0, 0, 0);
 341         ret = kevent64(kq, &kev, 1, NULL, 0, 0, NULL);
 342         if (ret != 0) {
 343                 T_FAIL("%s() failure: initial kevent returned %d\n", __func__, ret);
 344                 failed++;
 345                 return;
 346         }
 347
 348         T_SETUPEND;
 349
 350         EV_SET64(&kev, 4, EVFILT_TIMER, EV_ONESHOT, 0, second, 0, 0, 0);
 351
 352         uint64_t expected_us = (uint64_t)second * 1000;
 353
 354         if (second < 0) {
 355                 expected_us = 0;
 356         }
 357
 358         ret = do_simple_kevent(&kev, expected_us);
 359
 360         if (ret) {
 361                 passed++;
 362                 T_PASS("%s() %d, %d", __func__, first, second);
 363         } else {
 364                 failed++;
 365                 T_FAIL("%s() %d, %d", __func__, first, second);
 366         }
 367 }
 368
 369 static void
 370 disable_timer_coalescing(void)
 371 {
 372         struct task_qos_policy      qosinfo;
 373         kern_return_t                       kr;
 374
 375         T_SETUPBEGIN;
 376
 377         qosinfo.task_latency_qos_tier = LATENCY_QOS_TIER_0;
 378         qosinfo.task_throughput_qos_tier = THROUGHPUT_QOS_TIER_0;
 379
 380         kr = task_policy_set(mach_task_self(), TASK_OVERRIDE_QOS_POLICY, (task_policy_t)&qosinfo,
 381             TASK_QOS_POLICY_COUNT);
 382         if (kr != KERN_SUCCESS) {
 383                 T_FAIL("task_policy_set(... TASK_OVERRIDE_QOS_POLICY ...) failed: %d (%s)", kr, mach_error_string(kr));
 384         }
 385
 386         T_SETUPEND;
 387 }
 388
 389 T_DECL(kqueue_timer_tests,
 390     "Tests assorted kqueue operations for timer-related events")
 391 {
 392         /*
 393          * Since we're trying to test timers here, disable timer coalescing
 394          * to improve the accuracy of timer fires for this process.
 395          */
 396         disable_timer_coalescing();
 397
 398         mach_timebase_info(&timebase_info);
 399
 400         kq = kqueue();
 401         assert(kq > 0);
 402         passed = 0;
 403         failed = 0;
 404
 405         test_absolute_kevent(100, 0);
 406         test_absolute_kevent(200, 0);
 407         test_absolute_kevent(300, 0);
 408         test_absolute_kevent(1000, 0);
 409         T_MAYFAIL;
 410         test_absolute_kevent(500, NOTE_USECONDS);
 411         T_MAYFAIL;
 412         test_absolute_kevent(100, NOTE_USECONDS);
 413         T_MAYFAIL;
 414         test_absolute_kevent(2, NOTE_SECONDS);
 415         T_MAYFAIL;
 416         test_absolute_kevent(-1000, 0);
 417
 418         T_MAYFAIL;
 419         test_absolute_kevent((int)nanos_to_abs(10 * NSEC_PER_MSEC), NOTE_MACHTIME);
 420
 421         test_oneshot_kevent(1, NOTE_SECONDS);
 422         T_MAYFAIL;
 423         test_oneshot_kevent(10, 0);
 424         T_MAYFAIL;
 425         test_oneshot_kevent(200, NOTE_USECONDS);
 426         T_MAYFAIL;
 427         test_oneshot_kevent(300000, NOTE_NSECONDS);
 428         T_MAYFAIL;
 429         test_oneshot_kevent(-1, NOTE_SECONDS);
 430
 431         T_MAYFAIL;
 432         test_oneshot_kevent((int)nanos_to_abs(10 * NSEC_PER_MSEC), NOTE_MACHTIME);
 433
 434         test_interval_kevent(250 * 1000);
 435         T_MAYFAIL;
 436         test_interval_kevent(5 * 1000);
 437         T_MAYFAIL;
 438         test_interval_kevent(200);
 439         T_MAYFAIL;
 440         test_interval_kevent(50);
 441
 442         test_interval_kevent(-1000);
 443
 444         test_repeating_kevent(10000); /* 10ms */
 445
 446         test_updated_kevent(1000, 2000);
 447         test_updated_kevent(2000, 1000);
 448         test_updated_kevent(1000, -1);
 449 }