app/test/test_timer.c

   1 /* SPDX-License-Identifier: BSD-3-Clause
   2  * Copyright(c) 2010-2014 Intel Corporation
   3  */
   4
   5 #include "test.h"
   6
   7 /*
   8  * Timer
   9  * =====
  10  *
  11  * #. Stress test 1.
  12  *
  13  *    The objective of the timer stress tests is to check that there are no
  14  *    race conditions in list and status management. This test launches,
  15  *    resets and stops the timer very often on many cores at the same
  16  *    time.
  17  *
  18  *    - Only one timer is used for this test.
  19  *    - On each core, the rte_timer_manage() function is called from the main
  20  *      loop every 3 microseconds.
  21  *    - In the main loop, the timer may be reset (randomly, with a
  22  *      probability of 0.5 %) 100 microseconds later on a random core, or
  23  *      stopped (with a probability of 0.5 % also).
  24  *    - In callback, the timer is can be reset (randomly, with a
  25  *      probability of 0.5 %) 100 microseconds later on the same core or
  26  *      on another core (same probability), or stopped (same
  27  *      probability).
  28  *
  29  * # Stress test 2.
  30  *
  31  *    The objective of this test is similar to the first in that it attempts
  32  *    to find if there are any race conditions in the timer library. However,
  33  *    it is less complex in terms of operations performed and duration, as it
  34  *    is designed to have a predictable outcome that can be tested.
  35  *
  36  *    - A set of timers is initialized for use by the test
  37  *    - All cores then simultaneously are set to schedule all the timers at
  38  *      the same time, so conflicts should occur.
  39  *    - Then there is a delay while we wait for the timers to expire
  40  *    - Then the main lcore calls timer_manage() and we check that all
  41  *      timers have had their callbacks called exactly once - no more no less.
  42  *    - Then we repeat the process, except after setting up the timers, we have
  43  *      all cores randomly reschedule them.
  44  *    - Again we check that the expected number of callbacks has occurred when
  45  *      we call timer-manage.
  46  *
  47  * #. Basic test.
  48  *
  49  *    This test performs basic functional checks of the timers. The test
  50  *    uses four different timers that are loaded and stopped under
  51  *    specific conditions in specific contexts.
  52  *
  53  *    - Four timers are used for this test.
  54  *    - On each core, the rte_timer_manage() function is called from main loop
  55  *      every 3 microseconds.
  56  *
  57  *    The autotest python script checks that the behavior is correct:
  58  *
  59  *    - timer0
  60  *
  61  *      - At initialization, timer0 is loaded by the main core, on main core
  62  *        in "single" mode (time = 1 second).
  63  *      - In the first 19 callbacks, timer0 is reloaded on the same core,
  64  *        then, it is explicitly stopped at the 20th call.
  65  *      - At t=25s, timer0 is reloaded once by timer2.
  66  *
  67  *    - timer1
  68  *
  69  *      - At initialization, timer1 is loaded by the main core, on the
  70  *        main core in "single" mode (time = 2 seconds).
  71  *      - In the first 9 callbacks, timer1 is reloaded on another
  72  *        core. After the 10th callback, timer1 is not reloaded anymore.
  73  *
  74  *    - timer2
  75  *
  76  *      - At initialization, timer2 is loaded by the main core, on the
  77  *        main core in "periodical" mode (time = 1 second).
  78  *      - In the callback, when t=25s, it stops timer3 and reloads timer0
  79  *        on the current core.
  80  *
  81  *    - timer3
  82  *
  83  *      - At initialization, timer3 is loaded by the main core, on
  84  *        another core in "periodical" mode (time = 1 second).
  85  *      - It is stopped at t=25s by timer2.
  86  */
  87
  88 #include <stdio.h>
  89 #include <stdarg.h>
  90 #include <string.h>
  91 #include <stdlib.h>
  92 #include <stdint.h>
  93 #include <inttypes.h>
  94 #include <sys/queue.h>
  95 #include <math.h>
  96
  97 #include <rte_common.h>
  98 #include <rte_log.h>
  99 #include <rte_memory.h>
 100 #include <rte_launch.h>
 101 #include <rte_cycles.h>
 102 #include <rte_eal.h>
 103 #include <rte_per_lcore.h>
 104 #include <rte_lcore.h>
 105 #include <rte_timer.h>
 106 #include <rte_random.h>
 107 #include <rte_malloc.h>
 108 #include <rte_pause.h>
 109
 110 #define TEST_DURATION_S 1 /* in seconds */
 111 #define NB_TIMER 4
 112
 113 #define RTE_LOGTYPE_TESTTIMER RTE_LOGTYPE_USER3
 114
 115 static volatile uint64_t end_time;
 116 static volatile int test_failed;
 117
 118 struct mytimerinfo {
 119         struct rte_timer tim;
 120         unsigned id;
 121         unsigned count;
 122 };
 123
 124 static struct mytimerinfo mytiminfo[NB_TIMER];
 125
 126 static void timer_basic_cb(struct rte_timer *tim, void *arg);
 127
 128 static void
 129 mytimer_reset(struct mytimerinfo *timinfo, uint64_t ticks,
 130               enum rte_timer_type type, unsigned tim_lcore,
 131               rte_timer_cb_t fct)
 132 {
 133         rte_timer_reset_sync(&timinfo->tim, ticks, type, tim_lcore,
 134                              fct, timinfo);
 135 }
 136
 137 /* timer callback for stress tests */
 138 static void
 139 timer_stress_cb(__rte_unused struct rte_timer *tim,
 140                 __rte_unused void *arg)
 141 {
 142         long r;
 143         unsigned lcore_id = rte_lcore_id();
 144         uint64_t hz = rte_get_timer_hz();
 145
 146         if (rte_timer_pending(tim))
 147                 return;
 148
 149         r = rte_rand();
 150         if ((r & 0xff) == 0) {
 151                 mytimer_reset(&mytiminfo[0], hz, SINGLE, lcore_id,
 152                               timer_stress_cb);
 153         }
 154         else if ((r & 0xff) == 1) {
 155                 mytimer_reset(&mytiminfo[0], hz, SINGLE,
 156                               rte_get_next_lcore(lcore_id, 0, 1),
 157                               timer_stress_cb);
 158         }
 159         else if ((r & 0xff) == 2) {
 160                 rte_timer_stop(&mytiminfo[0].tim);
 161         }
 162 }
 163
 164 static int
 165 timer_stress_main_loop(__rte_unused void *arg)
 166 {
 167         uint64_t hz = rte_get_timer_hz();
 168         unsigned lcore_id = rte_lcore_id();
 169         uint64_t cur_time;
 170         int64_t diff = 0;
 171         long r;
 172
 173         while (diff >= 0) {
 174
 175                 /* call the timer handler on each core */
 176                 rte_timer_manage();
 177
 178                 /* simulate the processing of a packet
 179                  * (1 us = 2000 cycles at 2 Ghz) */
 180                 rte_delay_us(1);
 181
 182                 /* randomly stop or reset timer */
 183                 r = rte_rand();
 184                 lcore_id = rte_get_next_lcore(lcore_id, 0, 1);
 185                 if ((r & 0xff) == 0) {
 186                         /* 100 us */
 187                         mytimer_reset(&mytiminfo[0], hz/10000, SINGLE, lcore_id,
 188                                       timer_stress_cb);
 189                 }
 190                 else if ((r & 0xff) == 1) {
 191                         rte_timer_stop_sync(&mytiminfo[0].tim);
 192                 }
 193                 cur_time = rte_get_timer_cycles();
 194                 diff = end_time - cur_time;
 195         }
 196
 197         lcore_id = rte_lcore_id();
 198         RTE_LOG(INFO, TESTTIMER, "core %u finished\n", lcore_id);
 199
 200         return 0;
 201 }
 202
 203 /* Need to synchronize worker lcores through multiple steps. */
 204 enum { WORKER_WAITING = 1, WORKER_RUN_SIGNAL, WORKER_RUNNING, WORKER_FINISHED };
 205 static uint16_t lcore_state[RTE_MAX_LCORE];
 206
 207 static void
 208 main_init_workers(void)
 209 {
 210         unsigned i;
 211
 212         RTE_LCORE_FOREACH_WORKER(i) {
 213                 __atomic_store_n(&lcore_state[i], WORKER_WAITING, __ATOMIC_RELAXED);
 214         }
 215 }
 216
 217 static void
 218 main_start_workers(void)
 219 {
 220         unsigned i;
 221
 222         RTE_LCORE_FOREACH_WORKER(i) {
 223                 __atomic_store_n(&lcore_state[i], WORKER_RUN_SIGNAL, __ATOMIC_RELEASE);
 224         }
 225         RTE_LCORE_FOREACH_WORKER(i) {
 226                 rte_wait_until_equal_16(&lcore_state[i], WORKER_RUNNING, __ATOMIC_ACQUIRE);
 227         }
 228 }
 229
 230 static void
 231 main_wait_for_workers(void)
 232 {
 233         unsigned i;
 234
 235         RTE_LCORE_FOREACH_WORKER(i) {
 236                 rte_wait_until_equal_16(&lcore_state[i], WORKER_FINISHED, __ATOMIC_ACQUIRE);
 237         }
 238 }
 239
 240 static void
 241 worker_wait_to_start(void)
 242 {
 243         unsigned lcore_id = rte_lcore_id();
 244
 245         rte_wait_until_equal_16(&lcore_state[lcore_id], WORKER_RUN_SIGNAL, __ATOMIC_ACQUIRE);
 246         __atomic_store_n(&lcore_state[lcore_id], WORKER_RUNNING, __ATOMIC_RELEASE);
 247 }
 248
 249 static void
 250 worker_finish(void)
 251 {
 252         unsigned lcore_id = rte_lcore_id();
 253
 254         __atomic_store_n(&lcore_state[lcore_id], WORKER_FINISHED, __ATOMIC_RELEASE);
 255 }
 256
 257
 258 static volatile int cb_count = 0;
 259
 260 /* callback for second stress test. will only be called
 261  * on main lcore
 262  */
 263 static void
 264 timer_stress2_cb(struct rte_timer *tim __rte_unused, void *arg __rte_unused)
 265 {
 266         cb_count++;
 267 }
 268
 269 #define NB_STRESS2_TIMERS 8192
 270
 271 static int
 272 timer_stress2_main_loop(__rte_unused void *arg)
 273 {
 274         static struct rte_timer *timers;
 275         int i, ret;
 276         uint64_t delay = rte_get_timer_hz() / 20;
 277         unsigned int lcore_id = rte_lcore_id();
 278         unsigned int main_lcore = rte_get_main_lcore();
 279         int32_t my_collisions = 0;
 280         static uint32_t collisions;
 281
 282         if (lcore_id == main_lcore) {
 283                 cb_count = 0;
 284                 test_failed = 0;
 285                 __atomic_store_n(&collisions, 0, __ATOMIC_RELAXED);
 286                 timers = rte_malloc(NULL, sizeof(*timers) * NB_STRESS2_TIMERS, 0);
 287                 if (timers == NULL) {
 288                         printf("Test Failed\n");
 289                         printf("- Cannot allocate memory for timers\n" );
 290                         test_failed = 1;
 291                         main_start_workers();
 292                         goto cleanup;
 293                 }
 294                 for (i = 0; i < NB_STRESS2_TIMERS; i++)
 295                         rte_timer_init(&timers[i]);
 296                 main_start_workers();
 297         } else {
 298                 worker_wait_to_start();
 299                 if (test_failed)
 300                         goto cleanup;
 301         }
 302
 303         /* have all cores schedule all timers on main lcore */
 304         for (i = 0; i < NB_STRESS2_TIMERS; i++) {
 305                 ret = rte_timer_reset(&timers[i], delay, SINGLE, main_lcore,
 306                                 timer_stress2_cb, NULL);
 307                 /* there will be collisions when multiple cores simultaneously
 308                  * configure the same timers */
 309                 if (ret != 0)
 310                         my_collisions++;
 311         }
 312         if (my_collisions != 0)
 313                 __atomic_fetch_add(&collisions, my_collisions, __ATOMIC_RELAXED);
 314
 315         /* wait long enough for timers to expire */
 316         rte_delay_ms(100);
 317
 318         /* all cores rendezvous */
 319         if (lcore_id == main_lcore) {
 320                 main_wait_for_workers();
 321         } else {
 322                 worker_finish();
 323         }
 324
 325         /* now check that we get the right number of callbacks */
 326         if (lcore_id == main_lcore) {
 327                 my_collisions = __atomic_load_n(&collisions, __ATOMIC_RELAXED);
 328                 if (my_collisions != 0)
 329                         printf("- %d timer reset collisions (OK)\n", my_collisions);
 330                 rte_timer_manage();
 331                 if (cb_count != NB_STRESS2_TIMERS) {
 332                         printf("Test Failed\n");
 333                         printf("- Stress test 2, part 1 failed\n");
 334                         printf("- Expected %d callbacks, got %d\n", NB_STRESS2_TIMERS,
 335                                         cb_count);
 336                         test_failed = 1;
 337                         main_start_workers();
 338                         goto cleanup;
 339                 }
 340                 cb_count = 0;
 341
 342                 /* proceed */
 343                 main_start_workers();
 344         } else {
 345                 /* proceed */
 346                 worker_wait_to_start();
 347                 if (test_failed)
 348                         goto cleanup;
 349         }
 350
 351         /* now test again, just stop and restart timers at random after init*/
 352         for (i = 0; i < NB_STRESS2_TIMERS; i++)
 353                 rte_timer_reset(&timers[i], delay, SINGLE, main_lcore,
 354                                 timer_stress2_cb, NULL);
 355
 356         /* pick random timer to reset, stopping them first half the time */
 357         for (i = 0; i < 100000; i++) {
 358                 int r = rand() % NB_STRESS2_TIMERS;
 359                 if (i % 2)
 360                         rte_timer_stop(&timers[r]);
 361                 rte_timer_reset(&timers[r], delay, SINGLE, main_lcore,
 362                                 timer_stress2_cb, NULL);
 363         }
 364
 365         /* wait long enough for timers to expire */
 366         rte_delay_ms(100);
 367
 368         /* now check that we get the right number of callbacks */
 369         if (lcore_id == main_lcore) {
 370                 main_wait_for_workers();
 371
 372                 rte_timer_manage();
 373                 if (cb_count != NB_STRESS2_TIMERS) {
 374                         printf("Test Failed\n");
 375                         printf("- Stress test 2, part 2 failed\n");
 376                         printf("- Expected %d callbacks, got %d\n", NB_STRESS2_TIMERS,
 377                                         cb_count);
 378                         test_failed = 1;
 379                 } else {
 380                         printf("Test OK\n");
 381                 }
 382         }
 383
 384 cleanup:
 385         if (lcore_id == main_lcore) {
 386                 main_wait_for_workers();
 387                 if (timers != NULL) {
 388                         rte_free(timers);
 389                         timers = NULL;
 390                 }
 391         } else {
 392                 worker_finish();
 393         }
 394
 395         return 0;
 396 }
 397
 398 /* timer callback for basic tests */
 399 static void
 400 timer_basic_cb(struct rte_timer *tim, void *arg)
 401 {
 402         struct mytimerinfo *timinfo = arg;
 403         uint64_t hz = rte_get_timer_hz();
 404         unsigned lcore_id = rte_lcore_id();
 405         uint64_t cur_time = rte_get_timer_cycles();
 406
 407         if (rte_timer_pending(tim))
 408                 return;
 409
 410         timinfo->count ++;
 411
 412         RTE_LOG(INFO, TESTTIMER,
 413                 "%"PRIu64": callback id=%u count=%u on core %u\n",
 414                 cur_time, timinfo->id, timinfo->count, lcore_id);
 415
 416         /* reload timer 0 on same core */
 417         if (timinfo->id == 0 && timinfo->count < 20) {
 418                 mytimer_reset(timinfo, hz, SINGLE, lcore_id, timer_basic_cb);
 419                 return;
 420         }
 421
 422         /* reload timer 1 on next core */
 423         if (timinfo->id == 1 && timinfo->count < 10) {
 424                 mytimer_reset(timinfo, hz*2, SINGLE,
 425                               rte_get_next_lcore(lcore_id, 0, 1),
 426                               timer_basic_cb);
 427                 return;
 428         }
 429
 430         /* Explicitly stop timer 0. Once stop() called, we can even
 431          * erase the content of the structure: it is not referenced
 432          * anymore by any code (in case of dynamic structure, it can
 433          * be freed) */
 434         if (timinfo->id == 0 && timinfo->count == 20) {
 435
 436                 /* stop_sync() is not needed, because we know that the
 437                  * status of timer is only modified by this core */
 438                 rte_timer_stop(tim);
 439                 memset(tim, 0xAA, sizeof(struct rte_timer));
 440                 return;
 441         }
 442
 443         /* stop timer3, and restart a new timer0 (it was removed 5
 444          * seconds ago) for a single shot */
 445         if (timinfo->id == 2 && timinfo->count == 25) {
 446                 rte_timer_stop_sync(&mytiminfo[3].tim);
 447
 448                 /* need to reinit because structure was erased with 0xAA */
 449                 rte_timer_init(&mytiminfo[0].tim);
 450                 mytimer_reset(&mytiminfo[0], hz, SINGLE, lcore_id,
 451                               timer_basic_cb);
 452         }
 453 }
 454
 455 static int
 456 timer_basic_main_loop(__rte_unused void *arg)
 457 {
 458         uint64_t hz = rte_get_timer_hz();
 459         unsigned lcore_id = rte_lcore_id();
 460         uint64_t cur_time;
 461         int64_t diff = 0;
 462
 463         /* launch all timers on core 0 */
 464         if (lcore_id == rte_get_main_lcore()) {
 465                 mytimer_reset(&mytiminfo[0], hz/4, SINGLE, lcore_id,
 466                               timer_basic_cb);
 467                 mytimer_reset(&mytiminfo[1], hz/2, SINGLE, lcore_id,
 468                               timer_basic_cb);
 469                 mytimer_reset(&mytiminfo[2], hz/4, PERIODICAL, lcore_id,
 470                               timer_basic_cb);
 471                 mytimer_reset(&mytiminfo[3], hz/4, PERIODICAL,
 472                               rte_get_next_lcore(lcore_id, 0, 1),
 473                               timer_basic_cb);
 474         }
 475
 476         while (diff >= 0) {
 477
 478                 /* call the timer handler on each core */
 479                 rte_timer_manage();
 480
 481                 /* simulate the processing of a packet
 482                  * (3 us = 6000 cycles at 2 Ghz) */
 483                 rte_delay_us(3);
 484
 485                 cur_time = rte_get_timer_cycles();
 486                 diff = end_time - cur_time;
 487         }
 488         RTE_LOG(INFO, TESTTIMER, "core %u finished\n", lcore_id);
 489
 490         return 0;
 491 }
 492
 493 static int
 494 timer_sanity_check(void)
 495 {
 496 #ifdef RTE_LIBEAL_USE_HPET
 497         if (eal_timer_source != EAL_TIMER_HPET) {
 498                 printf("Not using HPET, can't sanity check timer sources\n");
 499                 return 0;
 500         }
 501
 502         const uint64_t t_hz = rte_get_tsc_hz();
 503         const uint64_t h_hz = rte_get_hpet_hz();
 504         printf("Hertz values: TSC = %"PRIu64", HPET = %"PRIu64"\n", t_hz, h_hz);
 505
 506         const uint64_t tsc_start = rte_get_tsc_cycles();
 507         const uint64_t hpet_start = rte_get_hpet_cycles();
 508         rte_delay_ms(100); /* delay 1/10 second */
 509         const uint64_t tsc_end = rte_get_tsc_cycles();
 510         const uint64_t hpet_end = rte_get_hpet_cycles();
 511         printf("Measured cycles: TSC = %"PRIu64", HPET = %"PRIu64"\n",
 512                         tsc_end-tsc_start, hpet_end-hpet_start);
 513
 514         const double tsc_time = (double)(tsc_end - tsc_start)/t_hz;
 515         const double hpet_time = (double)(hpet_end - hpet_start)/h_hz;
 516         /* get the percentage that the times differ by */
 517         const double time_diff = fabs(tsc_time - hpet_time)*100/tsc_time;
 518         printf("Measured time: TSC = %.4f, HPET = %.4f\n", tsc_time, hpet_time);
 519
 520         printf("Elapsed time measured by TSC and HPET differ by %f%%\n",
 521                         time_diff);
 522         if (time_diff > 0.1) {
 523                 printf("Error times differ by >0.1%%");
 524                 return -1;
 525         }
 526 #endif
 527         return 0;
 528 }
 529
 530 static int
 531 test_timer(void)
 532 {
 533         unsigned i;
 534         uint64_t cur_time;
 535         uint64_t hz;
 536
 537         if (rte_lcore_count() < 2) {
 538                 printf("Not enough cores for timer_autotest, expecting at least 2\n");
 539                 return TEST_SKIPPED;
 540         }
 541
 542         /* sanity check our timer sources and timer config values */
 543         if (timer_sanity_check() < 0) {
 544                 printf("Timer sanity checks failed\n");
 545                 return TEST_FAILED;
 546         }
 547
 548         /* init timer */
 549         for (i=0; i<NB_TIMER; i++) {
 550                 memset(&mytiminfo[i], 0, sizeof(struct mytimerinfo));
 551                 mytiminfo[i].id = i;
 552                 rte_timer_init(&mytiminfo[i].tim);
 553         }
 554
 555         /* calculate the "end of test" time */
 556         cur_time = rte_get_timer_cycles();
 557         hz = rte_get_timer_hz();
 558         end_time = cur_time + (hz * TEST_DURATION_S);
 559
 560         /* start other cores */
 561         printf("Start timer stress tests\n");
 562         rte_eal_mp_remote_launch(timer_stress_main_loop, NULL, CALL_MAIN);
 563         rte_eal_mp_wait_lcore();
 564
 565         /* stop timer 0 used for stress test */
 566         rte_timer_stop_sync(&mytiminfo[0].tim);
 567
 568         /* run a second, slightly different set of stress tests */
 569         printf("\nStart timer stress tests 2\n");
 570         test_failed = 0;
 571         main_init_workers();
 572         rte_eal_mp_remote_launch(timer_stress2_main_loop, NULL, CALL_MAIN);
 573         rte_eal_mp_wait_lcore();
 574         if (test_failed)
 575                 return TEST_FAILED;
 576
 577         /* calculate the "end of test" time */
 578         cur_time = rte_get_timer_cycles();
 579         hz = rte_get_timer_hz();
 580         end_time = cur_time + (hz * TEST_DURATION_S);
 581
 582         /* start other cores */
 583         printf("\nStart timer basic tests\n");
 584         rte_eal_mp_remote_launch(timer_basic_main_loop, NULL, CALL_MAIN);
 585         rte_eal_mp_wait_lcore();
 586
 587         /* stop all timers */
 588         for (i=0; i<NB_TIMER; i++) {
 589                 rte_timer_stop_sync(&mytiminfo[i].tim);
 590         }
 591
 592         rte_timer_dump_stats(stdout);
 593
 594         return TEST_SUCCESS;
 595 }
 596
 597 REGISTER_TEST_COMMAND(timer_autotest, test_timer);