1 /*
2  * Copyright (c) 2019 - 2020 Nordic Semiconductor ASA
3  *
4  * SPDX-License-Identifier: Apache-2.0
5  */
6 
7 /** @file
8  *  @brief Thread analyzer implementation
9  */
10 
11 #include <zephyr/kernel.h>
12 /* For z_stack_space_get() */
13 #include <kernel_internal.h>
14 #include <zephyr/debug/thread_analyzer.h>
15 #include <zephyr/debug/stack.h>
16 #include <zephyr/logging/log.h>
17 #include <stdio.h>
18 #include <zephyr/init.h>
19 
20 LOG_MODULE_REGISTER(thread_analyzer, CONFIG_THREAD_ANALYZER_LOG_LEVEL);
21 
22 #if CONFIG_THREAD_ANALYZER_AUTO_THREAD_PRIORITY_OVERRIDE
23 #define AUTO_THREAD_PRIO CONFIG_THREAD_ANALYZER_AUTO_THREAD_PRIORITY
24 #else
25 #define AUTO_THREAD_PRIO K_LOWEST_APPLICATION_THREAD_PRIO
26 #endif
27 
28 #if defined(CONFIG_THREAD_ANALYZER_USE_PRINTK)
29 #define THREAD_ANALYZER_PRINT(...) printk(__VA_ARGS__)
30 #define THREAD_ANALYZER_FMT(str)   str "\n"
31 #define THREAD_ANALYZER_VSTR(str)  (str)
32 #else
33 #define THREAD_ANALYZER_PRINT(...) LOG_INF(__VA_ARGS__)
34 #define THREAD_ANALYZER_FMT(str)   str
35 #define THREAD_ANALYZER_VSTR(str)  str
36 #endif
37 
38 /* @brief Maximum length of the pointer when converted to string
39  *
40  * Pointer is converted to string in hexadecimal form.
41  * It would use 2 hex digits for every single byte of the pointer
42  * but some implementations adds 0x prefix when used with %p format option.
43  */
44 #define PTR_STR_MAXLEN (sizeof(void *) * 2 + 2)
45 
thread_print_cb(struct thread_analyzer_info * info)46 static void thread_print_cb(struct thread_analyzer_info *info)
47 {
48 	size_t pcnt = (info->stack_used * 100U) / info->stack_size;
49 #ifdef CONFIG_THREAD_RUNTIME_STATS
50 	THREAD_ANALYZER_PRINT(
51 		THREAD_ANALYZER_FMT(
52 			" %-20s: STACK: unused %zu usage %zu / %zu (%zu %%); CPU: %u %%"),
53 		THREAD_ANALYZER_VSTR(info->name),
54 		info->stack_size - info->stack_used, info->stack_used,
55 		info->stack_size, pcnt,
56 		info->utilization);
57 
58 #ifdef CONFIG_THREAD_ANALYZER_PRIV_STACK_USAGE
59 	if (info->priv_stack_size > 0) {
60 		pcnt = (info->priv_stack_used * 100U) / info->priv_stack_size;
61 
62 		THREAD_ANALYZER_PRINT(
63 			THREAD_ANALYZER_FMT(
64 				" %-20s: PRIV_STACK: unused %zu usage %zu / %zu (%zu %%)"),
65 			" ", info->priv_stack_size - info->priv_stack_used, info->priv_stack_used,
66 			info->priv_stack_size, pcnt);
67 	}
68 #endif
69 
70 #ifdef CONFIG_SCHED_THREAD_USAGE
71 	THREAD_ANALYZER_PRINT(
72 		THREAD_ANALYZER_FMT(" %-20s: Total CPU cycles used: %llu"),
73 		" ", info->usage.total_cycles);
74 
75 #ifdef CONFIG_SCHED_THREAD_USAGE_ANALYSIS
76 	THREAD_ANALYZER_PRINT(
77 		THREAD_ANALYZER_FMT(
78 			" %-20s: Current Frame: %llu;"
79 			" Longest Frame: %llu; Average Frame: %llu"),
80 		" ", info->usage.current_cycles, info->usage.peak_cycles,
81 		info->usage.average_cycles);
82 #endif
83 #endif
84 #else
85 	THREAD_ANALYZER_PRINT(
86 		THREAD_ANALYZER_FMT(
87 			" %-20s: unused %zu usage %zu / %zu (%zu %%)"),
88 		THREAD_ANALYZER_VSTR(info->name),
89 		info->stack_size - info->stack_used, info->stack_used,
90 		info->stack_size, pcnt);
91 #endif
92 
93 #ifdef CONFIG_THREAD_ANALYZER_STACK_SAFETY
94 	switch (info->stack_safety) {
95 	case THREAD_ANALYZE_STACK_SAFETY_THRESHOLD_EXCEEDED:
96 		THREAD_ANALYZER_PRINT(
97 			THREAD_ANALYZER_FMT(
98 				" %-20s: Stack Safety Warning: Threshold crossed"),
99 			" ");
100 		break;
101 	case THREAD_ANALYZE_STACK_SAFETY_AT_LIMIT:
102 		THREAD_ANALYZER_PRINT(
103 			THREAD_ANALYZER_FMT(
104 				" %-20s: Stack Safety Alert: Stack exhausted"),
105 			" ");
106 		break;
107 	case THREAD_ANALYZE_STACK_SAFETY_OVERFLOW:
108 		THREAD_ANALYZER_PRINT(
109 			THREAD_ANALYZER_FMT(
110 				" %-20s: Stack Safety Breach: Stack overflowed"),
111 			" ");
112 		break;
113 	default:
114 		break;
115 	}
116 
117 #endif
118 }
119 
120 struct ta_cb_user_data {
121 	thread_analyzer_cb cb;
122 	unsigned int cpu;
123 };
124 
125 #ifdef CONFIG_THREAD_ANALYZER_STACK_SAFETY
thread_analyzer_stack_safety_handler_default(struct k_thread * thread,size_t unused_space,uint32_t * stack_issue)126 void thread_analyzer_stack_safety_handler_default(struct k_thread *thread,
127 						  size_t unused_space,
128 						  uint32_t *stack_issue)
129 {
130 	/*
131 	 * Since the handler was called, the configured threshold must at
132 	 * least have been crossed. Custom handlers may even be able to detect
133 	 * some stack overflow conditions, but the default handler cannot.
134 	 */
135 
136 	*stack_issue = (unused_space == 0) ?
137 			THREAD_ANALYZE_STACK_SAFETY_AT_LIMIT :
138 			THREAD_ANALYZE_STACK_SAFETY_THRESHOLD_EXCEEDED;
139 }
140 
141 static thread_analyzer_stack_safety_handler stack_safety_handler =
142 		thread_analyzer_stack_safety_handler_default;
143 
thread_analyzer_stack_safety_handler_set(thread_analyzer_stack_safety_handler handler)144 void thread_analyzer_stack_safety_handler_set(thread_analyzer_stack_safety_handler handler)
145 {
146 	stack_safety_handler = (handler != NULL) ? handler :
147 				thread_analyzer_stack_safety_handler_default;
148 }
149 #endif
150 
thread_analyze_cb(const struct k_thread * cthread,void * user_data)151 static void thread_analyze_cb(const struct k_thread *cthread, void *user_data)
152 {
153 	struct k_thread *thread = (struct k_thread *)cthread;
154 #ifdef CONFIG_THREAD_RUNTIME_STATS
155 	k_thread_runtime_stats_t rt_stats_all;
156 #endif
157 	size_t size = thread->stack_info.size;
158 	struct ta_cb_user_data *ud = user_data;
159 	thread_analyzer_cb cb = ud->cb;
160 	unsigned int cpu = ud->cpu;
161 	struct thread_analyzer_info info;
162 	char hexname[PTR_STR_MAXLEN + 1];
163 	const char *name;
164 	size_t unused;
165 	int err;
166 	int ret;
167 
168 	name = k_thread_name_get((k_tid_t)thread);
169 	if (!name || name[0] == '\0') {
170 		name = hexname;
171 		snprintk(hexname, sizeof(hexname), "%p", (void *)thread);
172 	}
173 
174 #ifdef CONFIG_THREAD_ANALYZER_STACK_SAFETY
175 	info.stack_safety = 0;
176 	err = k_thread_runtime_stack_safety_full_check(thread, &unused,
177 			(k_thread_stack_safety_handler_t) stack_safety_handler,
178 			&info.stack_safety);
179 #else
180 	err = k_thread_stack_space_get(thread, &unused);
181 #endif
182 
183 	if (err) {
184 		THREAD_ANALYZER_PRINT(
185 			THREAD_ANALYZER_FMT(
186 				" %-20s: unable to get stack space (%d)"),
187 			name, err);
188 
189 		unused = 0;
190 	}
191 
192 	info.name = name;
193 	info.stack_size = size;
194 	info.stack_used = size - unused;
195 
196 #ifdef CONFIG_THREAD_ANALYZER_PRIV_STACK_USAGE
197 	ret = arch_thread_priv_stack_space_get(cthread, &size, &unused);
198 	if (ret == 0) {
199 		info.priv_stack_size = size;
200 		info.priv_stack_used = size - unused;
201 	} else {
202 		info.priv_stack_size = 0;
203 	}
204 #endif
205 
206 #ifdef CONFIG_THREAD_RUNTIME_STATS
207 	ret = 0;
208 
209 	if (k_thread_runtime_stats_get(thread, &info.usage) != 0) {
210 		ret++;
211 	}
212 
213 	if (IS_ENABLED(CONFIG_THREAD_ANALYZER_AUTO_SEPARATE_CORES)) {
214 		if (k_thread_runtime_stats_cpu_get(cpu, &rt_stats_all) != 0) {
215 			ret++;
216 		}
217 	} else {
218 		if (k_thread_runtime_stats_all_get(&rt_stats_all) != 0) {
219 			ret++;
220 		}
221 	}
222 
223 	if (ret == 0) {
224 		info.utilization = (info.usage.execution_cycles * 100U) /
225 			rt_stats_all.execution_cycles;
226 	}
227 #endif
228 
229 	ARG_UNUSED(ret);
230 
231 	cb(&info);
232 
233 #ifdef CONFIG_THREAD_ANALYZER_LONG_FRAME_PER_INTERVAL
234 	k_thread_runtime_stats_longest_frame_reset(thread);
235 #endif
236 
237 }
238 
239 K_KERNEL_STACK_ARRAY_DECLARE(z_interrupt_stacks, CONFIG_MP_MAX_NUM_CPUS,
240 			     CONFIG_ISR_STACK_SIZE);
241 
isr_stack(int core)242 static void isr_stack(int core)
243 {
244 	const uint8_t *buf = K_KERNEL_STACK_BUFFER(z_interrupt_stacks[core]);
245 	size_t size = K_KERNEL_STACK_SIZEOF(z_interrupt_stacks[core]);
246 	size_t unused;
247 	int err;
248 
249 	err = z_stack_space_get(buf, size, &unused);
250 	if (err == 0) {
251 		THREAD_ANALYZER_PRINT(
252 			THREAD_ANALYZER_FMT(
253 				" %s%-17d: STACK: unused %zu usage %zu / %zu (%zu %%)"),
254 			THREAD_ANALYZER_VSTR("ISR"), core, unused,
255 			size - unused, size, (100 * (size - unused)) / size);
256 	}
257 }
258 
isr_stacks(void)259 static void isr_stacks(void)
260 {
261 	unsigned int num_cpus = arch_num_cpus();
262 
263 	for (int i = 0; i < num_cpus; i++) {
264 		isr_stack(i);
265 	}
266 }
267 
thread_analyzer_run(thread_analyzer_cb cb,unsigned int cpu)268 void thread_analyzer_run(thread_analyzer_cb cb, unsigned int cpu)
269 {
270 	struct ta_cb_user_data ud = { .cb = cb, .cpu = cpu };
271 
272 	if (IS_ENABLED(CONFIG_THREAD_ANALYZER_RUN_UNLOCKED)) {
273 		if (IS_ENABLED(CONFIG_THREAD_ANALYZER_AUTO_SEPARATE_CORES)) {
274 			k_thread_foreach_unlocked_filter_by_cpu(cpu, thread_analyze_cb, &ud);
275 		} else {
276 			k_thread_foreach_unlocked(thread_analyze_cb, &ud);
277 		}
278 	} else {
279 		if (IS_ENABLED(CONFIG_THREAD_ANALYZER_AUTO_SEPARATE_CORES)) {
280 			k_thread_foreach_filter_by_cpu(cpu, thread_analyze_cb, &ud);
281 		} else {
282 			k_thread_foreach(thread_analyze_cb, &ud);
283 		}
284 	}
285 
286 	if (IS_ENABLED(CONFIG_THREAD_ANALYZER_ISR_STACK_USAGE)) {
287 		if (IS_ENABLED(CONFIG_THREAD_ANALYZER_AUTO_SEPARATE_CORES)) {
288 			isr_stack(cpu);
289 		} else {
290 			isr_stacks();
291 		}
292 	}
293 }
294 
thread_analyzer_print(unsigned int cpu)295 void thread_analyzer_print(unsigned int cpu)
296 {
297 #if IS_ENABLED(CONFIG_THREAD_ANALYZER_AUTO_SEPARATE_CORES)
298 	THREAD_ANALYZER_PRINT(THREAD_ANALYZER_FMT("Thread analyze core %u:"),
299 						  cpu);
300 #else
301 	THREAD_ANALYZER_PRINT(THREAD_ANALYZER_FMT("Thread analyze:"));
302 #endif
303 	thread_analyzer_run(thread_print_cb, cpu);
304 }
305 
306 #if defined(CONFIG_THREAD_ANALYZER_AUTO)
307 
thread_analyzer_auto(void * a,void * b,void * c)308 void thread_analyzer_auto(void *a, void *b, void *c)
309 {
310 	unsigned int cpu = IS_ENABLED(CONFIG_THREAD_ANALYZER_AUTO_SEPARATE_CORES) ?
311 		(unsigned int)(uintptr_t) a : 0;
312 
313 	for (;;) {
314 		thread_analyzer_print(cpu);
315 		k_sleep(K_SECONDS(CONFIG_THREAD_ANALYZER_AUTO_INTERVAL));
316 	}
317 }
318 
319 #ifdef CONFIG_THREAD_ANALYZER_AUTO_SEPARATE_CORES
320 
321 static K_THREAD_STACK_ARRAY_DEFINE(analyzer_thread_stacks, CONFIG_MP_MAX_NUM_CPUS,
322 				   CONFIG_THREAD_ANALYZER_AUTO_STACK_SIZE);
323 static struct k_thread analyzer_thread[CONFIG_MP_MAX_NUM_CPUS];
324 
thread_analyzer_init(void)325 static int thread_analyzer_init(void)
326 {
327 	uint16_t i;
328 
329 	for (i = 0; i < ARRAY_SIZE(analyzer_thread); i++) {
330 		char name[24];
331 		k_tid_t tid = NULL;
332 		int ret;
333 
334 		tid = k_thread_create(&analyzer_thread[i], analyzer_thread_stacks[i],
335 				      CONFIG_THREAD_ANALYZER_AUTO_STACK_SIZE,
336 				      thread_analyzer_auto,
337 				      (void *) (uintptr_t) i, NULL, NULL,
338 				      AUTO_THREAD_PRIO, 0, K_FOREVER);
339 		if (!tid) {
340 			LOG_ERR("k_thread_create() failed for core %u", i);
341 			continue;
342 		}
343 		ret = k_thread_cpu_pin(tid, i);
344 		if (ret < 0) {
345 			LOG_ERR("Pinning thread to code core %u", i);
346 			k_thread_abort(tid);
347 			continue;
348 		}
349 		snprintf(name, sizeof(name), "core %u thread analyzer", i);
350 		ret = k_thread_name_set(tid, name);
351 		if (ret < 0) {
352 			LOG_INF("k_thread_name_set failed: %d for %u", ret, i);
353 		}
354 
355 		k_thread_start(tid);
356 		LOG_DBG("Thread %p for core %u started", tid, i);
357 	}
358 
359 	return 0;
360 }
361 
362 SYS_INIT(thread_analyzer_init, APPLICATION, CONFIG_KERNEL_INIT_PRIORITY_DEFAULT);
363 
364 #else
365 
366 K_THREAD_DEFINE(thread_analyzer,
367 		CONFIG_THREAD_ANALYZER_AUTO_STACK_SIZE,
368 		thread_analyzer_auto,
369 		NULL, NULL, NULL,
370 		AUTO_THREAD_PRIO,
371 		0, 0);
372 
373 #endif /* CONFIG_THREAD_ANALYZER_AUTO_SEPARATE_CORES */
374 
375 #endif /* CONFIG_THREAD_ANALYZER_AUTO */
376