1 /*
2 * Copyright (c) 2022 Intel Corporation
3 *
4 * SPDX-License-Identifier: Apache-2.0
5 */
6
7 #include <zephyr/kernel.h>
8 #include <zephyr/sys/time_units.h>
9 #include <zephyr/tc_util.h>
10 #include <zephyr/ztest.h>
11
12 #define TIMERS 4
13 #define TEST_SECONDS 10
14 #define MAX_CALLBACKS (CONFIG_SYS_CLOCK_TICKS_PER_SEC*TEST_SECONDS)/TIMERS
15
16 struct timer_wrapper {
17 int64_t last_scheduled;
18 struct k_timer tm;
19 uint32_t callbacks;
20 uint32_t late_callbacks;
21 uint32_t last_isr;
22 uint32_t max_delta;
23 };
24
25 K_SEM_DEFINE(timers_sem, 0, K_SEM_MAX_LIMIT);
26
27 struct timer_wrapper timers[TIMERS];
28
tm_fn(struct k_timer * tm)29 void tm_fn(struct k_timer *tm)
30 {
31 struct timer_wrapper *tm_wrap =
32 CONTAINER_OF(tm, struct timer_wrapper, tm);
33 uint32_t now = k_cycle_get_32();
34
35 if (tm_wrap->last_isr != 0) {
36 uint32_t delta = now - tm_wrap->last_isr;
37
38 tm_wrap->max_delta = delta > tm_wrap->max_delta ? delta : tm_wrap->max_delta;
39 if (delta >= k_ticks_to_cyc_floor32(TIMERS + 1)) {
40 tm_wrap->late_callbacks++;
41 }
42 }
43 tm_wrap->last_isr = now;
44 tm_wrap->callbacks++;
45 if (tm_wrap->callbacks >= MAX_CALLBACKS) {
46 k_timer_stop(tm);
47 k_sem_give(&timers_sem);
48 } else {
49 int64_t next = tm_wrap->last_scheduled + TIMERS;
50
51 tm_wrap->last_scheduled = next;
52 k_timer_start(tm, K_TIMEOUT_ABS_TICKS(next), K_NO_WAIT);
53 }
54 }
55
56
57 /**
58 * @brief Test timers can be scheduled 1 tick apart without issues
59 *
60 * Schedules timers with absolute scheduling with a 1 tick
61 * period. Measures the total time elapsed and tries to run
62 * some fake busy work while doing so. If the print outs don't show up or
63 * the timer train is late to the station, the test fails.
64 */
ZTEST(timer_tick_train,test_one_tick_timer_train)65 ZTEST(timer_tick_train, test_one_tick_timer_train)
66 {
67 const uint32_t max_time = TEST_SECONDS*1000 + 1000;
68
69 TC_PRINT("Initializing %u Timers, Tick Rate %uHz, Expecting %u callbacks in %u ms\n",
70 TIMERS, CONFIG_SYS_CLOCK_TICKS_PER_SEC, MAX_CALLBACKS, max_time);
71
72 for (int i = 0; i < TIMERS; i++) {
73 k_timer_init(&timers[i].tm, tm_fn, NULL);
74 timers[i].max_delta = 0;
75 }
76
77 TC_PRINT("Starting Timers with Skews\n");
78 int64_t tick = k_uptime_ticks();
79
80 for (int i = 0; i < TIMERS; i++) {
81 timers[i].last_scheduled = tick + i;
82 k_timer_start(&timers[i].tm, K_TIMEOUT_ABS_TICKS(timers[i].last_scheduled),
83 K_NO_WAIT);
84 }
85
86 #ifdef CONFIG_TIMER_HAS_64BIT_CYCLE_COUNTER
87 uint64_t start_cycle = k_cycle_get_64();
88 #else
89 uint32_t start_time_ms = k_uptime_get();
90 #endif
91
92 uint32_t remaining_timers = TIMERS;
93
94 /* Do work in the meantime, proving there's enough time to do other things */
95 uint32_t busy_loops = 0;
96
97 while (true) {
98 while (k_sem_take(&timers_sem, K_NO_WAIT) == 0) {
99 remaining_timers--;
100
101 }
102 if (remaining_timers == 0) {
103 break;
104 }
105 TC_PRINT("Faking busy work, remaining timers is %u, timer callbacks %u\n",
106 remaining_timers, timers[0].callbacks);
107 busy_loops++;
108 k_busy_wait(250000);
109 }
110
111 #ifdef CONFIG_TIMER_HAS_64BIT_CYCLE_COUNTER
112 uint64_t end_cycle = k_cycle_get_64();
113 #else
114 uint64_t end_time_ms = k_uptime_get();
115 #endif
116
117 #ifdef CONFIG_TIMER_HAS_64BIT_CYCLE_COUNTER
118 uint64_t delta_cycles = end_cycle - start_cycle;
119 uint32_t delta_time = k_cyc_to_ms_floor32(delta_cycles);
120 #else
121 uint32_t delta_time = end_time_ms - start_time_ms;
122 #endif
123
124 TC_PRINT("One Tick Timer Train Done, took %u ms, busy loop ran %u times\n",
125 delta_time, busy_loops);
126
127 uint32_t max_delta = 0;
128
129 TC_PRINT(" Perfect delta %u cycles or %u us\n",
130 k_ticks_to_cyc_floor32(TIMERS), k_ticks_to_us_near32(TIMERS));
131 for (int i = 0; i < TIMERS; i++) {
132 TC_PRINT("Timer %d max delta %u cycles or %u us, "
133 "%u late callbacks (%u.%u%%)\n",
134 i, timers[i].max_delta,
135 k_cyc_to_us_near32(timers[i].max_delta),
136 timers[i].late_callbacks,
137 (1000 * timers[i].late_callbacks + MAX_CALLBACKS/2) / MAX_CALLBACKS / 10,
138 (1000 * timers[i].late_callbacks + MAX_CALLBACKS/2) / MAX_CALLBACKS % 10);
139 /* Record the stats gathered as a JSON object including related CONFIG_* params. */
140 TC_PRINT("RECORD: {"
141 "\"testcase\":\"one_tick_timer_train\""
142 ", \"timer\":%d, \"max_delta_cycles\":%u, \"max_delta_us\":%u"
143 ", \"late_callbacks\":%u"
144 ", \"perfect_delta_cycles\":%u, \"perfect_delta_us\":%u"
145 ", \"train_time_ms\":%u, \"busy_loops\":%u"
146 ", \"timers\":%u, \"expected_callbacks\":%u, \"expected_time_ms\":%u"
147 ", \"CONFIG_SYS_CLOCK_TICKS_PER_SEC\":%u"
148 "}\n",
149 i, timers[i].max_delta, k_cyc_to_us_near32(timers[i].max_delta),
150 timers[i].late_callbacks,
151 k_ticks_to_cyc_floor32(TIMERS), k_ticks_to_us_near32(TIMERS),
152 delta_time, busy_loops,
153 TIMERS, MAX_CALLBACKS, max_time,
154 CONFIG_SYS_CLOCK_TICKS_PER_SEC
155 );
156 max_delta = timers[i].max_delta > max_delta ? timers[i].max_delta : max_delta;
157 k_timer_stop(&timers[i].tm);
158 }
159
160 if (max_delta >= k_ticks_to_cyc_floor32(TIMERS + 1)) {
161 TC_PRINT("!! Some ticks were missed.\n");
162 TC_PRINT("!! Consider making CONFIG_SYS_CLOCK_TICKS_PER_SEC smaller.\n");
163 /* should this fail the test? */
164 }
165
166 const uint32_t maximum_busy_loops = TEST_SECONDS * 4;
167
168 if (busy_loops < (maximum_busy_loops - maximum_busy_loops/10)) {
169 TC_PRINT("!! The busy loop didn't run as much as expected.\n");
170 TC_PRINT("!! Consider making CONFIG_SYS_CLOCK_TICKS_PER_SEC smaller.\n");
171 }
172
173 /* On some platforms, where the tick period is short, like on nRF
174 * platforms where it is ~30 us, execution of the timer handlers
175 * can take significant part of the CPU time, so accept if at least
176 * one-third of possible busy loop iterations is actually performed.
177 */
178 const uint32_t acceptable_busy_loops = maximum_busy_loops / 3;
179
180 zassert_true(busy_loops > acceptable_busy_loops,
181 "Expected thread to run while 1 tick timers are firing");
182
183 zassert_true(delta_time < max_time,
184 "Expected timer train to finish in under %u milliseconds, took %u", max_time,
185 delta_time);
186 }
187
188 ZTEST_SUITE(timer_tick_train, NULL, NULL, NULL, NULL, NULL);
189
