xref: /openbmc/u-boot/tools/proftool.c (revision fd0bc623)
1 // SPDX-License-Identifier: GPL-2.0+
2 /*
3  * Copyright (c) 2013 Google, Inc
4  */
5 
6 /* Decode and dump U-Boot profiling information */
7 
8 #include <assert.h>
9 #include <ctype.h>
10 #include <limits.h>
11 #include <regex.h>
12 #include <stdarg.h>
13 #include <stdio.h>
14 #include <stdlib.h>
15 #include <string.h>
16 #include <unistd.h>
17 #include <sys/param.h>
18 #include <sys/types.h>
19 
20 #include <compiler.h>
21 #include <trace.h>
22 
23 #define MAX_LINE_LEN 500
24 
25 enum {
26 	FUNCF_TRACE	= 1 << 0,	/* Include this function in trace */
27 };
28 
29 struct func_info {
30 	unsigned long offset;
31 	const char *name;
32 	unsigned long code_size;
33 	unsigned long call_count;
34 	unsigned flags;
35 	/* the section this function is in */
36 	struct objsection_info *objsection;
37 };
38 
39 enum trace_line_type {
40 	TRACE_LINE_INCLUDE,
41 	TRACE_LINE_EXCLUDE,
42 };
43 
44 struct trace_configline_info {
45 	struct trace_configline_info *next;
46 	enum trace_line_type type;
47 	const char *name;	/* identifier name / wildcard */
48 	regex_t regex;		/* Regex to use if name starts with / */
49 };
50 
51 /* The contents of the trace config file */
52 struct trace_configline_info *trace_config_head;
53 
54 struct func_info *func_list;
55 int func_count;
56 struct trace_call *call_list;
57 int call_count;
58 int verbose;	/* Verbosity level 0=none, 1=warn, 2=notice, 3=info, 4=debug */
59 unsigned long text_offset;		/* text address of first function */
60 
61 static void outf(int level, const char *fmt, ...)
62 		__attribute__ ((format (__printf__, 2, 3)));
63 #define error(fmt, b...) outf(0, fmt, ##b)
64 #define warn(fmt, b...) outf(1, fmt, ##b)
65 #define notice(fmt, b...) outf(2, fmt, ##b)
66 #define info(fmt, b...) outf(3, fmt, ##b)
67 #define debug(fmt, b...) outf(4, fmt, ##b)
68 
69 
70 static void outf(int level, const char *fmt, ...)
71 {
72 	if (verbose >= level) {
73 		va_list args;
74 
75 		va_start(args, fmt);
76 		vfprintf(stderr, fmt, args);
77 		va_end(args);
78 	}
79 }
80 
81 static void usage(void)
82 {
83 	fprintf(stderr,
84 		"Usage: proftool -cds -v3 <cmd> <profdata>\n"
85 		"\n"
86 		"Commands\n"
87 		"   dump-ftrace\t\tDump out textual data in ftrace format\n"
88 		"\n"
89 		"Options:\n"
90 		"   -m <map>\tSpecify Systen.map file\n"
91 		"   -t <trace>\tSpecific trace data file (from U-Boot)\n"
92 		"   -v <0-4>\tSpecify verbosity\n");
93 	exit(EXIT_FAILURE);
94 }
95 
96 static int h_cmp_offset(const void *v1, const void *v2)
97 {
98 	const struct func_info *f1 = v1, *f2 = v2;
99 
100 	return (f1->offset / FUNC_SITE_SIZE) - (f2->offset / FUNC_SITE_SIZE);
101 }
102 
103 static int read_system_map(FILE *fin)
104 {
105 	unsigned long offset, start = 0;
106 	struct func_info *func;
107 	char buff[MAX_LINE_LEN];
108 	char symtype;
109 	char symname[MAX_LINE_LEN + 1];
110 	int linenum;
111 	int alloced;
112 
113 	for (linenum = 1, alloced = func_count = 0;; linenum++) {
114 		int fields = 0;
115 
116 		if (fgets(buff, sizeof(buff), fin))
117 			fields = sscanf(buff, "%lx %c %100s\n", &offset,
118 				&symtype, symname);
119 		if (fields == 2) {
120 			continue;
121 		} else if (feof(fin)) {
122 			break;
123 		} else if (fields < 2) {
124 			error("Map file line %d: invalid format\n", linenum);
125 			return 1;
126 		}
127 
128 		/* Must be a text symbol */
129 		symtype = tolower(symtype);
130 		if (symtype != 't' && symtype != 'w')
131 			continue;
132 
133 		if (func_count == alloced) {
134 			alloced += 256;
135 			func_list = realloc(func_list,
136 					sizeof(struct func_info) * alloced);
137 			assert(func_list);
138 		}
139 		if (!func_count)
140 			start = offset;
141 
142 		func = &func_list[func_count++];
143 		memset(func, '\0', sizeof(*func));
144 		func->offset = offset - start;
145 		func->name = strdup(symname);
146 		func->flags = FUNCF_TRACE;	/* trace by default */
147 
148 		/* Update previous function's code size */
149 		if (func_count > 1)
150 			func[-1].code_size = func->offset - func[-1].offset;
151 	}
152 	notice("%d functions found in map file\n", func_count);
153 	text_offset = start;
154 	return 0;
155 }
156 
157 static int read_data(FILE *fin, void *buff, int size)
158 {
159 	int err;
160 
161 	err = fread(buff, 1, size, fin);
162 	if (!err)
163 		return 1;
164 	if (err != size) {
165 		error("Cannot read profile file at pos %ld\n", ftell(fin));
166 		return -1;
167 	}
168 	return 0;
169 }
170 
171 static struct func_info *find_func_by_offset(uint32_t offset)
172 {
173 	struct func_info key, *found;
174 
175 	key.offset = offset;
176 	found = bsearch(&key, func_list, func_count, sizeof(struct func_info),
177 			h_cmp_offset);
178 
179 	return found;
180 }
181 
182 /* This finds the function which contains the given offset */
183 static struct func_info *find_caller_by_offset(uint32_t offset)
184 {
185 	int low;	/* least function that could be a match */
186 	int high;	/* greated function that could be a match */
187 	struct func_info key;
188 
189 	low = 0;
190 	high = func_count - 1;
191 	key.offset = offset;
192 	while (high > low + 1) {
193 		int mid = (low + high) / 2;
194 		int result;
195 
196 		result = h_cmp_offset(&key, &func_list[mid]);
197 		if (result > 0)
198 			low = mid;
199 		else if (result < 0)
200 			high = mid;
201 		else
202 			return &func_list[mid];
203 	}
204 
205 	return low >= 0 ? &func_list[low] : NULL;
206 }
207 
208 static int read_calls(FILE *fin, int count)
209 {
210 	struct trace_call *call_data;
211 	int i;
212 
213 	notice("call count: %d\n", count);
214 	call_list = (struct trace_call *)calloc(count, sizeof(*call_data));
215 	if (!call_list) {
216 		error("Cannot allocate call_list\n");
217 		return -1;
218 	}
219 	call_count = count;
220 
221 	call_data = call_list;
222 	for (i = 0; i < count; i++, call_data++) {
223 		if (read_data(fin, call_data, sizeof(*call_data)))
224 			return 1;
225 	}
226 	return 0;
227 }
228 
229 static int read_profile(FILE *fin, int *not_found)
230 {
231 	struct trace_output_hdr hdr;
232 
233 	*not_found = 0;
234 	while (!feof(fin)) {
235 		int err;
236 
237 		err = read_data(fin, &hdr, sizeof(hdr));
238 		if (err == 1)
239 			break; /* EOF */
240 		else if (err)
241 			return 1;
242 
243 		switch (hdr.type) {
244 		case TRACE_CHUNK_FUNCS:
245 			/* Ignored at present */
246 			break;
247 
248 		case TRACE_CHUNK_CALLS:
249 			if (read_calls(fin, hdr.rec_count))
250 				return 1;
251 			break;
252 		}
253 	}
254 	return 0;
255 }
256 
257 static int read_map_file(const char *fname)
258 {
259 	FILE *fmap;
260 	int err = 0;
261 
262 	fmap = fopen(fname, "r");
263 	if (!fmap) {
264 		error("Cannot open map file '%s'\n", fname);
265 		return 1;
266 	}
267 	if (fmap) {
268 		err = read_system_map(fmap);
269 		fclose(fmap);
270 	}
271 	return err;
272 }
273 
274 static int read_profile_file(const char *fname)
275 {
276 	int not_found = INT_MAX;
277 	FILE *fprof;
278 	int err;
279 
280 	fprof = fopen(fname, "rb");
281 	if (!fprof) {
282 		error("Cannot open profile data file '%s'\n",
283 		      fname);
284 		return 1;
285 	} else {
286 		err = read_profile(fprof, &not_found);
287 		fclose(fprof);
288 		if (err)
289 			return err;
290 
291 		if (not_found) {
292 			warn("%d profile functions could not be found in the map file - are you sure that your profile data and map file correspond?\n",
293 			     not_found);
294 			return 1;
295 		}
296 	}
297 	return 0;
298 }
299 
300 static int regex_report_error(regex_t *regex, int err, const char *op,
301 			      const char *name)
302 {
303 	char buf[200];
304 
305 	regerror(err, regex, buf, sizeof(buf));
306 	error("Regex error '%s' in %s '%s'\n", buf, op, name);
307 	return -1;
308 }
309 
310 static void check_trace_config_line(struct trace_configline_info *item)
311 {
312 	struct func_info *func, *end;
313 	int err;
314 
315 	debug("Checking trace config line '%s'\n", item->name);
316 	for (func = func_list, end = func + func_count; func < end; func++) {
317 		err = regexec(&item->regex, func->name, 0, NULL, 0);
318 		debug("   - regex '%s', string '%s': %d\n", item->name,
319 		      func->name, err);
320 		if (err == REG_NOMATCH)
321 			continue;
322 
323 		if (err) {
324 			regex_report_error(&item->regex, err, "match",
325 					   item->name);
326 			break;
327 		}
328 
329 		/* It matches, so perform the action */
330 		switch (item->type) {
331 		case TRACE_LINE_INCLUDE:
332 			info("      include %s at %lx\n", func->name,
333 			     text_offset + func->offset);
334 			func->flags |= FUNCF_TRACE;
335 			break;
336 
337 		case TRACE_LINE_EXCLUDE:
338 			info("      exclude %s at %lx\n", func->name,
339 			     text_offset + func->offset);
340 			func->flags &= ~FUNCF_TRACE;
341 			break;
342 		}
343 	}
344 }
345 
346 static void check_trace_config(void)
347 {
348 	struct trace_configline_info *line;
349 
350 	for (line = trace_config_head; line; line = line->next)
351 		check_trace_config_line(line);
352 }
353 
354 /**
355  * Check the functions to see if they each have an objsection. If not, then
356  * the linker must have eliminated them.
357  */
358 static void check_functions(void)
359 {
360 	struct func_info *func, *end;
361 	unsigned long removed_code_size = 0;
362 	int not_found = 0;
363 
364 	/* Look for missing functions */
365 	for (func = func_list, end = func + func_count; func < end; func++) {
366 		if (!func->objsection) {
367 			removed_code_size += func->code_size;
368 			not_found++;
369 		}
370 	}
371 
372 	/* Figure out what functions we want to trace */
373 	check_trace_config();
374 
375 	warn("%d functions removed by linker, %ld code size\n",
376 	     not_found, removed_code_size);
377 }
378 
379 static int read_trace_config(FILE *fin)
380 {
381 	char buff[200];
382 	int linenum = 0;
383 	struct trace_configline_info **tailp = &trace_config_head;
384 
385 	while (fgets(buff, sizeof(buff), fin)) {
386 		int len = strlen(buff);
387 		struct trace_configline_info *line;
388 		char *saveptr;
389 		char *s, *tok;
390 		int err;
391 
392 		linenum++;
393 		if (len && buff[len - 1] == '\n')
394 			buff[len - 1] = '\0';
395 
396 		/* skip blank lines and comments */
397 		for (s = buff; *s == ' ' || *s == '\t'; s++)
398 			;
399 		if (!*s || *s == '#')
400 			continue;
401 
402 		line = (struct trace_configline_info *)calloc(1,
403 							      sizeof(*line));
404 		if (!line) {
405 			error("Cannot allocate config line\n");
406 			return -1;
407 		}
408 
409 		tok = strtok_r(s, " \t", &saveptr);
410 		if (!tok) {
411 			error("Invalid trace config data on line %d\n",
412 			      linenum);
413 			return -1;
414 		}
415 		if (0 == strcmp(tok, "include-func")) {
416 			line->type = TRACE_LINE_INCLUDE;
417 		} else if (0 == strcmp(tok, "exclude-func")) {
418 			line->type = TRACE_LINE_EXCLUDE;
419 		} else {
420 			error("Unknown command in trace config data line %d\n",
421 			      linenum);
422 			return -1;
423 		}
424 
425 		tok = strtok_r(NULL, " \t", &saveptr);
426 		if (!tok) {
427 			error("Missing pattern in trace config data line %d\n",
428 			      linenum);
429 			return -1;
430 		}
431 
432 		err = regcomp(&line->regex, tok, REG_NOSUB);
433 		if (err) {
434 			int r = regex_report_error(&line->regex, err,
435 						   "compile", tok);
436 			free(line);
437 			return r;
438 		}
439 
440 		/* link this new one to the end of the list */
441 		line->name = strdup(tok);
442 		line->next = NULL;
443 		*tailp = line;
444 		tailp = &line->next;
445 	}
446 
447 	if (!feof(fin)) {
448 		error("Cannot read from trace config file at position %ld\n",
449 		      ftell(fin));
450 		return -1;
451 	}
452 	return 0;
453 }
454 
455 static int read_trace_config_file(const char *fname)
456 {
457 	FILE *fin;
458 	int err;
459 
460 	fin = fopen(fname, "r");
461 	if (!fin) {
462 		error("Cannot open trace_config file '%s'\n", fname);
463 		return -1;
464 	}
465 	err = read_trace_config(fin);
466 	fclose(fin);
467 	return err;
468 }
469 
470 static void out_func(ulong func_offset, int is_caller, const char *suffix)
471 {
472 	struct func_info *func;
473 
474 	func = (is_caller ? find_caller_by_offset : find_func_by_offset)
475 		(func_offset);
476 
477 	if (func)
478 		printf("%s%s", func->name, suffix);
479 	else
480 		printf("%lx%s", func_offset, suffix);
481 }
482 
483 /*
484  * # tracer: function
485  * #
486  * #           TASK-PID   CPU#    TIMESTAMP  FUNCTION
487  * #              | |      |          |         |
488  * #           bash-4251  [01] 10152.583854: path_put <-path_walk
489  * #           bash-4251  [01] 10152.583855: dput <-path_put
490  * #           bash-4251  [01] 10152.583855: _atomic_dec_and_lock <-dput
491  */
492 static int make_ftrace(void)
493 {
494 	struct trace_call *call;
495 	int missing_count = 0, skip_count = 0;
496 	int i;
497 
498 	printf("# tracer: ftrace\n"
499 		"#\n"
500 		"#           TASK-PID   CPU#    TIMESTAMP  FUNCTION\n"
501 		"#              | |      |          |         |\n");
502 	for (i = 0, call = call_list; i < call_count; i++, call++) {
503 		struct func_info *func = find_func_by_offset(call->func);
504 		ulong time = call->flags & FUNCF_TIMESTAMP_MASK;
505 
506 		if (TRACE_CALL_TYPE(call) != FUNCF_ENTRY &&
507 		    TRACE_CALL_TYPE(call) != FUNCF_EXIT)
508 			continue;
509 		if (!func) {
510 			warn("Cannot find function at %lx\n",
511 			     text_offset + call->func);
512 			missing_count++;
513 			continue;
514 		}
515 
516 		if (!(func->flags & FUNCF_TRACE)) {
517 			debug("Funcion '%s' is excluded from trace\n",
518 			      func->name);
519 			skip_count++;
520 			continue;
521 		}
522 
523 		printf("%16s-%-5d [01] %lu.%06lu: ", "uboot", 1,
524 		       time / 1000000, time % 1000000);
525 
526 		out_func(call->func, 0, " <- ");
527 		out_func(call->caller, 1, "\n");
528 	}
529 	info("ftrace: %d functions not found, %d excluded\n", missing_count,
530 	     skip_count);
531 
532 	return 0;
533 }
534 
535 static int prof_tool(int argc, char * const argv[],
536 		     const char *prof_fname, const char *map_fname,
537 		     const char *trace_config_fname)
538 {
539 	int err = 0;
540 
541 	if (read_map_file(map_fname))
542 		return -1;
543 	if (prof_fname && read_profile_file(prof_fname))
544 		return -1;
545 	if (trace_config_fname && read_trace_config_file(trace_config_fname))
546 		return -1;
547 
548 	check_functions();
549 
550 	for (; argc; argc--, argv++) {
551 		const char *cmd = *argv;
552 
553 		if (0 == strcmp(cmd, "dump-ftrace"))
554 			err = make_ftrace();
555 		else
556 			warn("Unknown command '%s'\n", cmd);
557 	}
558 
559 	return err;
560 }
561 
562 int main(int argc, char *argv[])
563 {
564 	const char *map_fname = "System.map";
565 	const char *prof_fname = NULL;
566 	const char *trace_config_fname = NULL;
567 	int opt;
568 
569 	verbose = 2;
570 	while ((opt = getopt(argc, argv, "m:p:t:v:")) != -1) {
571 		switch (opt) {
572 		case 'm':
573 			map_fname = optarg;
574 			break;
575 
576 		case 'p':
577 			prof_fname = optarg;
578 			break;
579 
580 		case 't':
581 			trace_config_fname = optarg;
582 			break;
583 
584 		case 'v':
585 			verbose = atoi(optarg);
586 			break;
587 
588 		default:
589 			usage();
590 		}
591 	}
592 	argc -= optind; argv += optind;
593 	if (argc < 1)
594 		usage();
595 
596 	debug("Debug enabled\n");
597 	return prof_tool(argc, argv, prof_fname, map_fname,
598 			 trace_config_fname);
599 }
600