1 /*
2 * Copyright (c) 2022 Nordic Semiconductor
3 *
4 * SPDX-License-Identifier: Apache-2.0
5 */
6
7 #include <zephyr/ztest.h>
8 #include <zephyr/logging/log.h>
9
10 /* The idea of this test is to estimate stack usage of logging messages. Each
11 * test checks stack usage before and after logging a message. Increase of stack
12 * usage is interpreted as stack used by the logging. Test has been used to
13 * characterize some common architectures and it will fail if significantly more
14 * stack is used.
15 *
16 * This will help to detect when changes in logging, toolchain or modules used
17 * by logging increase stack usage. Failure of the test should lead to investigation
18 * to determine if stack usage change is justified. If it is justified, thresholds
19 * may be updated.
20 */
21
22 LOG_MODULE_REGISTER(test);
23
24 static size_t simple_usage;
25 static size_t hexdump_usage;
26 static size_t more_args_usage;
27
28 /* Stack increase margin. */
29 #ifdef CONFIG_PICOLIBC
30 #define STACK_USAGE_MARGIN 128
31 #else
32 #define STACK_USAGE_MARGIN 16
33 #endif
34
after(void * data)35 static void after(void *data)
36 {
37 PRINT("#elif %sdefined(CONFIG_LOG_MODE_IMMEDIATE) && %sdefined(CONFIG_NO_OPTIMIZATIONS)\n",
38 IS_ENABLED(CONFIG_LOG_MODE_IMMEDIATE) ? "" : "!",
39 IS_ENABLED(CONFIG_NO_OPTIMIZATIONS) ? "" : "!");
40 PRINT("#define SIMPLE_USAGE %zu\n", simple_usage);
41 PRINT("#define HEXDUMP_USAGE %zu\n", hexdump_usage);
42 PRINT("#define MORE_ARGS_USAGE %zu\n", more_args_usage);
43 }
44
45 ZTEST_SUITE(test_log_stack, NULL, NULL, NULL, NULL, after);
46
47 #define TEST_LOG_STACK(usage, log_msg) do { \
48 size_t unused, unused2; \
49 int err; \
50 \
51 k_msleep(100); \
52 err = k_thread_stack_space_get(k_current_get(), &unused); \
53 zassert_equal(err, 0); \
54 __DEBRACKET log_msg; \
55 \
56 k_msleep(100); \
57 \
58 err = k_thread_stack_space_get(k_current_get(), &unused2); \
59 zassert_equal(err, 0); \
60 \
61 usage = unused - unused2; \
62 PRINT("Stack increase due to log usage: %zu\n", usage); \
63 } while (0)
64
65 #if defined(CONFIG_CPU_CORTEX_M0)
66
67 #if !defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
68 #define SIMPLE_USAGE 120
69 #define HEXDUMP_USAGE 120
70 #define MORE_ARGS_USAGE 136
71 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
72 #define SIMPLE_USAGE 436
73 #define HEXDUMP_USAGE 436
74 #define MORE_ARGS_USAGE 452
75 #elif !defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
76 #define SIMPLE_USAGE 168
77 #define HEXDUMP_USAGE 168
78 #define MORE_ARGS_USAGE 171
79 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
80 #define SIMPLE_USAGE 911
81 #define HEXDUMP_USAGE 911
82 #define MORE_ARGS_USAGE 927
83 #endif
84
85 #elif defined(CONFIG_CPU_CORTEX_M3)
86
87 #if !defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
88 #define SIMPLE_USAGE 160
89 #define HEXDUMP_USAGE 160
90 #define MORE_ARGS_USAGE 176
91 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
92 #define SIMPLE_USAGE 388
93 #define HEXDUMP_USAGE 388
94 #define MORE_ARGS_USAGE 404
95 #elif !defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
96 #define SIMPLE_USAGE 144
97 #define HEXDUMP_USAGE 88
98 #define MORE_ARGS_USAGE 144
99 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
100 #define SIMPLE_USAGE 640
101 #define HEXDUMP_USAGE 640
102 #define MORE_ARGS_USAGE 656
103 #endif
104
105 #elif defined(CONFIG_X86) && !defined(CONFIG_X86_64)
106
107 #if !defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
108 #define SIMPLE_USAGE 72
109 #define HEXDUMP_USAGE 68
110 #define MORE_ARGS_USAGE 88
111 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
112 #define SIMPLE_USAGE 448
113 #define HEXDUMP_USAGE 444
114 #define MORE_ARGS_USAGE 484
115 #elif !defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
116 #define SIMPLE_USAGE 288
117 #define HEXDUMP_USAGE 272
118 #define MORE_ARGS_USAGE 304
119 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
120 #define SIMPLE_USAGE 988
121 #define HEXDUMP_USAGE 972
122 #define MORE_ARGS_USAGE 1020
123 #endif
124
125 #elif defined(CONFIG_X86_64)
126
127 #if !defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
128 #define SIMPLE_USAGE 168
129 #define HEXDUMP_USAGE 136
130 #define MORE_ARGS_USAGE 200
131 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
132 #define SIMPLE_USAGE 1120
133 #define HEXDUMP_USAGE 1104
134 #define MORE_ARGS_USAGE 1184
135 #elif !defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
136 #define SIMPLE_USAGE 576
137 #define HEXDUMP_USAGE 576
138 #define MORE_ARGS_USAGE 608
139 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
140 #define SIMPLE_USAGE 1680
141 #define HEXDUMP_USAGE 1680
142 #define MORE_ARGS_USAGE 1744
143 #endif
144
145 #elif defined(CONFIG_RISCV) && !defined(CONFIG_64BIT) && !defined(CONFIG_SMP)
146
147 #if !defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
148 #define SIMPLE_USAGE 136
149 #define HEXDUMP_USAGE 136
150 #define MORE_ARGS_USAGE 152
151 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
152 #define SIMPLE_USAGE 504
153 #define HEXDUMP_USAGE 504
154 #define MORE_ARGS_USAGE 520
155 #elif !defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
156 #define SIMPLE_USAGE 240
157 #define HEXDUMP_USAGE 240
158 #define MORE_ARGS_USAGE 240
159 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
160 #define SIMPLE_USAGE 992
161 #define HEXDUMP_USAGE 992
162 #define MORE_ARGS_USAGE 1008
163 #endif
164
165 #elif defined(CONFIG_RISCV) && !defined(CONFIG_64BIT) && defined(CONFIG_SMP)
166
167 #if !defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
168 #define SIMPLE_USAGE 96
169 #define HEXDUMP_USAGE 96
170 #define MORE_ARGS_USAGE 112
171 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
172 #define SIMPLE_USAGE 456
173 #define HEXDUMP_USAGE 456
174 #define MORE_ARGS_USAGE 472
175 #elif !defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
176 #define SIMPLE_USAGE 304
177 #define HEXDUMP_USAGE 240
178 #define MORE_ARGS_USAGE 240
179 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
180 #define SIMPLE_USAGE 1008
181 #define HEXDUMP_USAGE 1008
182 #define MORE_ARGS_USAGE 1024
183 #endif
184
185 #elif defined(CONFIG_RISCV) && defined(CONFIG_64BIT) && defined(CONFIG_SMP)
186
187 #if !defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
188 #define SIMPLE_USAGE 200
189 #define HEXDUMP_USAGE 168
190 #define MORE_ARGS_USAGE 232
191 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
192 #define SIMPLE_USAGE 736
193 #define HEXDUMP_USAGE 768
194 #define MORE_ARGS_USAGE 768
195 #elif !defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
196 #define SIMPLE_USAGE 320
197 #define HEXDUMP_USAGE 320
198 #define MORE_ARGS_USAGE 320
199 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
200 #define SIMPLE_USAGE 1248
201 #define HEXDUMP_USAGE 1248
202 #define MORE_ARGS_USAGE 1280
203 #endif
204
205 #elif defined(CONFIG_RISCV) && defined(CONFIG_64BIT)
206
207 #if !defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
208 #define SIMPLE_USAGE 240
209 #define HEXDUMP_USAGE 240
210 #define MORE_ARGS_USAGE 272
211 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
212 #define SIMPLE_USAGE 704
213 #define HEXDUMP_USAGE 704
214 #define MORE_ARGS_USAGE 736
215 #elif !defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
216 #define SIMPLE_USAGE 320
217 #define HEXDUMP_USAGE 320
218 #define MORE_ARGS_USAGE 320
219 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
220 #define SIMPLE_USAGE 1128
221 #define HEXDUMP_USAGE 1128
222 #define MORE_ARGS_USAGE 1160
223 #endif
224
225 #elif defined(CONFIG_SPARC)
226
227 #if !defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
228 #define SIMPLE_USAGE 0
229 #define HEXDUMP_USAGE 28
230 #define MORE_ARGS_USAGE 0
231 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
232 #define SIMPLE_USAGE 849
233 #define HEXDUMP_USAGE 849
234 #define MORE_ARGS_USAGE 865
235 #elif !defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
236 #define SIMPLE_USAGE 416
237 #define HEXDUMP_USAGE 232
238 #define MORE_ARGS_USAGE 416
239 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
240 #define SIMPLE_USAGE 1544
241 #define HEXDUMP_USAGE 1544
242 #define MORE_ARGS_USAGE 1560
243 #endif
244
245 #elif defined(CONFIG_XTENSA)
246
247 #if !defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
248 #define SIMPLE_USAGE 72
249 #define HEXDUMP_USAGE 168
250 #define MORE_ARGS_USAGE 88
251 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && !defined(CONFIG_NO_OPTIMIZATIONS)
252 #define SIMPLE_USAGE 584
253 #define HEXDUMP_USAGE 584
254 #define MORE_ARGS_USAGE 600
255 #elif !defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
256 #define SIMPLE_USAGE 336
257 #define HEXDUMP_USAGE 336
258 #define MORE_ARGS_USAGE 336
259 #elif defined(CONFIG_LOG_MODE_IMMEDIATE) && defined(CONFIG_NO_OPTIMIZATIONS)
260 #define SIMPLE_USAGE 1040
261 #define HEXDUMP_USAGE 1040
262 #define MORE_ARGS_USAGE 1056
263 #endif
264
265 #else
266 /* For other platforms which were not characterized use something big. */
267 #define SIMPLE_USAGE 2000
268 #define HEXDUMP_USAGE 2000
269 #define MORE_ARGS_USAGE 2000
270 #endif
271
272 #define SIMPLE_USAGE_LIMIT (SIMPLE_USAGE + STACK_USAGE_MARGIN)
273 #define HEXDUMP_USAGE_LIMIT (HEXDUMP_USAGE + STACK_USAGE_MARGIN)
274 #define MORE_ARGS_USAGE_LIMIT (MORE_ARGS_USAGE + STACK_USAGE_MARGIN)
275
ZTEST(test_log_stack,test_log_simple)276 ZTEST(test_log_stack, test_log_simple)
277 {
278 uint32_t test_u = 1;
279 int test_i = 1;
280
281 TEST_LOG_STACK(simple_usage, (LOG_INF("test %u %d", test_u, test_i)));
282
283 zassert_true(simple_usage <= SIMPLE_USAGE_LIMIT, "Usage:%zu, expected:%zu",
284 simple_usage, SIMPLE_USAGE_LIMIT);
285 }
286
ZTEST(test_log_stack,test_log_hexdump)287 ZTEST(test_log_stack, test_log_hexdump)
288 {
289 uint8_t data[] = {1, 2, 3, 4};
290
291 TEST_LOG_STACK(hexdump_usage, (LOG_HEXDUMP_INF(data, sizeof(data), "description")));
292
293 zassert_true(hexdump_usage <= HEXDUMP_USAGE_LIMIT, "Usage:%zu, expected:%zu",
294 hexdump_usage, HEXDUMP_USAGE_LIMIT);
295 }
296
ZTEST(test_log_stack,test_log_more_args)297 ZTEST(test_log_stack, test_log_more_args)
298 {
299 TEST_LOG_STACK(more_args_usage, (LOG_INF("test %d %d %d %d %d %d",
300 k_uptime_get_32(), k_uptime_get_32(),
301 k_uptime_get_32(), k_uptime_get_32(),
302 k_uptime_get_32(), k_uptime_get_32())));
303
304 zassert_true(more_args_usage <= MORE_ARGS_USAGE_LIMIT, "Usage:%zu, expected:%zu",
305 more_args_usage, MORE_ARGS_USAGE_LIMIT);
306 }
307
