proftool.c 13 KB

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