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