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