app/test/test_timer.c

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