dpdk/app/test/test_timer.c
<<
>>
Prefs
   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_atomic.h>
 106#include <rte_timer.h>
 107#include <rte_random.h>
 108#include <rte_malloc.h>
 109#include <rte_pause.h>
 110
 111#define TEST_DURATION_S 1 /* in seconds */
 112#define NB_TIMER 4
 113
 114#define RTE_LOGTYPE_TESTTIMER RTE_LOGTYPE_USER3
 115
 116static volatile uint64_t end_time;
 117static volatile int test_failed;
 118
 119struct mytimerinfo {
 120        struct rte_timer tim;
 121        unsigned id;
 122        unsigned count;
 123};
 124
 125static struct mytimerinfo mytiminfo[NB_TIMER];
 126
 127static void timer_basic_cb(struct rte_timer *tim, void *arg);
 128
 129static void
 130mytimer_reset(struct mytimerinfo *timinfo, uint64_t ticks,
 131              enum rte_timer_type type, unsigned tim_lcore,
 132              rte_timer_cb_t fct)
 133{
 134        rte_timer_reset_sync(&timinfo->tim, ticks, type, tim_lcore,
 135                             fct, timinfo);
 136}
 137
 138/* timer callback for stress tests */
 139static void
 140timer_stress_cb(__rte_unused struct rte_timer *tim,
 141                __rte_unused void *arg)
 142{
 143        long r;
 144        unsigned lcore_id = rte_lcore_id();
 145        uint64_t hz = rte_get_timer_hz();
 146
 147        if (rte_timer_pending(tim))
 148                return;
 149
 150        r = rte_rand();
 151        if ((r & 0xff) == 0) {
 152                mytimer_reset(&mytiminfo[0], hz, SINGLE, lcore_id,
 153                              timer_stress_cb);
 154        }
 155        else if ((r & 0xff) == 1) {
 156                mytimer_reset(&mytiminfo[0], hz, SINGLE,
 157                              rte_get_next_lcore(lcore_id, 0, 1),
 158                              timer_stress_cb);
 159        }
 160        else if ((r & 0xff) == 2) {
 161                rte_timer_stop(&mytiminfo[0].tim);
 162        }
 163}
 164
 165static int
 166timer_stress_main_loop(__rte_unused void *arg)
 167{
 168        uint64_t hz = rte_get_timer_hz();
 169        unsigned lcore_id = rte_lcore_id();
 170        uint64_t cur_time;
 171        int64_t diff = 0;
 172        long r;
 173
 174        while (diff >= 0) {
 175
 176                /* call the timer handler on each core */
 177                rte_timer_manage();
 178
 179                /* simulate the processing of a packet
 180                 * (1 us = 2000 cycles at 2 Ghz) */
 181                rte_delay_us(1);
 182
 183                /* randomly stop or reset timer */
 184                r = rte_rand();
 185                lcore_id = rte_get_next_lcore(lcore_id, 0, 1);
 186                if ((r & 0xff) == 0) {
 187                        /* 100 us */
 188                        mytimer_reset(&mytiminfo[0], hz/10000, SINGLE, lcore_id,
 189                                      timer_stress_cb);
 190                }
 191                else if ((r & 0xff) == 1) {
 192                        rte_timer_stop_sync(&mytiminfo[0].tim);
 193                }
 194                cur_time = rte_get_timer_cycles();
 195                diff = end_time - cur_time;
 196        }
 197
 198        lcore_id = rte_lcore_id();
 199        RTE_LOG(INFO, TESTTIMER, "core %u finished\n", lcore_id);
 200
 201        return 0;
 202}
 203
 204/* Need to synchronize worker lcores through multiple steps. */
 205enum { WORKER_WAITING = 1, WORKER_RUN_SIGNAL, WORKER_RUNNING, WORKER_FINISHED };
 206static rte_atomic16_t lcore_state[RTE_MAX_LCORE];
 207
 208static void
 209main_init_workers(void)
 210{
 211        unsigned i;
 212
 213        RTE_LCORE_FOREACH_WORKER(i) {
 214                rte_atomic16_set(&lcore_state[i], WORKER_WAITING);
 215        }
 216}
 217
 218static void
 219main_start_workers(void)
 220{
 221        unsigned i;
 222
 223        RTE_LCORE_FOREACH_WORKER(i) {
 224                rte_atomic16_set(&lcore_state[i], WORKER_RUN_SIGNAL);
 225        }
 226        RTE_LCORE_FOREACH_WORKER(i) {
 227                while (rte_atomic16_read(&lcore_state[i]) != WORKER_RUNNING)
 228                        rte_pause();
 229        }
 230}
 231
 232static void
 233main_wait_for_workers(void)
 234{
 235        unsigned i;
 236
 237        RTE_LCORE_FOREACH_WORKER(i) {
 238                while (rte_atomic16_read(&lcore_state[i]) != WORKER_FINISHED)
 239                        rte_pause();
 240        }
 241}
 242
 243static void
 244worker_wait_to_start(void)
 245{
 246        unsigned lcore_id = rte_lcore_id();
 247
 248        while (rte_atomic16_read(&lcore_state[lcore_id]) != WORKER_RUN_SIGNAL)
 249                rte_pause();
 250        rte_atomic16_set(&lcore_state[lcore_id], WORKER_RUNNING);
 251}
 252
 253static void
 254worker_finish(void)
 255{
 256        unsigned lcore_id = rte_lcore_id();
 257
 258        rte_atomic16_set(&lcore_state[lcore_id], WORKER_FINISHED);
 259}
 260
 261
 262static volatile int cb_count = 0;
 263
 264/* callback for second stress test. will only be called
 265 * on main lcore
 266 */
 267static void
 268timer_stress2_cb(struct rte_timer *tim __rte_unused, void *arg __rte_unused)
 269{
 270        cb_count++;
 271}
 272
 273#define NB_STRESS2_TIMERS 8192
 274
 275static int
 276timer_stress2_main_loop(__rte_unused void *arg)
 277{
 278        static struct rte_timer *timers;
 279        int i, ret;
 280        uint64_t delay = rte_get_timer_hz() / 20;
 281        unsigned int lcore_id = rte_lcore_id();
 282        unsigned int main_lcore = rte_get_main_lcore();
 283        int32_t my_collisions = 0;
 284        static rte_atomic32_t collisions;
 285
 286        if (lcore_id == main_lcore) {
 287                cb_count = 0;
 288                test_failed = 0;
 289                rte_atomic32_set(&collisions, 0);
 290                main_init_workers();
 291                timers = rte_malloc(NULL, sizeof(*timers) * NB_STRESS2_TIMERS, 0);
 292                if (timers == NULL) {
 293                        printf("Test Failed\n");
 294                        printf("- Cannot allocate memory for timers\n" );
 295                        test_failed = 1;
 296                        main_start_workers();
 297                        goto cleanup;
 298                }
 299                for (i = 0; i < NB_STRESS2_TIMERS; i++)
 300                        rte_timer_init(&timers[i]);
 301                main_start_workers();
 302        } else {
 303                worker_wait_to_start();
 304                if (test_failed)
 305                        goto cleanup;
 306        }
 307
 308        /* have all cores schedule all timers on main lcore */
 309        for (i = 0; i < NB_STRESS2_TIMERS; i++) {
 310                ret = rte_timer_reset(&timers[i], delay, SINGLE, main_lcore,
 311                                timer_stress2_cb, NULL);
 312                /* there will be collisions when multiple cores simultaneously
 313                 * configure the same timers */
 314                if (ret != 0)
 315                        my_collisions++;
 316        }
 317        if (my_collisions != 0)
 318                rte_atomic32_add(&collisions, my_collisions);
 319
 320        /* wait long enough for timers to expire */
 321        rte_delay_ms(100);
 322
 323        /* all cores rendezvous */
 324        if (lcore_id == main_lcore) {
 325                main_wait_for_workers();
 326        } else {
 327                worker_finish();
 328        }
 329
 330        /* now check that we get the right number of callbacks */
 331        if (lcore_id == main_lcore) {
 332                my_collisions = rte_atomic32_read(&collisions);
 333                if (my_collisions != 0)
 334                        printf("- %d timer reset collisions (OK)\n", my_collisions);
 335                rte_timer_manage();
 336                if (cb_count != NB_STRESS2_TIMERS) {
 337                        printf("Test Failed\n");
 338                        printf("- Stress test 2, part 1 failed\n");
 339                        printf("- Expected %d callbacks, got %d\n", NB_STRESS2_TIMERS,
 340                                        cb_count);
 341                        test_failed = 1;
 342                        main_start_workers();
 343                        goto cleanup;
 344                }
 345                cb_count = 0;
 346
 347                /* proceed */
 348                main_start_workers();
 349        } else {
 350                /* proceed */
 351                worker_wait_to_start();
 352                if (test_failed)
 353                        goto cleanup;
 354        }
 355
 356        /* now test again, just stop and restart timers at random after init*/
 357        for (i = 0; i < NB_STRESS2_TIMERS; i++)
 358                rte_timer_reset(&timers[i], delay, SINGLE, main_lcore,
 359                                timer_stress2_cb, NULL);
 360
 361        /* pick random timer to reset, stopping them first half the time */
 362        for (i = 0; i < 100000; i++) {
 363                int r = rand() % NB_STRESS2_TIMERS;
 364                if (i % 2)
 365                        rte_timer_stop(&timers[r]);
 366                rte_timer_reset(&timers[r], delay, SINGLE, main_lcore,
 367                                timer_stress2_cb, NULL);
 368        }
 369
 370        /* wait long enough for timers to expire */
 371        rte_delay_ms(100);
 372
 373        /* now check that we get the right number of callbacks */
 374        if (lcore_id == main_lcore) {
 375                main_wait_for_workers();
 376
 377                rte_timer_manage();
 378                if (cb_count != NB_STRESS2_TIMERS) {
 379                        printf("Test Failed\n");
 380                        printf("- Stress test 2, part 2 failed\n");
 381                        printf("- Expected %d callbacks, got %d\n", NB_STRESS2_TIMERS,
 382                                        cb_count);
 383                        test_failed = 1;
 384                } else {
 385                        printf("Test OK\n");
 386                }
 387        }
 388
 389cleanup:
 390        if (lcore_id == main_lcore) {
 391                main_wait_for_workers();
 392                if (timers != NULL) {
 393                        rte_free(timers);
 394                        timers = NULL;
 395                }
 396        } else {
 397                worker_finish();
 398        }
 399
 400        return 0;
 401}
 402
 403/* timer callback for basic tests */
 404static void
 405timer_basic_cb(struct rte_timer *tim, void *arg)
 406{
 407        struct mytimerinfo *timinfo = arg;
 408        uint64_t hz = rte_get_timer_hz();
 409        unsigned lcore_id = rte_lcore_id();
 410        uint64_t cur_time = rte_get_timer_cycles();
 411
 412        if (rte_timer_pending(tim))
 413                return;
 414
 415        timinfo->count ++;
 416
 417        RTE_LOG(INFO, TESTTIMER,
 418                "%"PRIu64": callback id=%u count=%u on core %u\n",
 419                cur_time, timinfo->id, timinfo->count, lcore_id);
 420
 421        /* reload timer 0 on same core */
 422        if (timinfo->id == 0 && timinfo->count < 20) {
 423                mytimer_reset(timinfo, hz, SINGLE, lcore_id, timer_basic_cb);
 424                return;
 425        }
 426
 427        /* reload timer 1 on next core */
 428        if (timinfo->id == 1 && timinfo->count < 10) {
 429                mytimer_reset(timinfo, hz*2, SINGLE,
 430                              rte_get_next_lcore(lcore_id, 0, 1),
 431                              timer_basic_cb);
 432                return;
 433        }
 434
 435        /* Explicitelly stop timer 0. Once stop() called, we can even
 436         * erase the content of the structure: it is not referenced
 437         * anymore by any code (in case of dynamic structure, it can
 438         * be freed) */
 439        if (timinfo->id == 0 && timinfo->count == 20) {
 440
 441                /* stop_sync() is not needed, because we know that the
 442                 * status of timer is only modified by this core */
 443                rte_timer_stop(tim);
 444                memset(tim, 0xAA, sizeof(struct rte_timer));
 445                return;
 446        }
 447
 448        /* stop timer3, and restart a new timer0 (it was removed 5
 449         * seconds ago) for a single shot */
 450        if (timinfo->id == 2 && timinfo->count == 25) {
 451                rte_timer_stop_sync(&mytiminfo[3].tim);
 452
 453                /* need to reinit because structure was erased with 0xAA */
 454                rte_timer_init(&mytiminfo[0].tim);
 455                mytimer_reset(&mytiminfo[0], hz, SINGLE, lcore_id,
 456                              timer_basic_cb);
 457        }
 458}
 459
 460static int
 461timer_basic_main_loop(__rte_unused void *arg)
 462{
 463        uint64_t hz = rte_get_timer_hz();
 464        unsigned lcore_id = rte_lcore_id();
 465        uint64_t cur_time;
 466        int64_t diff = 0;
 467
 468        /* launch all timers on core 0 */
 469        if (lcore_id == rte_get_main_lcore()) {
 470                mytimer_reset(&mytiminfo[0], hz/4, SINGLE, lcore_id,
 471                              timer_basic_cb);
 472                mytimer_reset(&mytiminfo[1], hz/2, SINGLE, lcore_id,
 473                              timer_basic_cb);
 474                mytimer_reset(&mytiminfo[2], hz/4, PERIODICAL, lcore_id,
 475                              timer_basic_cb);
 476                mytimer_reset(&mytiminfo[3], hz/4, PERIODICAL,
 477                              rte_get_next_lcore(lcore_id, 0, 1),
 478                              timer_basic_cb);
 479        }
 480
 481        while (diff >= 0) {
 482
 483                /* call the timer handler on each core */
 484                rte_timer_manage();
 485
 486                /* simulate the processing of a packet
 487                 * (3 us = 6000 cycles at 2 Ghz) */
 488                rte_delay_us(3);
 489
 490                cur_time = rte_get_timer_cycles();
 491                diff = end_time - cur_time;
 492        }
 493        RTE_LOG(INFO, TESTTIMER, "core %u finished\n", lcore_id);
 494
 495        return 0;
 496}
 497
 498static int
 499timer_sanity_check(void)
 500{
 501#ifdef RTE_LIBEAL_USE_HPET
 502        if (eal_timer_source != EAL_TIMER_HPET) {
 503                printf("Not using HPET, can't sanity check timer sources\n");
 504                return 0;
 505        }
 506
 507        const uint64_t t_hz = rte_get_tsc_hz();
 508        const uint64_t h_hz = rte_get_hpet_hz();
 509        printf("Hertz values: TSC = %"PRIu64", HPET = %"PRIu64"\n", t_hz, h_hz);
 510
 511        const uint64_t tsc_start = rte_get_tsc_cycles();
 512        const uint64_t hpet_start = rte_get_hpet_cycles();
 513        rte_delay_ms(100); /* delay 1/10 second */
 514        const uint64_t tsc_end = rte_get_tsc_cycles();
 515        const uint64_t hpet_end = rte_get_hpet_cycles();
 516        printf("Measured cycles: TSC = %"PRIu64", HPET = %"PRIu64"\n",
 517                        tsc_end-tsc_start, hpet_end-hpet_start);
 518
 519        const double tsc_time = (double)(tsc_end - tsc_start)/t_hz;
 520        const double hpet_time = (double)(hpet_end - hpet_start)/h_hz;
 521        /* get the percentage that the times differ by */
 522        const double time_diff = fabs(tsc_time - hpet_time)*100/tsc_time;
 523        printf("Measured time: TSC = %.4f, HPET = %.4f\n", tsc_time, hpet_time);
 524
 525        printf("Elapsed time measured by TSC and HPET differ by %f%%\n",
 526                        time_diff);
 527        if (time_diff > 0.1) {
 528                printf("Error times differ by >0.1%%");
 529                return -1;
 530        }
 531#endif
 532        return 0;
 533}
 534
 535static int
 536test_timer(void)
 537{
 538        unsigned i;
 539        uint64_t cur_time;
 540        uint64_t hz;
 541
 542        if (rte_lcore_count() < 2) {
 543                printf("Not enough cores for timer_autotest, expecting at least 2\n");
 544                return TEST_SKIPPED;
 545        }
 546
 547        /* sanity check our timer sources and timer config values */
 548        if (timer_sanity_check() < 0) {
 549                printf("Timer sanity checks failed\n");
 550                return TEST_FAILED;
 551        }
 552
 553        /* init timer */
 554        for (i=0; i<NB_TIMER; i++) {
 555                memset(&mytiminfo[i], 0, sizeof(struct mytimerinfo));
 556                mytiminfo[i].id = i;
 557                rte_timer_init(&mytiminfo[i].tim);
 558        }
 559
 560        /* calculate the "end of test" time */
 561        cur_time = rte_get_timer_cycles();
 562        hz = rte_get_timer_hz();
 563        end_time = cur_time + (hz * TEST_DURATION_S);
 564
 565        /* start other cores */
 566        printf("Start timer stress tests\n");
 567        rte_eal_mp_remote_launch(timer_stress_main_loop, NULL, CALL_MAIN);
 568        rte_eal_mp_wait_lcore();
 569
 570        /* stop timer 0 used for stress test */
 571        rte_timer_stop_sync(&mytiminfo[0].tim);
 572
 573        /* run a second, slightly different set of stress tests */
 574        printf("\nStart timer stress tests 2\n");
 575        test_failed = 0;
 576        rte_eal_mp_remote_launch(timer_stress2_main_loop, NULL, CALL_MAIN);
 577        rte_eal_mp_wait_lcore();
 578        if (test_failed)
 579                return TEST_FAILED;
 580
 581        /* calculate the "end of test" time */
 582        cur_time = rte_get_timer_cycles();
 583        hz = rte_get_timer_hz();
 584        end_time = cur_time + (hz * TEST_DURATION_S);
 585
 586        /* start other cores */
 587        printf("\nStart timer basic tests\n");
 588        rte_eal_mp_remote_launch(timer_basic_main_loop, NULL, CALL_MAIN);
 589        rte_eal_mp_wait_lcore();
 590
 591        /* stop all timers */
 592        for (i=0; i<NB_TIMER; i++) {
 593                rte_timer_stop_sync(&mytiminfo[i].tim);
 594        }
 595
 596        rte_timer_dump_stats(stdout);
 597
 598        return TEST_SUCCESS;
 599}
 600
 601REGISTER_TEST_COMMAND(timer_autotest, test_timer);
 602