proftool.c 13 KB

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