proftool.c 49 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996997998999100010011002100310041005100610071008100910101011101210131014101510161017101810191020102110221023102410251026102710281029103010311032103310341035103610371038103910401041104210431044104510461047104810491050105110521053105410551056105710581059106010611062106310641065106610671068106910701071107210731074107510761077107810791080108110821083108410851086108710881089109010911092109310941095109610971098109911001101110211031104110511061107110811091110111111121113111411151116111711181119112011211122112311241125112611271128112911301131113211331134113511361137113811391140114111421143114411451146114711481149115011511152115311541155115611571158115911601161116211631164116511661167116811691170117111721173117411751176117711781179118011811182118311841185118611871188118911901191119211931194119511961197119811991200120112021203120412051206120712081209121012111212121312141215121612171218121912201221122212231224122512261227122812291230123112321233123412351236123712381239124012411242124312441245124612471248124912501251125212531254125512561257125812591260126112621263126412651266126712681269127012711272127312741275127612771278127912801281128212831284128512861287128812891290129112921293129412951296129712981299130013011302130313041305130613071308130913101311131213131314131513161317131813191320132113221323132413251326132713281329133013311332133313341335133613371338133913401341134213431344134513461347134813491350135113521353135413551356135713581359136013611362136313641365136613671368136913701371137213731374137513761377137813791380138113821383138413851386138713881389139013911392139313941395139613971398139914001401140214031404140514061407140814091410141114121413141414151416141714181419142014211422142314241425142614271428142914301431143214331434143514361437143814391440144114421443144414451446144714481449145014511452145314541455145614571458145914601461146214631464146514661467146814691470147114721473147414751476147714781479148014811482148314841485148614871488148914901491149214931494149514961497149814991500150115021503150415051506150715081509151015111512151315141515151615171518151915201521152215231524152515261527152815291530153115321533153415351536153715381539154015411542154315441545154615471548154915501551155215531554155515561557155815591560156115621563156415651566156715681569157015711572157315741575157615771578157915801581158215831584158515861587158815891590159115921593159415951596159715981599160016011602160316041605160616071608160916101611161216131614161516161617161816191620162116221623162416251626162716281629163016311632163316341635163616371638163916401641164216431644164516461647164816491650165116521653165416551656165716581659166016611662166316641665166616671668166916701671167216731674167516761677167816791680168116821683168416851686168716881689169016911692169316941695169616971698169917001701170217031704170517061707170817091710171117121713171417151716171717181719172017211722172317241725172617271728172917301731173217331734173517361737173817391740174117421743174417451746174717481749175017511752175317541755175617571758175917601761176217631764176517661767176817691770177117721773177417751776177717781779178017811782178317841785178617871788178917901791179217931794179517961797179817991800180118021803180418051806180718081809181018111812181318141815181618171818181918201821182218231824182518261827182818291830183118321833183418351836183718381839184018411842184318441845184618471848184918501851185218531854185518561857185818591860186118621863186418651866186718681869187018711872187318741875187618771878187918801881188218831884188518861887188818891890189118921893189418951896189718981899190019011902190319041905190619071908190919101911191219131914191519161917191819191920192119221923192419251926192719281929193019311932193319341935193619371938193919401941194219431944194519461947194819491950195119521953195419551956195719581959196019611962196319641965196619671968196919701971197219731974197519761977197819791980198119821983198419851986198719881989199019911992199319941995199619971998
  1. // SPDX-License-Identifier: GPL-2.0+
  2. /*
  3. * Copyright 2023 Google LLC
  4. * Written by Simon Glass <sjg@chromium.org>
  5. */
  6. /*
  7. * Decode and dump U-Boot trace information into formats that can be used
  8. * by trace-cmd, kernelshark or flamegraph.pl
  9. *
  10. * See doc/develop/trace.rst for more information
  11. */
  12. #include <assert.h>
  13. #include <ctype.h>
  14. #include <limits.h>
  15. #include <regex.h>
  16. #include <stdarg.h>
  17. #include <stdio.h>
  18. #include <stdlib.h>
  19. #include <string.h>
  20. #include <unistd.h>
  21. #include <sys/param.h>
  22. #include <sys/types.h>
  23. #include <compiler.h>
  24. #include <trace.h>
  25. #include <abuf.h>
  26. #include <linux/list.h>
  27. /* Set to 1 to emit version 7 file (currently this doesn't work) */
  28. #define VERSION7 0
  29. /* enable some debug features */
  30. #define _DEBUG 0
  31. /* from linux/kernel.h */
  32. #define __ALIGN_MASK(x, mask) (((x) + (mask)) & ~(mask))
  33. #define ALIGN(x, a) __ALIGN_MASK((x), (typeof(x))(a) - 1)
  34. /**
  35. * container_of - cast a member of a structure out to the containing structure
  36. * @ptr: the pointer to the member.
  37. * @type: the type of the container struct this is embedded in.
  38. * @member: the name of the member within the struct.
  39. *
  40. * (this is needed by list.h)
  41. */
  42. #define container_of(ptr, type, member) ({ \
  43. const typeof( ((type *)0)->member ) *__mptr = (ptr); \
  44. (type *)( (char *)__mptr - offsetof(type,member) );})
  45. enum {
  46. FUNCF_TRACE = 1 << 0, /* Include this function in trace */
  47. TRACE_PAGE_SIZE = 4096, /* Assumed page size for trace */
  48. TRACE_PID = 1, /* PID to use for U-Boot */
  49. LEN_STACK_SIZE = 4, /* number of nested length fix-ups */
  50. TRACE_PAGE_MASK = TRACE_PAGE_SIZE - 1,
  51. MAX_STACK_DEPTH = 50, /* Max nested function calls */
  52. MAX_LINE_LEN = 500, /* Max characters per line */
  53. };
  54. /**
  55. * enum out_format_t - supported output formats
  56. *
  57. * @OUT_FMT_DEFAULT: Use the default for the output file
  58. * @OUT_FMT_FUNCTION: Write ftrace 'function' records
  59. * @OUT_FMT_FUNCGRAPH: Write ftrace funcgraph_entry and funcgraph_exit records
  60. * @OUT_FMT_FLAMEGRAPH_CALLS: Write a file suitable for flamegraph.pl
  61. * @OUT_FMT_FLAMEGRAPH_TIMING: Write a file suitable for flamegraph.pl with the
  62. * counts set to the number of microseconds used by each function
  63. */
  64. enum out_format_t {
  65. OUT_FMT_DEFAULT,
  66. OUT_FMT_FUNCTION,
  67. OUT_FMT_FUNCGRAPH,
  68. OUT_FMT_FLAMEGRAPH_CALLS,
  69. OUT_FMT_FLAMEGRAPH_TIMING,
  70. };
  71. /* Section types for v7 format (trace-cmd format) */
  72. enum {
  73. SECTION_OPTIONS,
  74. };
  75. /* Option types (trace-cmd format) */
  76. enum {
  77. OPTION_DONE,
  78. OPTION_DATE,
  79. OPTION_CPUSTAT,
  80. OPTION_BUFFER,
  81. OPTION_TRACECLOCK,
  82. OPTION_UNAME,
  83. OPTION_HOOK,
  84. OPTION_OFFSET,
  85. OPTION_CPUCOUNT,
  86. OPTION_VERSION,
  87. OPTION_PROCMAPS,
  88. OPTION_TRACEID,
  89. OPTION_TIME_SHIFT,
  90. OPTION_GUEST,
  91. OPTION_TSC2NSEC,
  92. };
  93. /* types of trace records (trace-cmd format) */
  94. enum trace_type {
  95. __TRACE_FIRST_TYPE = 0,
  96. TRACE_FN,
  97. TRACE_CTX,
  98. TRACE_WAKE,
  99. TRACE_STACK,
  100. TRACE_PRINT,
  101. TRACE_BPRINT,
  102. TRACE_MMIO_RW,
  103. TRACE_MMIO_MAP,
  104. TRACE_BRANCH,
  105. TRACE_GRAPH_RET,
  106. TRACE_GRAPH_ENT,
  107. };
  108. /**
  109. * struct flame_node - a node in the call-stack tree
  110. *
  111. * Each stack frame detected in the trace is given a node corresponding to a
  112. * function call in the call stack. Functions can appear multiple times when
  113. * they are called by a different set of parent functions.
  114. *
  115. * @parent: Parent node (the call stack for the function that called this one)
  116. * @child_head: List of children of this node (functions called from here)
  117. * @sibling: Next node in the list of children
  118. * @func: Function this node refers to (NULL for root node)
  119. * @count: Number of times this call-stack occurred
  120. * @duration: Number of microseconds taken to run this function, excluding all
  121. * of the functions it calls
  122. */
  123. struct flame_node {
  124. struct flame_node *parent;
  125. struct list_head child_head;
  126. struct list_head sibling_node;
  127. struct func_info *func;
  128. int count;
  129. ulong duration;
  130. };
  131. /**
  132. * struct flame_state - state information for building the flame graph
  133. *
  134. * @node: Current node being processed (corresponds to a function call)
  135. * @stack: Stack of call-start time for this function as well as the
  136. * accumulated total time of all child calls (so we can subtract them from the
  137. * function's call time. This is an 'empty' stack, meaning that @stack_ptr
  138. * points to the next available stack position
  139. * @stack_ptr: points to first empty position in the stack
  140. * @nodes: Number of nodes created (running count)
  141. */
  142. struct flame_state {
  143. struct flame_node *node;
  144. struct stack_info {
  145. ulong timestamp;
  146. ulong child_total;
  147. } stack[MAX_STACK_DEPTH];
  148. int stack_ptr;
  149. int nodes;
  150. };
  151. /**
  152. * struct func_info - information recorded for each function
  153. *
  154. * @offset: Function offset in the image, measured from the text_base
  155. * @name: Function name
  156. * @code_size: Total code size of the function
  157. * @flags: Either 0 or FUNCF_TRACE
  158. */
  159. struct func_info {
  160. unsigned long offset;
  161. const char *name;
  162. unsigned long code_size;
  163. unsigned flags;
  164. };
  165. /**
  166. * enum trace_line_type - whether to include or exclude a function
  167. *
  168. * @TRACE_LINE_INCLUDE: Include the function
  169. * @TRACE_LINE_EXCLUDE: Exclude the function
  170. */
  171. enum trace_line_type {
  172. TRACE_LINE_INCLUDE,
  173. TRACE_LINE_EXCLUDE,
  174. };
  175. /**
  176. * struct trace_configline_info - information about a config-file line
  177. *
  178. * @next: Next line
  179. * @type: Line type
  180. * @name: identifier name / wildcard
  181. * @regex: Regex to use if name starts with '/'
  182. */
  183. struct trace_configline_info {
  184. struct trace_configline_info *next;
  185. enum trace_line_type type;
  186. const char *name;
  187. regex_t regex;
  188. };
  189. /**
  190. * struct tw_len - holds information about a length value that need fix-ups
  191. *
  192. * This is used to record a placeholder for a u32 or u64 length which is written
  193. * to the output file but needs to be updated once the length is actually known
  194. *
  195. * This allows us to write tw->ptr - @len_base to position @ptr in the file
  196. *
  197. * @ptr: Position of the length value in the file
  198. * @base: Base position for the calculation
  199. * @size: Size of the length value, in bytes (4 or 8)
  200. */
  201. struct tw_len {
  202. int ptr;
  203. int base;
  204. int size;
  205. };
  206. /**
  207. * struct twriter - Writer for trace records
  208. *
  209. * Maintains state used when writing the output file in trace-cmd format
  210. *
  211. * @ptr: Current file position
  212. * @len_stack: Stack of length values that need fixing up
  213. * @len: Number of items on @len_stack
  214. * @str_buf: Buffer of strings (for v7 format)
  215. * @str_ptr: Current write-position in the buffer for strings
  216. * @fout: Output file
  217. */
  218. struct twriter {
  219. int ptr;
  220. struct tw_len len_stack[LEN_STACK_SIZE];
  221. int len_count;
  222. struct abuf str_buf;
  223. int str_ptr;
  224. FILE *fout;
  225. };
  226. /* The contents of the trace config file */
  227. struct trace_configline_info *trace_config_head;
  228. /* list of all functions in System.map file, sorted by offset in the image */
  229. struct func_info *func_list;
  230. int func_count; /* number of functions */
  231. struct trace_call *call_list; /* list of all calls in the input trace file */
  232. int call_count; /* number of calls */
  233. int verbose; /* Verbosity level 0=none, 1=warn, 2=notice, 3=info, 4=debug */
  234. ulong text_offset; /* text address of first function */
  235. ulong text_base; /* CONFIG_TEXT_BASE from trace file */
  236. /* debugging helpers */
  237. static void outf(int level, const char *fmt, ...)
  238. __attribute__ ((format (__printf__, 2, 3)));
  239. #define error(fmt, b...) outf(0, fmt, ##b)
  240. #define warn(fmt, b...) outf(1, fmt, ##b)
  241. #define notice(fmt, b...) outf(2, fmt, ##b)
  242. #define info(fmt, b...) outf(3, fmt, ##b)
  243. #define debug(fmt, b...) outf(4, fmt, ##b)
  244. static void outf(int level, const char *fmt, ...)
  245. {
  246. if (verbose >= level) {
  247. va_list args;
  248. va_start(args, fmt);
  249. vfprintf(stderr, fmt, args);
  250. va_end(args);
  251. }
  252. }
  253. static void usage(void)
  254. {
  255. fprintf(stderr,
  256. "Usage: proftool [-cmtv] <cmd> <profdata>\n"
  257. "\n"
  258. "Commands\n"
  259. " dump-ftrace\t\tDump out records in ftrace format for use by trace-cmd\n"
  260. " dump-flamegraph\tWrite a file for use with flamegraph.pl\n"
  261. "\n"
  262. "Options:\n"
  263. " -c <cfg>\tSpecify config file\n"
  264. " -f <subtype>\tSpecify output subtype\n"
  265. " -m <map>\tSpecify Systen.map file\n"
  266. " -o <fname>\tSpecify output file\n"
  267. " -t <fname>\tSpecify trace data file (from U-Boot 'trace calls')\n"
  268. " -v <0-4>\tSpecify verbosity\n"
  269. "\n"
  270. "Subtypes for dump-ftrace:\n"
  271. " function - write function-call records (caller/callee)\n"
  272. " funcgraph - write function entry/exit records (graph)\n"
  273. "\n"
  274. "Subtypes for dump-flamegraph\n"
  275. " calls - create a flamegraph of stack frames\n"
  276. " timing - create a flamegraph of microseconds for each stack frame\n");
  277. exit(EXIT_FAILURE);
  278. }
  279. /**
  280. * h_cmp_offset - bsearch() function to compare two functions bny their offset
  281. *
  282. * @v1: Pointer to first function (struct func_info)
  283. * @v2: Pointer to second function (struct func_info)
  284. * Returns: < 0 if v1 offset < v2 offset, 0 if equal, > 0 otherwise
  285. */
  286. static int h_cmp_offset(const void *v1, const void *v2)
  287. {
  288. const struct func_info *f1 = v1, *f2 = v2;
  289. return (f1->offset / FUNC_SITE_SIZE) - (f2->offset / FUNC_SITE_SIZE);
  290. }
  291. /**
  292. * read_system_map() - read the System.map file to create a list of functions
  293. *
  294. * This also reads the text_offset value, since we assume that the first text
  295. * symbol is at that address
  296. *
  297. * @fin: File to read
  298. * Returns: 0 if OK, non-zero on error
  299. */
  300. static int read_system_map(FILE *fin)
  301. {
  302. unsigned long offset, start = 0;
  303. struct func_info *func;
  304. char buff[MAX_LINE_LEN];
  305. char symtype;
  306. char symname[MAX_LINE_LEN + 1];
  307. int linenum;
  308. int alloced;
  309. for (linenum = 1, alloced = func_count = 0;; linenum++) {
  310. int fields = 0;
  311. if (fgets(buff, sizeof(buff), fin))
  312. fields = sscanf(buff, "%lx %c %100s\n", &offset,
  313. &symtype, symname);
  314. if (fields == 2) {
  315. continue;
  316. } else if (feof(fin)) {
  317. break;
  318. } else if (fields < 2) {
  319. error("Map file line %d: invalid format\n", linenum);
  320. return 1;
  321. }
  322. /* Must be a text symbol */
  323. symtype = tolower(symtype);
  324. if (symtype != 't' && symtype != 'w')
  325. continue;
  326. if (func_count == alloced) {
  327. alloced += 256;
  328. func_list = realloc(func_list,
  329. sizeof(struct func_info) * alloced);
  330. assert(func_list);
  331. }
  332. if (!func_count)
  333. start = offset;
  334. func = &func_list[func_count++];
  335. memset(func, '\0', sizeof(*func));
  336. func->offset = offset - start;
  337. func->name = strdup(symname);
  338. func->flags = FUNCF_TRACE; /* trace by default */
  339. /* Update previous function's code size */
  340. if (func_count > 1)
  341. func[-1].code_size = func->offset - func[-1].offset;
  342. }
  343. notice("%d functions found in map file, start addr %lx\n", func_count,
  344. start);
  345. text_offset = start;
  346. return 0;
  347. }
  348. static int read_data(FILE *fin, void *buff, int size)
  349. {
  350. int err;
  351. err = fread(buff, 1, size, fin);
  352. if (!err)
  353. return 1;
  354. if (err != size) {
  355. error("Cannot read trace file at pos %lx\n", ftell(fin));
  356. return -1;
  357. }
  358. return 0;
  359. }
  360. /**
  361. * find_func_by_offset() - Look up a function by its offset
  362. *
  363. * @offset: Offset to search for, from text_base
  364. * Returns: function, if found, else NULL
  365. *
  366. * This does a fast search for a function given its offset from text_base
  367. *
  368. */
  369. static struct func_info *find_func_by_offset(uint offset)
  370. {
  371. struct func_info key, *found;
  372. key.offset = offset;
  373. found = bsearch(&key, func_list, func_count, sizeof(struct func_info),
  374. h_cmp_offset);
  375. return found;
  376. }
  377. /**
  378. * find_caller_by_offset() - finds the function which contains the given offset
  379. *
  380. * @offset: Offset to search for, from text_base
  381. * Returns: function, if found, else NULL
  382. *
  383. * If the offset falls between two functions, then it is assumed to belong to
  384. * the first function (with the lowest offset). This is a way of figuring out
  385. * which function owns code at a particular offset
  386. */
  387. static struct func_info *find_caller_by_offset(uint offset)
  388. {
  389. int low; /* least function that could be a match */
  390. int high; /* greated function that could be a match */
  391. struct func_info key;
  392. low = 0;
  393. high = func_count - 1;
  394. key.offset = offset;
  395. while (high > low + 1) {
  396. int mid = (low + high) / 2;
  397. int result;
  398. result = h_cmp_offset(&key, &func_list[mid]);
  399. if (result > 0)
  400. low = mid;
  401. else if (result < 0)
  402. high = mid;
  403. else
  404. return &func_list[mid];
  405. }
  406. return low >= 0 ? &func_list[low] : NULL;
  407. }
  408. /**
  409. * read_calls() - Read the list of calls from the trace data
  410. *
  411. * The calls are stored consecutively in the trace output produced by U-Boot
  412. *
  413. * @fin: File to read from
  414. * @count: Number of calls to read
  415. * Returns: 0 if OK, -1 on error
  416. */
  417. static int read_calls(FILE *fin, size_t count)
  418. {
  419. struct trace_call *call_data;
  420. int i;
  421. notice("call count: %zu\n", count);
  422. call_list = (struct trace_call *)calloc(count, sizeof(*call_data));
  423. if (!call_list) {
  424. error("Cannot allocate call_list\n");
  425. return -1;
  426. }
  427. call_count = count;
  428. call_data = call_list;
  429. for (i = 0; i < count; i++, call_data++) {
  430. if (read_data(fin, call_data, sizeof(*call_data)))
  431. return -1;
  432. }
  433. return 0;
  434. }
  435. /**
  436. * read_trace() - Read the U-Boot trace file
  437. *
  438. * Read in the calls from the trace file. The function list is ignored at
  439. * present
  440. *
  441. * @fin: File to read
  442. * Returns 0 if OK, non-zero on error
  443. */
  444. static int read_trace(FILE *fin)
  445. {
  446. struct trace_output_hdr hdr;
  447. while (!feof(fin)) {
  448. int err;
  449. err = read_data(fin, &hdr, sizeof(hdr));
  450. if (err == 1)
  451. break; /* EOF */
  452. else if (err)
  453. return 1;
  454. text_base = hdr.text_base;
  455. switch (hdr.type) {
  456. case TRACE_CHUNK_FUNCS:
  457. /* Ignored at present */
  458. break;
  459. case TRACE_CHUNK_CALLS:
  460. if (read_calls(fin, hdr.rec_count))
  461. return 1;
  462. break;
  463. }
  464. }
  465. return 0;
  466. }
  467. /**
  468. * read_map_file() - Read the System.map file
  469. *
  470. * This reads the file into the func_list array
  471. *
  472. * @fname: Filename to read
  473. * Returns 0 if OK, non-zero on error
  474. */
  475. static int read_map_file(const char *fname)
  476. {
  477. FILE *fmap;
  478. int err = 0;
  479. fmap = fopen(fname, "r");
  480. if (!fmap) {
  481. error("Cannot open map file '%s'\n", fname);
  482. return 1;
  483. }
  484. if (fmap) {
  485. err = read_system_map(fmap);
  486. fclose(fmap);
  487. }
  488. return err;
  489. }
  490. /**
  491. * read_trace_file() - Open and read the U-Boot trace file
  492. *
  493. * Read in the calls from the trace file. The function list is ignored at
  494. * present
  495. *
  496. * @fin: File to read
  497. * Returns 0 if OK, non-zero on error
  498. */
  499. static int read_trace_file(const char *fname)
  500. {
  501. FILE *fprof;
  502. int err;
  503. fprof = fopen(fname, "rb");
  504. if (!fprof) {
  505. error("Cannot open trace data file '%s'\n",
  506. fname);
  507. return 1;
  508. } else {
  509. err = read_trace(fprof);
  510. fclose(fprof);
  511. if (err)
  512. return err;
  513. }
  514. return 0;
  515. }
  516. static int regex_report_error(regex_t *regex, int err, const char *op,
  517. const char *name)
  518. {
  519. char buf[200];
  520. regerror(err, regex, buf, sizeof(buf));
  521. error("Regex error '%s' in %s '%s'\n", buf, op, name);
  522. return -1;
  523. }
  524. static void check_trace_config_line(struct trace_configline_info *item)
  525. {
  526. struct func_info *func, *end;
  527. int err;
  528. debug("Checking trace config line '%s'\n", item->name);
  529. for (func = func_list, end = func + func_count; func < end; func++) {
  530. err = regexec(&item->regex, func->name, 0, NULL, 0);
  531. debug(" - regex '%s', string '%s': %d\n", item->name,
  532. func->name, err);
  533. if (err == REG_NOMATCH)
  534. continue;
  535. if (err) {
  536. regex_report_error(&item->regex, err, "match",
  537. item->name);
  538. break;
  539. }
  540. /* It matches, so perform the action */
  541. switch (item->type) {
  542. case TRACE_LINE_INCLUDE:
  543. info(" include %s at %lx\n", func->name,
  544. text_offset + func->offset);
  545. func->flags |= FUNCF_TRACE;
  546. break;
  547. case TRACE_LINE_EXCLUDE:
  548. info(" exclude %s at %lx\n", func->name,
  549. text_offset + func->offset);
  550. func->flags &= ~FUNCF_TRACE;
  551. break;
  552. }
  553. }
  554. }
  555. /** check_trace_config() - Check trace-config file, reporting any problems */
  556. static void check_trace_config(void)
  557. {
  558. struct trace_configline_info *line;
  559. for (line = trace_config_head; line; line = line->next)
  560. check_trace_config_line(line);
  561. }
  562. /**
  563. * read_trace_config() - read the trace-config file
  564. *
  565. * This file consists of lines like:
  566. *
  567. * include-func <regex>
  568. * exclude-func <regex>
  569. *
  570. * where <regex> is a regular expression matched against function names. It
  571. * allows some functions to be dropped from the trace when producing ftrace
  572. * records
  573. *
  574. * @fin: File to process
  575. * Returns: 0 if OK, -1 on error
  576. */
  577. static int read_trace_config(FILE *fin)
  578. {
  579. char buff[200];
  580. int linenum = 0;
  581. struct trace_configline_info **tailp = &trace_config_head;
  582. while (fgets(buff, sizeof(buff), fin)) {
  583. int len = strlen(buff);
  584. struct trace_configline_info *line;
  585. char *saveptr;
  586. char *s, *tok;
  587. int err;
  588. linenum++;
  589. if (len && buff[len - 1] == '\n')
  590. buff[len - 1] = '\0';
  591. /* skip blank lines and comments */
  592. for (s = buff; *s == ' ' || *s == '\t'; s++)
  593. ;
  594. if (!*s || *s == '#')
  595. continue;
  596. line = (struct trace_configline_info *)calloc(1, sizeof(*line));
  597. if (!line) {
  598. error("Cannot allocate config line\n");
  599. return -1;
  600. }
  601. tok = strtok_r(s, " \t", &saveptr);
  602. if (!tok) {
  603. error("Invalid trace config data on line %d\n",
  604. linenum);
  605. return -1;
  606. }
  607. if (0 == strcmp(tok, "include-func")) {
  608. line->type = TRACE_LINE_INCLUDE;
  609. } else if (0 == strcmp(tok, "exclude-func")) {
  610. line->type = TRACE_LINE_EXCLUDE;
  611. } else {
  612. error("Unknown command in trace config data line %d\n",
  613. linenum);
  614. return -1;
  615. }
  616. tok = strtok_r(NULL, " \t", &saveptr);
  617. if (!tok) {
  618. error("Missing pattern in trace config data line %d\n",
  619. linenum);
  620. return -1;
  621. }
  622. err = regcomp(&line->regex, tok, REG_NOSUB);
  623. if (err) {
  624. int r = regex_report_error(&line->regex, err,
  625. "compile", tok);
  626. free(line);
  627. return r;
  628. }
  629. /* link this new one to the end of the list */
  630. line->name = strdup(tok);
  631. line->next = NULL;
  632. *tailp = line;
  633. tailp = &line->next;
  634. }
  635. if (!feof(fin)) {
  636. error("Cannot read from trace config file at position %ld\n",
  637. ftell(fin));
  638. return -1;
  639. }
  640. return 0;
  641. }
  642. static int read_trace_config_file(const char *fname)
  643. {
  644. FILE *fin;
  645. int err;
  646. fin = fopen(fname, "r");
  647. if (!fin) {
  648. error("Cannot open trace_config file '%s'\n", fname);
  649. return -1;
  650. }
  651. err = read_trace_config(fin);
  652. fclose(fin);
  653. return err;
  654. }
  655. /**
  656. * tputh() - Write a 16-bit little-endian value to a file
  657. *
  658. * @fout: File to write to
  659. * @val: Value to write
  660. * Returns: number of bytes written (2)
  661. */
  662. static int tputh(FILE *fout, unsigned int val)
  663. {
  664. fputc(val, fout);
  665. fputc(val >> 8, fout);
  666. return 2;
  667. }
  668. /**
  669. * tputl() - Write a 32-bit little-endian value to a file
  670. *
  671. * @fout: File to write to
  672. * @val: Value to write
  673. * Returns: number of bytes written (4)
  674. */
  675. static int tputl(FILE *fout, ulong val)
  676. {
  677. fputc(val, fout);
  678. fputc(val >> 8, fout);
  679. fputc(val >> 16, fout);
  680. fputc(val >> 24, fout);
  681. return 4;
  682. }
  683. /**
  684. * tputh() - Write a 64-bit little-endian value to a file
  685. *
  686. * @fout: File to write to
  687. * @val: Value to write
  688. * Returns: number of bytes written (8)
  689. */
  690. static int tputq(FILE *fout, unsigned long long val)
  691. {
  692. tputl(fout, val);
  693. tputl(fout, val >> 32U);
  694. return 8;
  695. }
  696. /**
  697. * tputh() - Write a string to a file
  698. *
  699. * The string is written without its terminator
  700. *
  701. * @fout: File to write to
  702. * @val: Value to write
  703. * Returns: number of bytes written
  704. */
  705. static int tputs(FILE *fout, const char *str)
  706. {
  707. fputs(str, fout);
  708. return strlen(str);
  709. }
  710. /**
  711. * add_str() - add a name string to the string table
  712. *
  713. * This is used by the v7 format
  714. *
  715. * @tw: Writer context
  716. * @name: String to write
  717. * Returns: Updated value of string pointer, or -1 if out of memory
  718. */
  719. static int add_str(struct twriter *tw, const char *name)
  720. {
  721. int str_ptr;
  722. int len;
  723. len = strlen(name) + 1;
  724. str_ptr = tw->str_ptr;
  725. tw->str_ptr += len;
  726. if (tw->str_ptr > abuf_size(&tw->str_buf)) {
  727. int new_size;
  728. new_size = ALIGN(tw->str_ptr, 4096);
  729. if (!abuf_realloc(&tw->str_buf, new_size))
  730. return -1;
  731. }
  732. return str_ptr;
  733. }
  734. /**
  735. * push_len() - Push a new length request onto the stack
  736. *
  737. * @tw: Writer context
  738. * @base: Base position of the length calculation
  739. * @msg: Indicates the type of caller, for debugging
  740. * @size: Size of the length value, either 4 bytes or 8
  741. * Returns number of bytes written to the file (=@size on success), -ve on error
  742. *
  743. * This marks a place where a length must be written, covering data that is
  744. * about to be written. It writes a placeholder value.
  745. *
  746. * Once the data is written, calling pop_len() will update the placeholder with
  747. * the correct length based on how many bytes have been written
  748. */
  749. static int push_len(struct twriter *tw, int base, const char *msg, int size)
  750. {
  751. struct tw_len *lp;
  752. if (tw->len_count >= LEN_STACK_SIZE) {
  753. fprintf(stderr, "Length-stack overflow: %s\n", msg);
  754. return -1;
  755. }
  756. if (size != 4 && size != 8) {
  757. fprintf(stderr, "Length-stack invalid size %d: %s\n", size,
  758. msg);
  759. return -1;
  760. }
  761. lp = &tw->len_stack[tw->len_count++];
  762. lp->base = base;
  763. lp->ptr = tw->ptr;
  764. lp->size = size;
  765. return size == 8 ? tputq(tw->fout, 0) : tputl(tw->fout, 0);
  766. }
  767. /**
  768. * pop_len() - Update a length value once the length is known
  769. *
  770. * Pops a value of the length stack and updates the file at that position with
  771. * the number of bytes written between now and then. Once done, the file is
  772. * seeked to the current (tw->ptr) position again, so writing can continue as
  773. * normal.
  774. *
  775. * @tw: Writer context
  776. * @msg: Indicates the type of caller, for debugging
  777. * Returns 0 if OK, -1 on error
  778. */
  779. static int pop_len(struct twriter *tw, const char *msg)
  780. {
  781. struct tw_len *lp;
  782. int len, ret;
  783. if (!tw->len_count) {
  784. fprintf(stderr, "Length-stack underflow: %s\n", msg);
  785. return -1;
  786. }
  787. lp = &tw->len_stack[--tw->len_count];
  788. if (fseek(tw->fout, lp->ptr, SEEK_SET))
  789. return -1;
  790. len = tw->ptr - lp->base;
  791. ret = lp->size == 8 ? tputq(tw->fout, len) : tputl(tw->fout, len);
  792. if (ret < 0)
  793. return -1;
  794. if (fseek(tw->fout, tw->ptr, SEEK_SET))
  795. return -1;
  796. return 0;
  797. }
  798. /**
  799. * start_header() - Start a v7 section
  800. *
  801. * Writes a header in v7 format
  802. *
  803. * @tw: Writer context
  804. * @id: ID of header to write (SECTION_...)
  805. * @flags: Flags value to write
  806. * @name: Name of section
  807. * Returns: number of bytes written
  808. */
  809. static int start_header(struct twriter *tw, int id, uint flags,
  810. const char *name)
  811. {
  812. int str_id;
  813. int lptr;
  814. int base;
  815. int ret;
  816. base = tw->ptr + 16;
  817. lptr = 0;
  818. lptr += tputh(tw->fout, id);
  819. lptr += tputh(tw->fout, flags);
  820. str_id = add_str(tw, name);
  821. if (str_id < 0)
  822. return -1;
  823. lptr += tputl(tw->fout, str_id);
  824. /* placeholder for size */
  825. ret = push_len(tw, base, "v7 header", 8);
  826. if (ret < 0)
  827. return -1;
  828. lptr += ret;
  829. return lptr;
  830. }
  831. /**
  832. * start_page() - Start a new page of output data
  833. *
  834. * The output is arranged in 4KB pages with a base timestamp at the start of
  835. * each. This starts a new page, making sure it is aligned to 4KB in the output
  836. * file.
  837. *
  838. * @tw: Writer context
  839. * @timestamp: Base timestamp for the page
  840. */
  841. static int start_page(struct twriter *tw, ulong timestamp)
  842. {
  843. int start;
  844. int ret;
  845. /* move to start of next page */
  846. start = ALIGN(tw->ptr, TRACE_PAGE_SIZE);
  847. ret = fseek(tw->fout, start, SEEK_SET);
  848. if (ret < 0) {
  849. fprintf(stderr, "Cannot seek to page start\n");
  850. return -1;
  851. }
  852. tw->ptr = start;
  853. /* page header */
  854. tw->ptr += tputq(tw->fout, timestamp);
  855. ret = push_len(tw, start + 16, "page", 8);
  856. if (ret < 0)
  857. return ret;
  858. tw->ptr += ret;
  859. return 0;
  860. }
  861. /**
  862. * finish_page() - finish a page
  863. *
  864. * Sets the lengths correctly and moves to the start of the next page
  865. *
  866. * @tw: Writer context
  867. * Returns: 0 on success, -1 on error
  868. */
  869. static int finish_page(struct twriter *tw)
  870. {
  871. int ret, end;
  872. ret = pop_len(tw, "page");
  873. if (ret < 0)
  874. return ret;
  875. end = ALIGN(tw->ptr, TRACE_PAGE_SIZE);
  876. /*
  877. * Write a byte so that the data actually makes to the file, in the case
  878. * that we never write any more pages
  879. */
  880. if (tw->ptr != end) {
  881. if (fseek(tw->fout, end - 1, SEEK_SET)) {
  882. fprintf(stderr, "cannot seek to start of next page\n");
  883. return -1;
  884. }
  885. fputc(0, tw->fout);
  886. tw->ptr = end;
  887. }
  888. return 0;
  889. }
  890. /**
  891. * output_headers() - Output v6 headers to the file
  892. *
  893. * Writes out the various formats so that trace-cmd and kernelshark can make
  894. * sense of the data
  895. *
  896. * This updates tw->ptr as it goes
  897. *
  898. * @tw: Writer context
  899. * Returns: 0 on success, -ve on error
  900. */
  901. static int output_headers(struct twriter *tw)
  902. {
  903. FILE *fout = tw->fout;
  904. char str[800];
  905. int len, ret;
  906. tw->ptr += fprintf(fout, "%c%c%ctracing6%c%c%c", 0x17, 0x08, 0x44,
  907. 0 /* terminator */, 0 /* little endian */,
  908. 4 /* 32-bit long values */);
  909. /* host-machine page size 4KB */
  910. tw->ptr += tputl(fout, 4 << 10);
  911. tw->ptr += fprintf(fout, "header_page%c", 0);
  912. snprintf(str, sizeof(str),
  913. "\tfield: u64 timestamp;\toffset:0;\tsize:8;\tsigned:0;\n"
  914. "\tfield: local_t commit;\toffset:8;\tsize:8;\tsigned:1;\n"
  915. "\tfield: int overwrite;\toffset:8;\tsize:1;\tsigned:1;\n"
  916. "\tfield: char data;\toffset:16;\tsize:4080;\tsigned:1;\n");
  917. len = strlen(str);
  918. tw->ptr += tputq(fout, len);
  919. tw->ptr += tputs(fout, str);
  920. if (VERSION7) {
  921. /* no compression */
  922. tw->ptr += fprintf(fout, "none%cversion%c\n", 0, 0);
  923. ret = start_header(tw, SECTION_OPTIONS, 0, "options");
  924. if (ret < 0) {
  925. fprintf(stderr, "Cannot start option header\n");
  926. return -1;
  927. }
  928. tw->ptr += ret;
  929. tw->ptr += tputh(fout, OPTION_DONE);
  930. tw->ptr += tputl(fout, 8);
  931. tw->ptr += tputl(fout, 0);
  932. ret = pop_len(tw, "t7 header");
  933. if (ret < 0) {
  934. fprintf(stderr, "Cannot finish option header\n");
  935. return -1;
  936. }
  937. }
  938. tw->ptr += fprintf(fout, "header_event%c", 0);
  939. snprintf(str, sizeof(str),
  940. "# compressed entry header\n"
  941. "\ttype_len : 5 bits\n"
  942. "\ttime_delta : 27 bits\n"
  943. "\tarray : 32 bits\n"
  944. "\n"
  945. "\tpadding : type == 29\n"
  946. "\ttime_extend : type == 30\n"
  947. "\ttime_stamp : type == 31\n"
  948. "\tdata max type_len == 28\n");
  949. len = strlen(str);
  950. tw->ptr += tputq(fout, len);
  951. tw->ptr += tputs(fout, str);
  952. /* number of ftrace-event-format files */
  953. tw->ptr += tputl(fout, 3);
  954. snprintf(str, sizeof(str),
  955. "name: function\n"
  956. "ID: 1\n"
  957. "format:\n"
  958. "\tfield:unsigned short common_type;\toffset:0;\tsize:2;\tsigned:0;\n"
  959. "\tfield:unsigned char common_flags;\toffset:2;\tsize:1;\tsigned:0;\n"
  960. "\tfield:unsigned char common_preempt_count;\toffset:3;\tsize:1;signed:0;\n"
  961. "\tfield:int common_pid;\toffset:4;\tsize:4;\tsigned:1;\n"
  962. "\n"
  963. "\tfield:unsigned long ip;\toffset:8;\tsize:8;\tsigned:0;\n"
  964. "\tfield:unsigned long parent_ip;\toffset:16;\tsize:8;\tsigned:0;\n"
  965. "\n"
  966. "print fmt: \" %%ps <-- %%ps\", (void *)REC->ip, (void *)REC->parent_ip\n");
  967. len = strlen(str);
  968. tw->ptr += tputq(fout, len);
  969. tw->ptr += tputs(fout, str);
  970. snprintf(str, sizeof(str),
  971. "name: funcgraph_entry\n"
  972. "ID: 11\n"
  973. "format:\n"
  974. "\tfield:unsigned short common_type;\toffset:0;\tsize:2;\tsigned:0;\n"
  975. "\tfield:unsigned char common_flags;\toffset:2;\tsize:1;\tsigned:0;\n"
  976. "\tfield:unsigned char common_preempt_count;\toffset:3;\tsize:1;signed:0;\n"
  977. "\tfield:int common_pid;\toffset:4;\tsize:4;\tsigned:1;\n"
  978. "\n"
  979. "\tfield:unsigned long func;\toffset:8;\tsize:8;\tsigned:0;\n"
  980. "\tfield:int depth;\toffset:16;\tsize:4;\tsigned:1;\n"
  981. "\n"
  982. "print fmt: \"--> %%ps (%%d)\", (void *)REC->func, REC->depth\n");
  983. len = strlen(str);
  984. tw->ptr += tputq(fout, len);
  985. tw->ptr += tputs(fout, str);
  986. snprintf(str, sizeof(str),
  987. "name: funcgraph_exit\n"
  988. "ID: 10\n"
  989. "format:\n"
  990. "\tfield:unsigned short common_type;\toffset:0;\tsize:2;\tsigned:0;\n"
  991. "\tfield:unsigned char common_flags;\toffset:2;\tsize:1;\tsigned:0;\n"
  992. "\tfield:unsigned char common_preempt_count;\toffset:3;\tsize:1;signed:0;\n"
  993. "\tfield:int common_pid;\toffset:4;\tsize:4;\tsigned:1;\n"
  994. "\n"
  995. "\tfield:unsigned long func;\toffset:8;\tsize:8;\tsigned:0;\n"
  996. "\tfield:int depth;\toffset:16;\tsize:4;\tsigned:1;\n"
  997. "\tfield:unsigned int overrun;\toffset:20;\tsize:4;\tsigned:0;\n"
  998. "\tfield:unsigned long long calltime;\toffset:24;\tsize:8;\tsigned:0;\n"
  999. "\tfield:unsigned long long rettime;\toffset:32;\tsize:8;\tsigned:0;\n"
  1000. "\n"
  1001. "print fmt: \"<-- %%ps (%%d) (start: %%llx end: %%llx) over: %%d\", (void *)REC->func, REC->depth, REC->calltime, REC->rettime, REC->depth\n");
  1002. len = strlen(str);
  1003. tw->ptr += tputq(fout, len);
  1004. tw->ptr += tputs(fout, str);
  1005. return 0;
  1006. }
  1007. /**
  1008. * write_symbols() - Write the symbols out
  1009. *
  1010. * Writes the symbol information in the following format to mimic the Linux
  1011. * /proc/kallsyms file:
  1012. *
  1013. * <address> T <name>
  1014. *
  1015. * This updates tw->ptr as it goes
  1016. *
  1017. * @tw: Writer context
  1018. * Returns: 0 on success, -ve on error
  1019. */
  1020. static int write_symbols(struct twriter *tw)
  1021. {
  1022. char str[200];
  1023. int ret, i;
  1024. /* write symbols */
  1025. ret = push_len(tw, tw->ptr + 4, "syms", 4);
  1026. if (ret < 0)
  1027. return -1;
  1028. tw->ptr += ret;
  1029. for (i = 0; i < func_count; i++) {
  1030. struct func_info *func = &func_list[i];
  1031. snprintf(str, sizeof(str), "%016lx T %s\n",
  1032. text_offset + func->offset, func->name);
  1033. tw->ptr += tputs(tw->fout, str);
  1034. }
  1035. ret = pop_len(tw, "syms");
  1036. if (ret < 0)
  1037. return -1;
  1038. tw->ptr += ret;
  1039. return 0;
  1040. }
  1041. /**
  1042. * write_options() - Write the options out
  1043. *
  1044. * Writes various options which are needed or useful. We use OPTION_TSC2NSEC
  1045. * to indicates that values in the output need to be multiplied by 1000 since
  1046. * U-Boot's trace values are in microseconds.
  1047. *
  1048. * This updates tw->ptr as it goes
  1049. *
  1050. * @tw: Writer context
  1051. * Returns: 0 on success, -ve on error
  1052. */
  1053. static int write_options(struct twriter *tw)
  1054. {
  1055. FILE *fout = tw->fout;
  1056. char str[200];
  1057. int len;
  1058. /* trace_printk, 0 for now */
  1059. tw->ptr += tputl(fout, 0);
  1060. /* processes */
  1061. snprintf(str, sizeof(str), "%d u-boot\n", TRACE_PID);
  1062. len = strlen(str);
  1063. tw->ptr += tputq(fout, len);
  1064. tw->ptr += tputs(fout, str);
  1065. /* number of CPUs */
  1066. tw->ptr += tputl(fout, 1);
  1067. tw->ptr += fprintf(fout, "options %c", 0);
  1068. /* traceclock */
  1069. tw->ptr += tputh(fout, OPTION_TRACECLOCK);
  1070. tw->ptr += tputl(fout, 0);
  1071. /* uname */
  1072. tw->ptr += tputh(fout, OPTION_UNAME);
  1073. snprintf(str, sizeof(str), "U-Boot");
  1074. len = strlen(str);
  1075. tw->ptr += tputl(fout, len);
  1076. tw->ptr += tputs(fout, str);
  1077. /* version */
  1078. tw->ptr += tputh(fout, OPTION_VERSION);
  1079. snprintf(str, sizeof(str), "unknown");
  1080. len = strlen(str);
  1081. tw->ptr += tputl(fout, len);
  1082. tw->ptr += tputs(fout, str);
  1083. /* trace ID */
  1084. tw->ptr += tputh(fout, OPTION_TRACEID);
  1085. tw->ptr += tputl(fout, 8);
  1086. tw->ptr += tputq(fout, 0x123456780abcdef0);
  1087. /* time conversion */
  1088. tw->ptr += tputh(fout, OPTION_TSC2NSEC);
  1089. tw->ptr += tputl(fout, 16);
  1090. tw->ptr += tputl(fout, 1000); /* multiplier */
  1091. tw->ptr += tputl(fout, 0); /* shift */
  1092. tw->ptr += tputq(fout, 0); /* offset */
  1093. /* cpustat - bogus data for now, but at least it mentions the CPU */
  1094. tw->ptr += tputh(fout, OPTION_CPUSTAT);
  1095. snprintf(str, sizeof(str),
  1096. "CPU: 0\n"
  1097. "entries: 100\n"
  1098. "overrun: 43565\n"
  1099. "commit overrun: 0\n"
  1100. "bytes: 3360\n"
  1101. "oldest event ts: 963732.447752\n"
  1102. "now ts: 963832.146824\n"
  1103. "dropped events: 0\n"
  1104. "read events: 42379\n");
  1105. len = strlen(str);
  1106. tw->ptr += tputl(fout, len);
  1107. tw->ptr += tputs(fout, str);
  1108. tw->ptr += tputh(fout, OPTION_DONE);
  1109. return 0;
  1110. }
  1111. /**
  1112. * calc_min_depth() - Calculate the minimum call depth from the call list
  1113. *
  1114. * Starting with a depth of 0, this works through the call list, adding 1 for
  1115. * each function call and subtracting 1 for each function return. Most likely
  1116. * the value ends up being negative, since the trace does not start at the
  1117. * very top of the call stack, e.g. main(), but some function called by that.
  1118. *
  1119. * This value can be used to calculate the depth value for the first call,
  1120. * such that it never goes negative for subsequent returns.
  1121. *
  1122. * Returns: minimum call depth (e.g. -2)
  1123. */
  1124. static int calc_min_depth(void)
  1125. {
  1126. struct trace_call *call;
  1127. int depth, min_depth, i;
  1128. /* Calculate minimum depth */
  1129. depth = 0;
  1130. min_depth = 0;
  1131. for (i = 0, call = call_list; i < call_count; i++, call++) {
  1132. switch (TRACE_CALL_TYPE(call)) {
  1133. case FUNCF_ENTRY:
  1134. depth++;
  1135. break;
  1136. case FUNCF_EXIT:
  1137. depth--;
  1138. if (depth < min_depth)
  1139. min_depth = depth;
  1140. break;
  1141. }
  1142. }
  1143. return min_depth;
  1144. }
  1145. /**
  1146. * write_pages() - Write the pages of trace data
  1147. *
  1148. * This works through all the calls, writing out as many pages of data as are
  1149. * needed.
  1150. *
  1151. * @tw: Writer context
  1152. * @out_format: Output format to use
  1153. * @missing_countp: Returns number of missing functions (not found in function
  1154. * list)
  1155. * @skip_countp: Returns number of skipped functions (excluded from trace)
  1156. *
  1157. * Returns: 0 on success, -ve on error
  1158. */
  1159. static int write_pages(struct twriter *tw, enum out_format_t out_format,
  1160. int *missing_countp, int *skip_countp)
  1161. {
  1162. ulong func_stack[MAX_STACK_DEPTH];
  1163. int stack_ptr; /* next free position in stack */
  1164. int upto, depth, page_upto, i;
  1165. int missing_count = 0, skip_count = 0;
  1166. struct trace_call *call;
  1167. ulong last_timestamp;
  1168. FILE *fout = tw->fout;
  1169. int last_delta = 0;
  1170. int err_count;
  1171. bool in_page;
  1172. in_page = false;
  1173. last_timestamp = 0;
  1174. upto = 0;
  1175. page_upto = 0;
  1176. err_count = 0;
  1177. /* maintain a stack of start times for calling functions */
  1178. stack_ptr = 0;
  1179. /*
  1180. * The first thing in the trace may not be the top-level function, so
  1181. * set the initial depth so that no function goes below depth 0
  1182. */
  1183. depth = -calc_min_depth();
  1184. for (i = 0, call = call_list; i < call_count; i++, call++) {
  1185. bool entry = TRACE_CALL_TYPE(call) == FUNCF_ENTRY;
  1186. struct func_info *func;
  1187. ulong timestamp;
  1188. uint rec_words;
  1189. int delta;
  1190. func = find_func_by_offset(call->func);
  1191. if (!func) {
  1192. warn("Cannot find function at %lx\n",
  1193. text_offset + call->func);
  1194. missing_count++;
  1195. if (missing_count > 20) {
  1196. /* perhaps trace does not match System.map */
  1197. fprintf(stderr, "Too many missing functions\n");
  1198. return -1;
  1199. }
  1200. continue;
  1201. }
  1202. if (!(func->flags & FUNCF_TRACE)) {
  1203. debug("Funcion '%s' is excluded from trace\n",
  1204. func->name);
  1205. skip_count++;
  1206. continue;
  1207. }
  1208. if (out_format == OUT_FMT_FUNCTION)
  1209. rec_words = 6;
  1210. else /* 2 header words and then 3 or 8 others */
  1211. rec_words = 2 + (entry ? 3 : 8);
  1212. /* convert timestamp from us to ns */
  1213. timestamp = call->flags & FUNCF_TIMESTAMP_MASK;
  1214. if (in_page) {
  1215. if (page_upto + rec_words * 4 > TRACE_PAGE_SIZE) {
  1216. if (finish_page(tw))
  1217. return -1;
  1218. in_page = false;
  1219. }
  1220. }
  1221. if (!in_page) {
  1222. if (start_page(tw, timestamp))
  1223. return -1;
  1224. in_page = true;
  1225. last_timestamp = timestamp;
  1226. last_delta = 0;
  1227. page_upto = tw->ptr & TRACE_PAGE_MASK;
  1228. if (_DEBUG) {
  1229. fprintf(stderr,
  1230. "new page, last_timestamp=%ld, upto=%d\n",
  1231. last_timestamp, upto);
  1232. }
  1233. }
  1234. delta = timestamp - last_timestamp;
  1235. if (delta < 0) {
  1236. fprintf(stderr, "Time went backwards\n");
  1237. err_count++;
  1238. }
  1239. if (err_count > 20) {
  1240. fprintf(stderr, "Too many errors, giving up\n");
  1241. return -1;
  1242. }
  1243. if (delta > 0x07fffff) {
  1244. /*
  1245. * hard to imagine how this could happen since it means
  1246. * that no function calls were made for a long time
  1247. */
  1248. fprintf(stderr, "cannot represent time delta %x\n",
  1249. delta);
  1250. return -1;
  1251. }
  1252. if (out_format == OUT_FMT_FUNCTION) {
  1253. struct func_info *caller_func;
  1254. if (_DEBUG) {
  1255. fprintf(stderr, "%d: delta=%d, stamp=%ld\n",
  1256. upto, delta, timestamp);
  1257. fprintf(stderr,
  1258. " last_delta %x to %x: last_timestamp=%lx, "
  1259. "timestamp=%lx, call->flags=%x, upto=%d\n",
  1260. last_delta, delta, last_timestamp,
  1261. timestamp, call->flags, upto);
  1262. }
  1263. /* type_len is 6, meaning 4 * 6 = 24 bytes */
  1264. tw->ptr += tputl(fout, rec_words | (uint)delta << 5);
  1265. tw->ptr += tputh(fout, TRACE_FN);
  1266. tw->ptr += tputh(fout, 0); /* flags */
  1267. tw->ptr += tputl(fout, TRACE_PID); /* PID */
  1268. /* function */
  1269. tw->ptr += tputq(fout, text_offset + func->offset);
  1270. caller_func = find_caller_by_offset(call->caller);
  1271. /* caller */
  1272. tw->ptr += tputq(fout,
  1273. text_offset + caller_func->offset);
  1274. } else {
  1275. tw->ptr += tputl(fout, rec_words | delta << 5);
  1276. tw->ptr += tputh(fout, entry ? TRACE_GRAPH_ENT
  1277. : TRACE_GRAPH_RET);
  1278. tw->ptr += tputh(fout, 0); /* flags */
  1279. tw->ptr += tputl(fout, TRACE_PID); /* PID */
  1280. /* function */
  1281. tw->ptr += tputq(fout, text_offset + func->offset);
  1282. tw->ptr += tputl(fout, depth); /* depth */
  1283. if (entry) {
  1284. depth++;
  1285. if (stack_ptr < MAX_STACK_DEPTH)
  1286. func_stack[stack_ptr] = timestamp;
  1287. stack_ptr++;
  1288. } else {
  1289. ulong func_duration = 0;
  1290. depth--;
  1291. if (stack_ptr && stack_ptr <= MAX_STACK_DEPTH) {
  1292. ulong start = func_stack[--stack_ptr];
  1293. func_duration = timestamp - start;
  1294. }
  1295. tw->ptr += tputl(fout, 0); /* overrun */
  1296. tw->ptr += tputq(fout, 0); /* calltime */
  1297. /* rettime */
  1298. tw->ptr += tputq(fout, func_duration);
  1299. }
  1300. }
  1301. last_delta = delta;
  1302. last_timestamp = timestamp;
  1303. page_upto += 4 + rec_words * 4;
  1304. upto++;
  1305. if (stack_ptr == MAX_STACK_DEPTH)
  1306. break;
  1307. }
  1308. if (in_page && finish_page(tw))
  1309. return -1;
  1310. *missing_countp = missing_count;
  1311. *skip_countp = skip_count;
  1312. return 0;
  1313. }
  1314. /**
  1315. * write_flyrecord() - Write the flyrecord information
  1316. *
  1317. * Writes the header and pages of data for the "flyrecord" section. It also
  1318. * writes out the counter-type info, selecting "[local]"
  1319. *
  1320. * @tw: Writer context
  1321. * @out_format: Output format to use
  1322. * @missing_countp: Returns number of missing functions (not found in function
  1323. * list)
  1324. * @skip_countp: Returns number of skipped functions (excluded from trace)
  1325. *
  1326. * Returns: 0 on success, -ve on error
  1327. */
  1328. static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
  1329. int *missing_countp, int *skip_countp)
  1330. {
  1331. unsigned long long start, start_ofs, len;
  1332. int ret;
  1333. FILE *fout = tw->fout;
  1334. char str[200];
  1335. /* Record start pointer */
  1336. start_ofs = tw->ptr;
  1337. debug("Start of flyrecord header at: 0x%llx\n", start_ofs);
  1338. tw->ptr += fprintf(fout, "flyrecord%c", 0);
  1339. /* flyrecord\0 - allocated 10 bytes */
  1340. start_ofs += 10;
  1341. /*
  1342. * 8 bytes that are a 64-bit word containing the offset into the file
  1343. * that holds the data for the CPU.
  1344. *
  1345. * 8 bytes that are a 64-bit word containing the size of the CPU
  1346. * data at that offset.
  1347. */
  1348. start_ofs += 16;
  1349. snprintf(str, sizeof(str),
  1350. "[local] global counter uptime perf mono mono_raw boot x86-tsc\n");
  1351. len = strlen(str);
  1352. /* trace clock length - 8 bytes */
  1353. start_ofs += 8;
  1354. /* trace clock data */
  1355. start_ofs += len;
  1356. debug("Calculated flyrecord header end at: 0x%llx, trace clock len: 0x%llx\n",
  1357. start_ofs, len);
  1358. /* trace data */
  1359. start = ALIGN(start_ofs, TRACE_PAGE_SIZE);
  1360. tw->ptr += tputq(fout, start);
  1361. /* use a placeholder for the size */
  1362. ret = push_len(tw, start, "flyrecord", 8);
  1363. if (ret < 0)
  1364. return -1;
  1365. tw->ptr += ret;
  1366. tw->ptr += tputq(fout, len);
  1367. tw->ptr += tputs(fout, str);
  1368. debug("End of flyrecord header at: 0x%x, offset: 0x%llx\n",
  1369. tw->ptr, start);
  1370. debug("trace text base %lx, map file %lx\n", text_base, text_offset);
  1371. ret = write_pages(tw, out_format, missing_countp, skip_countp);
  1372. if (ret < 0) {
  1373. fprintf(stderr, "Cannot output pages\n");
  1374. return -1;
  1375. }
  1376. ret = pop_len(tw, "flyrecord");
  1377. if (ret < 0) {
  1378. fprintf(stderr, "Cannot finish flyrecord header\n");
  1379. return -1;
  1380. }
  1381. return 0;
  1382. }
  1383. /**
  1384. * make_ftrace() - Write out an ftrace file
  1385. *
  1386. * See here for format:
  1387. *
  1388. * https://github.com/rostedt/trace-cmd/blob/master/Documentation/trace-cmd/trace-cmd.dat.v7.5.txt
  1389. *
  1390. * @fout: Output file
  1391. * @out_format: Output format to use
  1392. * Returns: 0 on success, -ve on error
  1393. */
  1394. static int make_ftrace(FILE *fout, enum out_format_t out_format)
  1395. {
  1396. int missing_count, skip_count;
  1397. struct twriter tws, *tw = &tws;
  1398. int ret;
  1399. memset(tw, '\0', sizeof(*tw));
  1400. abuf_init(&tw->str_buf);
  1401. tw->fout = fout;
  1402. tw->ptr = 0;
  1403. ret = output_headers(tw);
  1404. if (ret < 0) {
  1405. fprintf(stderr, "Cannot output headers\n");
  1406. return -1;
  1407. }
  1408. /* number of event systems files */
  1409. tw->ptr += tputl(fout, 0);
  1410. ret = write_symbols(tw);
  1411. if (ret < 0) {
  1412. fprintf(stderr, "Cannot write symbols\n");
  1413. return -1;
  1414. }
  1415. ret = write_options(tw);
  1416. if (ret < 0) {
  1417. fprintf(stderr, "Cannot write options\n");
  1418. return -1;
  1419. }
  1420. ret = write_flyrecord(tw, out_format, &missing_count, &skip_count);
  1421. if (ret < 0) {
  1422. fprintf(stderr, "Cannot write flyrecord\n");
  1423. return -1;
  1424. }
  1425. info("ftrace: %d functions not found, %d excluded\n", missing_count,
  1426. skip_count);
  1427. return 0;
  1428. }
  1429. /**
  1430. * create_node() - Create a new node in the flamegraph tree
  1431. *
  1432. * @msg: Message to use for debugging if something goes wrong
  1433. * Returns: Pointer to newly created node, or NULL on error
  1434. */
  1435. static struct flame_node *create_node(const char *msg)
  1436. {
  1437. struct flame_node *node;
  1438. node = calloc(1, sizeof(*node));
  1439. if (!node) {
  1440. fprintf(stderr, "Out of memory for %s\n", msg);
  1441. return NULL;
  1442. }
  1443. INIT_LIST_HEAD(&node->child_head);
  1444. return node;
  1445. }
  1446. /**
  1447. * process_call(): Add a call to the flamegraph info
  1448. *
  1449. * For function calls, if this call stack has been seen before, this increments
  1450. * the call count, creating a new node if needed.
  1451. *
  1452. * For function returns, it adds up the time spent in this call stack,
  1453. * subtracting the time spent by child functions.
  1454. *
  1455. * @state: Current flamegraph state
  1456. * @entry: true if this is a function entry, false if a function exit
  1457. * @timestamp: Timestamp from the trace file (in microseconds)
  1458. * @func: Function that was called/returned from
  1459. *
  1460. * Returns: 0 on success, -ve on error
  1461. */
  1462. static int process_call(struct flame_state *state, bool entry, ulong timestamp,
  1463. struct func_info *func)
  1464. {
  1465. struct flame_node *node = state->node;
  1466. int stack_ptr = state->stack_ptr;
  1467. if (entry) {
  1468. struct flame_node *child, *chd;
  1469. /* see if we have this as a child node already */
  1470. child = NULL;
  1471. list_for_each_entry(chd, &node->child_head, sibling_node) {
  1472. if (chd->func == func) {
  1473. child = chd;
  1474. break;
  1475. }
  1476. }
  1477. if (!child) {
  1478. /* create a new node */
  1479. child = create_node("child");
  1480. if (!child)
  1481. return -1;
  1482. list_add_tail(&child->sibling_node, &node->child_head);
  1483. child->func = func;
  1484. child->parent = node;
  1485. state->nodes++;
  1486. }
  1487. debug("entry %s: move from %s to %s\n", func->name,
  1488. node->func ? node->func->name : "(root)",
  1489. child->func->name);
  1490. child->count++;
  1491. if (stack_ptr < MAX_STACK_DEPTH) {
  1492. state->stack[stack_ptr].timestamp = timestamp;
  1493. state->stack[stack_ptr].child_total = 0;
  1494. }
  1495. debug("%d: %20s: entry at %ld\n", stack_ptr, func->name,
  1496. timestamp);
  1497. stack_ptr++;
  1498. node = child;
  1499. } else if (node->parent) {
  1500. ulong total_duration = 0, child_duration = 0;
  1501. struct stack_info *stk;
  1502. debug("exit %s: move from %s to %s\n", func->name,
  1503. node->func->name, node->parent->func ?
  1504. node->parent->func->name : "(root)");
  1505. if (stack_ptr && stack_ptr <= MAX_STACK_DEPTH) {
  1506. stk = &state->stack[--stack_ptr];
  1507. /*
  1508. * get total duration of the function which just
  1509. * exited
  1510. */
  1511. total_duration = timestamp - stk->timestamp;
  1512. child_duration = stk->child_total;
  1513. if (stack_ptr)
  1514. state->stack[stack_ptr - 1].child_total += total_duration;
  1515. debug("%d: %20s: exit at %ld, total %ld, child %ld, child_total=%ld\n",
  1516. stack_ptr, func->name, timestamp,
  1517. total_duration, child_duration,
  1518. stk->child_total);
  1519. }
  1520. node->duration += total_duration - child_duration;
  1521. node = node->parent;
  1522. }
  1523. state->stack_ptr = stack_ptr;
  1524. state->node = node;
  1525. return 0;
  1526. }
  1527. /**
  1528. * make_flame_tree() - Create a tree of stack traces
  1529. *
  1530. * Set up a tree, with the root node having the top-level functions as children
  1531. * and the leaf nodes being leaf functions. Each node has a count of how many
  1532. * times this function appears in the trace
  1533. *
  1534. * @out_format: Output format to use
  1535. * @treep: Returns the resulting flamegraph tree
  1536. * Returns: 0 on success, -ve on error
  1537. */
  1538. static int make_flame_tree(enum out_format_t out_format,
  1539. struct flame_node **treep)
  1540. {
  1541. struct flame_state state;
  1542. struct flame_node *tree;
  1543. struct trace_call *call;
  1544. int i;
  1545. /* maintain a stack of start times, etc. for 'calling' functions */
  1546. state.stack_ptr = 0;
  1547. tree = create_node("tree");
  1548. if (!tree)
  1549. return -1;
  1550. state.node = tree;
  1551. state.nodes = 0;
  1552. for (i = 0, call = call_list; i < call_count; i++, call++) {
  1553. bool entry = TRACE_CALL_TYPE(call) == FUNCF_ENTRY;
  1554. ulong timestamp = call->flags & FUNCF_TIMESTAMP_MASK;
  1555. struct func_info *func;
  1556. func = find_func_by_offset(call->func);
  1557. if (!func) {
  1558. warn("Cannot find function at %lx\n",
  1559. text_offset + call->func);
  1560. continue;
  1561. }
  1562. if (process_call(&state, entry, timestamp, func))
  1563. return -1;
  1564. }
  1565. fprintf(stderr, "%d nodes\n", state.nodes);
  1566. *treep = tree;
  1567. return 0;
  1568. }
  1569. /**
  1570. * output_tree() - Output a flamegraph tree
  1571. *
  1572. * Writes the tree out to a file in a format suitable for flamegraph.pl
  1573. *
  1574. * This works by maintaining a string shared across all recursive calls. The
  1575. * function name for this node is added to the existing string, to make up the
  1576. * full call-stack description. For example, on entry, @str might contain:
  1577. *
  1578. * "initf_bootstage;bootstage_mark_name"
  1579. * ^ @base
  1580. *
  1581. * with @base pointing to the \0 at the end of the string. This function adds
  1582. * a ';' following by the name of the current function, e.g. "timer_get_boot_us"
  1583. * as well as the output value, to get the full line:
  1584. *
  1585. * initf_bootstage;bootstage_mark_name;timer_get_boot_us 123
  1586. *
  1587. * @fout: Output file
  1588. * @out_format: Output format to use
  1589. * @node: Node to output (pass the whole tree at first)
  1590. * @str: String to use to build the output line (e.g. 500 charas long)
  1591. * @maxlen: Maximum length of string
  1592. * @base: Current base position in the string
  1593. * @treep: Returns the resulting flamegraph tree
  1594. * Returns 0 if OK, -1 on error
  1595. */
  1596. static int output_tree(FILE *fout, enum out_format_t out_format,
  1597. const struct flame_node *node, char *str, int maxlen,
  1598. int base)
  1599. {
  1600. const struct flame_node *child;
  1601. int pos;
  1602. if (node->count) {
  1603. if (out_format == OUT_FMT_FLAMEGRAPH_CALLS) {
  1604. fprintf(fout, "%s %d\n", str, node->count);
  1605. } else {
  1606. /*
  1607. * Write out the number of microseconds used by this
  1608. * call stack. Since the time taken by child calls is
  1609. * subtracted from this total, it can reach 0, meaning
  1610. * that this function took no time beyond what its
  1611. * children used. For this case, write 1 rather than 0,
  1612. * so that this call stack appears in the flamegraph.
  1613. * This has the effect of inflating the timing slightly,
  1614. * but only by at most 1 microsecond per function,
  1615. * assuming that is the timestamp resolution
  1616. */
  1617. fprintf(fout, "%s %ld\n", str,
  1618. node->duration ? node->duration : 1);
  1619. }
  1620. }
  1621. pos = base;
  1622. if (pos)
  1623. str[pos++] = ';';
  1624. list_for_each_entry(child, &node->child_head, sibling_node) {
  1625. int len;
  1626. len = strlen(child->func->name);
  1627. if (pos + len + 1 >= maxlen) {
  1628. fprintf(stderr, "String too short (%d chars)\n",
  1629. maxlen);
  1630. return -1;
  1631. }
  1632. strcpy(str + pos, child->func->name);
  1633. if (output_tree(fout, out_format, child, str, maxlen,
  1634. pos + len))
  1635. return -1;
  1636. }
  1637. return 0;
  1638. }
  1639. /**
  1640. * make_flamegraph() - Write out a flame graph
  1641. *
  1642. * @fout: Output file
  1643. * @out_format: Output format to use, e.g. function counts or timing
  1644. * Returns 0 if OK, -1 on error
  1645. */
  1646. static int make_flamegraph(FILE *fout, enum out_format_t out_format)
  1647. {
  1648. struct flame_node *tree;
  1649. char str[500];
  1650. if (make_flame_tree(out_format, &tree))
  1651. return -1;
  1652. *str = '\0';
  1653. if (output_tree(fout, out_format, tree, str, sizeof(str), 0))
  1654. return -1;
  1655. return 0;
  1656. }
  1657. /**
  1658. * prof_tool() - Performs requested action
  1659. *
  1660. * @argc: Number of arguments (used to obtain the command
  1661. * @argv: List of arguments
  1662. * @trace_fname: Filename of input file (trace data from U-Boot)
  1663. * @map_fname: Filename of map file (System.map from U-Boot)
  1664. * @trace_config_fname: Trace-configuration file, or NULL if none
  1665. * @out_fname: Output filename
  1666. */
  1667. static int prof_tool(int argc, char *const argv[],
  1668. const char *trace_fname, const char *map_fname,
  1669. const char *trace_config_fname, const char *out_fname,
  1670. enum out_format_t out_format)
  1671. {
  1672. int err = 0;
  1673. if (read_map_file(map_fname))
  1674. return -1;
  1675. if (trace_fname && read_trace_file(trace_fname))
  1676. return -1;
  1677. if (trace_config_fname && read_trace_config_file(trace_config_fname))
  1678. return -1;
  1679. check_trace_config();
  1680. for (; argc; argc--, argv++) {
  1681. const char *cmd = *argv;
  1682. if (!strcmp(cmd, "dump-ftrace")) {
  1683. FILE *fout;
  1684. if (out_format != OUT_FMT_FUNCTION &&
  1685. out_format != OUT_FMT_FUNCGRAPH)
  1686. out_format = OUT_FMT_FUNCTION;
  1687. fout = fopen(out_fname, "w");
  1688. if (!fout) {
  1689. fprintf(stderr, "Cannot write file '%s'\n",
  1690. out_fname);
  1691. return -1;
  1692. }
  1693. err = make_ftrace(fout, out_format);
  1694. fclose(fout);
  1695. } else if (!strcmp(cmd, "dump-flamegraph")) {
  1696. FILE *fout;
  1697. if (out_format != OUT_FMT_FLAMEGRAPH_CALLS &&
  1698. out_format != OUT_FMT_FLAMEGRAPH_TIMING)
  1699. out_format = OUT_FMT_FLAMEGRAPH_CALLS;
  1700. fout = fopen(out_fname, "w");
  1701. if (!fout) {
  1702. fprintf(stderr, "Cannot write file '%s'\n",
  1703. out_fname);
  1704. return -1;
  1705. }
  1706. err = make_flamegraph(fout, out_format);
  1707. fclose(fout);
  1708. } else {
  1709. warn("Unknown command '%s'\n", cmd);
  1710. }
  1711. }
  1712. return err;
  1713. }
  1714. int main(int argc, char *argv[])
  1715. {
  1716. enum out_format_t out_format = OUT_FMT_DEFAULT;
  1717. const char *map_fname = "System.map";
  1718. const char *trace_fname = NULL;
  1719. const char *config_fname = NULL;
  1720. const char *out_fname = NULL;
  1721. int opt;
  1722. verbose = 2;
  1723. while ((opt = getopt(argc, argv, "c:f:m:o:t:v:")) != -1) {
  1724. switch (opt) {
  1725. case 'c':
  1726. config_fname = optarg;
  1727. break;
  1728. case 'f':
  1729. if (!strcmp("function", optarg)) {
  1730. out_format = OUT_FMT_FUNCTION;
  1731. } else if (!strcmp("funcgraph", optarg)) {
  1732. out_format = OUT_FMT_FUNCGRAPH;
  1733. } else if (!strcmp("calls", optarg)) {
  1734. out_format = OUT_FMT_FLAMEGRAPH_CALLS;
  1735. } else if (!strcmp("timing", optarg)) {
  1736. out_format = OUT_FMT_FLAMEGRAPH_TIMING;
  1737. } else {
  1738. fprintf(stderr,
  1739. "Invalid format: use function, funcgraph, calls, timing\n");
  1740. exit(1);
  1741. }
  1742. break;
  1743. case 'm':
  1744. map_fname = optarg;
  1745. break;
  1746. case 'o':
  1747. out_fname = optarg;
  1748. break;
  1749. case 't':
  1750. trace_fname = optarg;
  1751. break;
  1752. case 'v':
  1753. verbose = atoi(optarg);
  1754. break;
  1755. default:
  1756. usage();
  1757. }
  1758. }
  1759. argc -= optind; argv += optind;
  1760. if (argc < 1)
  1761. usage();
  1762. if (!out_fname || !map_fname || !trace_fname) {
  1763. fprintf(stderr,
  1764. "Must provide trace data, System.map file and output file\n");
  1765. usage();
  1766. }
  1767. debug("Debug enabled\n");
  1768. return prof_tool(argc, argv, trace_fname, map_fname, config_fname,
  1769. out_fname, out_format);
  1770. }