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
mytimer_reset(struct mytimerinfo * timinfo,uint64_t ticks,enum rte_timer_type type,unsigned tim_lcore,rte_timer_cb_t fct)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
timer_stress_cb(__rte_unused struct rte_timer * tim,__rte_unused void * arg)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
timer_stress_main_loop(__rte_unused void * arg)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
main_init_workers(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
main_start_workers(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
main_wait_for_workers(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
worker_wait_to_start(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
worker_finish(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
timer_stress2_cb(struct rte_timer * tim __rte_unused,void * arg __rte_unused)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
timer_stress2_main_loop(__rte_unused void * arg)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
timer_basic_cb(struct rte_timer * tim,void * arg)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
timer_basic_main_loop(__rte_unused void * arg)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
timer_sanity_check(void)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
test_timer(void)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);
598