de0c312fa69e81d43fc082995b4b6bdebf8aa5a2
[deb_dpdk.git] / test / 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_eal.h>
133 #include <rte_per_lcore.h>
134 #include <rte_lcore.h>
135 #include <rte_atomic.h>
136 #include <rte_timer.h>
137 #include <rte_random.h>
138 #include <rte_malloc.h>
139 #include <rte_pause.h>
140
141 #define TEST_DURATION_S 1 /* in seconds */
142 #define NB_TIMER 4
143
144 #define RTE_LOGTYPE_TESTTIMER RTE_LOGTYPE_USER3
145
146 static volatile uint64_t end_time;
147 static volatile int test_failed;
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 /* Need to synchronize slave lcores through multiple steps. */
235 enum { SLAVE_WAITING = 1, SLAVE_RUN_SIGNAL, SLAVE_RUNNING, SLAVE_FINISHED };
236 static rte_atomic16_t slave_state[RTE_MAX_LCORE];
237
238 static void
239 master_init_slaves(void)
240 {
241         unsigned i;
242
243         RTE_LCORE_FOREACH_SLAVE(i) {
244                 rte_atomic16_set(&slave_state[i], SLAVE_WAITING);
245         }
246 }
247
248 static void
249 master_start_slaves(void)
250 {
251         unsigned i;
252
253         RTE_LCORE_FOREACH_SLAVE(i) {
254                 rte_atomic16_set(&slave_state[i], SLAVE_RUN_SIGNAL);
255         }
256         RTE_LCORE_FOREACH_SLAVE(i) {
257                 while (rte_atomic16_read(&slave_state[i]) != SLAVE_RUNNING)
258                         rte_pause();
259         }
260 }
261
262 static void
263 master_wait_for_slaves(void)
264 {
265         unsigned i;
266
267         RTE_LCORE_FOREACH_SLAVE(i) {
268                 while (rte_atomic16_read(&slave_state[i]) != SLAVE_FINISHED)
269                         rte_pause();
270         }
271 }
272
273 static void
274 slave_wait_to_start(void)
275 {
276         unsigned lcore_id = rte_lcore_id();
277
278         while (rte_atomic16_read(&slave_state[lcore_id]) != SLAVE_RUN_SIGNAL)
279                 rte_pause();
280         rte_atomic16_set(&slave_state[lcore_id], SLAVE_RUNNING);
281 }
282
283 static void
284 slave_finish(void)
285 {
286         unsigned lcore_id = rte_lcore_id();
287
288         rte_atomic16_set(&slave_state[lcore_id], SLAVE_FINISHED);
289 }
290
291
292 static volatile int cb_count = 0;
293
294 /* callback for second stress test. will only be called
295  * on master lcore */
296 static void
297 timer_stress2_cb(struct rte_timer *tim __rte_unused, void *arg __rte_unused)
298 {
299         cb_count++;
300 }
301
302 #define NB_STRESS2_TIMERS 8192
303
304 static int
305 timer_stress2_main_loop(__attribute__((unused)) void *arg)
306 {
307         static struct rte_timer *timers;
308         int i, ret;
309         uint64_t delay = rte_get_timer_hz() / 20;
310         unsigned lcore_id = rte_lcore_id();
311         unsigned master = rte_get_master_lcore();
312         int32_t my_collisions = 0;
313         static rte_atomic32_t collisions;
314
315         if (lcore_id == master) {
316                 cb_count = 0;
317                 test_failed = 0;
318                 rte_atomic32_set(&collisions, 0);
319                 master_init_slaves();
320                 timers = rte_malloc(NULL, sizeof(*timers) * NB_STRESS2_TIMERS, 0);
321                 if (timers == NULL) {
322                         printf("Test Failed\n");
323                         printf("- Cannot allocate memory for timers\n" );
324                         test_failed = 1;
325                         master_start_slaves();
326                         goto cleanup;
327                 }
328                 for (i = 0; i < NB_STRESS2_TIMERS; i++)
329                         rte_timer_init(&timers[i]);
330                 master_start_slaves();
331         } else {
332                 slave_wait_to_start();
333                 if (test_failed)
334                         goto cleanup;
335         }
336
337         /* have all cores schedule all timers on master lcore */
338         for (i = 0; i < NB_STRESS2_TIMERS; i++) {
339                 ret = rte_timer_reset(&timers[i], delay, SINGLE, master,
340                                 timer_stress2_cb, NULL);
341                 /* there will be collisions when multiple cores simultaneously
342                  * configure the same timers */
343                 if (ret != 0)
344                         my_collisions++;
345         }
346         if (my_collisions != 0)
347                 rte_atomic32_add(&collisions, my_collisions);
348
349         /* wait long enough for timers to expire */
350         rte_delay_ms(100);
351
352         /* all cores rendezvous */
353         if (lcore_id == master) {
354                 master_wait_for_slaves();
355         } else {
356                 slave_finish();
357         }
358
359         /* now check that we get the right number of callbacks */
360         if (lcore_id == master) {
361                 my_collisions = rte_atomic32_read(&collisions);
362                 if (my_collisions != 0)
363                         printf("- %d timer reset collisions (OK)\n", my_collisions);
364                 rte_timer_manage();
365                 if (cb_count != NB_STRESS2_TIMERS) {
366                         printf("Test Failed\n");
367                         printf("- Stress test 2, part 1 failed\n");
368                         printf("- Expected %d callbacks, got %d\n", NB_STRESS2_TIMERS,
369                                         cb_count);
370                         test_failed = 1;
371                         master_start_slaves();
372                         goto cleanup;
373                 }
374                 cb_count = 0;
375
376                 /* proceed */
377                 master_start_slaves();
378         } else {
379                 /* proceed */
380                 slave_wait_to_start();
381                 if (test_failed)
382                         goto cleanup;
383         }
384
385         /* now test again, just stop and restart timers at random after init*/
386         for (i = 0; i < NB_STRESS2_TIMERS; i++)
387                 rte_timer_reset(&timers[i], delay, SINGLE, master,
388                                 timer_stress2_cb, NULL);
389
390         /* pick random timer to reset, stopping them first half the time */
391         for (i = 0; i < 100000; i++) {
392                 int r = rand() % NB_STRESS2_TIMERS;
393                 if (i % 2)
394                         rte_timer_stop(&timers[r]);
395                 rte_timer_reset(&timers[r], delay, SINGLE, master,
396                                 timer_stress2_cb, NULL);
397         }
398
399         /* wait long enough for timers to expire */
400         rte_delay_ms(100);
401
402         /* now check that we get the right number of callbacks */
403         if (lcore_id == master) {
404                 master_wait_for_slaves();
405
406                 rte_timer_manage();
407                 if (cb_count != NB_STRESS2_TIMERS) {
408                         printf("Test Failed\n");
409                         printf("- Stress test 2, part 2 failed\n");
410                         printf("- Expected %d callbacks, got %d\n", NB_STRESS2_TIMERS,
411                                         cb_count);
412                         test_failed = 1;
413                 } else {
414                         printf("Test OK\n");
415                 }
416         }
417
418 cleanup:
419         if (lcore_id == master) {
420                 master_wait_for_slaves();
421                 if (timers != NULL) {
422                         rte_free(timers);
423                         timers = NULL;
424                 }
425         } else {
426                 slave_finish();
427         }
428
429         return 0;
430 }
431
432 /* timer callback for basic tests */
433 static void
434 timer_basic_cb(struct rte_timer *tim, void *arg)
435 {
436         struct mytimerinfo *timinfo = arg;
437         uint64_t hz = rte_get_timer_hz();
438         unsigned lcore_id = rte_lcore_id();
439         uint64_t cur_time = rte_get_timer_cycles();
440
441         if (rte_timer_pending(tim))
442                 return;
443
444         timinfo->count ++;
445
446         RTE_LOG(INFO, TESTTIMER,
447                 "%"PRIu64": callback id=%u count=%u on core %u\n",
448                 cur_time, timinfo->id, timinfo->count, lcore_id);
449
450         /* reload timer 0 on same core */
451         if (timinfo->id == 0 && timinfo->count < 20) {
452                 mytimer_reset(timinfo, hz, SINGLE, lcore_id, timer_basic_cb);
453                 return;
454         }
455
456         /* reload timer 1 on next core */
457         if (timinfo->id == 1 && timinfo->count < 10) {
458                 mytimer_reset(timinfo, hz*2, SINGLE,
459                               rte_get_next_lcore(lcore_id, 0, 1),
460                               timer_basic_cb);
461                 return;
462         }
463
464         /* Explicitelly stop timer 0. Once stop() called, we can even
465          * erase the content of the structure: it is not referenced
466          * anymore by any code (in case of dynamic structure, it can
467          * be freed) */
468         if (timinfo->id == 0 && timinfo->count == 20) {
469
470                 /* stop_sync() is not needed, because we know that the
471                  * status of timer is only modified by this core */
472                 rte_timer_stop(tim);
473                 memset(tim, 0xAA, sizeof(struct rte_timer));
474                 return;
475         }
476
477         /* stop timer3, and restart a new timer0 (it was removed 5
478          * seconds ago) for a single shot */
479         if (timinfo->id == 2 && timinfo->count == 25) {
480                 rte_timer_stop_sync(&mytiminfo[3].tim);
481
482                 /* need to reinit because structure was erased with 0xAA */
483                 rte_timer_init(&mytiminfo[0].tim);
484                 mytimer_reset(&mytiminfo[0], hz, SINGLE, lcore_id,
485                               timer_basic_cb);
486         }
487 }
488
489 static int
490 timer_basic_main_loop(__attribute__((unused)) void *arg)
491 {
492         uint64_t hz = rte_get_timer_hz();
493         unsigned lcore_id = rte_lcore_id();
494         uint64_t cur_time;
495         int64_t diff = 0;
496
497         /* launch all timers on core 0 */
498         if (lcore_id == rte_get_master_lcore()) {
499                 mytimer_reset(&mytiminfo[0], hz/4, SINGLE, lcore_id,
500                               timer_basic_cb);
501                 mytimer_reset(&mytiminfo[1], hz/2, SINGLE, lcore_id,
502                               timer_basic_cb);
503                 mytimer_reset(&mytiminfo[2], hz/4, PERIODICAL, lcore_id,
504                               timer_basic_cb);
505                 mytimer_reset(&mytiminfo[3], hz/4, PERIODICAL,
506                               rte_get_next_lcore(lcore_id, 0, 1),
507                               timer_basic_cb);
508         }
509
510         while (diff >= 0) {
511
512                 /* call the timer handler on each core */
513                 rte_timer_manage();
514
515                 /* simulate the processing of a packet
516                  * (3 us = 6000 cycles at 2 Ghz) */
517                 rte_delay_us(3);
518
519                 cur_time = rte_get_timer_cycles();
520                 diff = end_time - cur_time;
521         }
522         RTE_LOG(INFO, TESTTIMER, "core %u finished\n", lcore_id);
523
524         return 0;
525 }
526
527 static int
528 timer_sanity_check(void)
529 {
530 #ifdef RTE_LIBEAL_USE_HPET
531         if (eal_timer_source != EAL_TIMER_HPET) {
532                 printf("Not using HPET, can't sanity check timer sources\n");
533                 return 0;
534         }
535
536         const uint64_t t_hz = rte_get_tsc_hz();
537         const uint64_t h_hz = rte_get_hpet_hz();
538         printf("Hertz values: TSC = %"PRIu64", HPET = %"PRIu64"\n", t_hz, h_hz);
539
540         const uint64_t tsc_start = rte_get_tsc_cycles();
541         const uint64_t hpet_start = rte_get_hpet_cycles();
542         rte_delay_ms(100); /* delay 1/10 second */
543         const uint64_t tsc_end = rte_get_tsc_cycles();
544         const uint64_t hpet_end = rte_get_hpet_cycles();
545         printf("Measured cycles: TSC = %"PRIu64", HPET = %"PRIu64"\n",
546                         tsc_end-tsc_start, hpet_end-hpet_start);
547
548         const double tsc_time = (double)(tsc_end - tsc_start)/t_hz;
549         const double hpet_time = (double)(hpet_end - hpet_start)/h_hz;
550         /* get the percentage that the times differ by */
551         const double time_diff = fabs(tsc_time - hpet_time)*100/tsc_time;
552         printf("Measured time: TSC = %.4f, HPET = %.4f\n", tsc_time, hpet_time);
553
554         printf("Elapsed time measured by TSC and HPET differ by %f%%\n",
555                         time_diff);
556         if (time_diff > 0.1) {
557                 printf("Error times differ by >0.1%%");
558                 return -1;
559         }
560 #endif
561         return 0;
562 }
563
564 static int
565 test_timer(void)
566 {
567         unsigned i;
568         uint64_t cur_time;
569         uint64_t hz;
570
571         /* sanity check our timer sources and timer config values */
572         if (timer_sanity_check() < 0) {
573                 printf("Timer sanity checks failed\n");
574                 return TEST_FAILED;
575         }
576
577         if (rte_lcore_count() < 2) {
578                 printf("not enough lcores for this test\n");
579                 return TEST_FAILED;
580         }
581
582         /* init timer */
583         for (i=0; i<NB_TIMER; i++) {
584                 memset(&mytiminfo[i], 0, sizeof(struct mytimerinfo));
585                 mytiminfo[i].id = i;
586                 rte_timer_init(&mytiminfo[i].tim);
587         }
588
589         /* calculate the "end of test" time */
590         cur_time = rte_get_timer_cycles();
591         hz = rte_get_timer_hz();
592         end_time = cur_time + (hz * TEST_DURATION_S);
593
594         /* start other cores */
595         printf("Start timer stress tests\n");
596         rte_eal_mp_remote_launch(timer_stress_main_loop, NULL, CALL_MASTER);
597         rte_eal_mp_wait_lcore();
598
599         /* stop timer 0 used for stress test */
600         rte_timer_stop_sync(&mytiminfo[0].tim);
601
602         /* run a second, slightly different set of stress tests */
603         printf("\nStart timer stress tests 2\n");
604         test_failed = 0;
605         rte_eal_mp_remote_launch(timer_stress2_main_loop, NULL, CALL_MASTER);
606         rte_eal_mp_wait_lcore();
607         if (test_failed)
608                 return TEST_FAILED;
609
610         /* calculate the "end of test" time */
611         cur_time = rte_get_timer_cycles();
612         hz = rte_get_timer_hz();
613         end_time = cur_time + (hz * TEST_DURATION_S);
614
615         /* start other cores */
616         printf("\nStart timer basic tests\n");
617         rte_eal_mp_remote_launch(timer_basic_main_loop, NULL, CALL_MASTER);
618         rte_eal_mp_wait_lcore();
619
620         /* stop all timers */
621         for (i=0; i<NB_TIMER; i++) {
622                 rte_timer_stop_sync(&mytiminfo[i].tim);
623         }
624
625         rte_timer_dump_stats(stdout);
626
627         return TEST_SUCCESS;
628 }
629
630 REGISTER_TEST_COMMAND(timer_autotest, test_timer);