builtin-ftrace.c 48 KB

12345678910111213141516171819202122232425262728293031323334353637383940414243444546474849505152535455565758596061626364656667686970717273747576777879808182838485868788899091929394959697989910010110210310410510610710810911011111211311411511611711811912012112212312412512612712812913013113213313413513613713813914014114214314414514614714814915015115215315415515615715815916016116216316416516616716816917017117217317417517617717817918018118218318418518618718818919019119219319419519619719819920020120220320420520620720820921021121221321421521621721821922022122222322422522622722822923023123223323423523623723823924024124224324424524624724824925025125225325425525625725825926026126226326426526626726826927027127227327427527627727827928028128228328428528628728828929029129229329429529629729829930030130230330430530630730830931031131231331431531631731831932032132232332432532632732832933033133233333433533633733833934034134234334434534634734834935035135235335435535635735835936036136236336436536636736836937037137237337437537637737837938038138238338438538638738838939039139239339439539639739839940040140240340440540640740840941041141241341441541641741841942042142242342442542642742842943043143243343443543643743843944044144244344444544644744844945045145245345445545645745845946046146246346446546646746846947047147247347447547647747847948048148248348448548648748848949049149249349449549649749849950050150250350450550650750850951051151251351451551651751851952052152252352452552652752852953053153253353453553653753853954054154254354454554654754854955055155255355455555655755855956056156256356456556656756856957057157257357457557657757857958058158258358458558658758858959059159259359459559659759859960060160260360460560660760860961061161261361461561661761861962062162262362462562662762862963063163263363463563663763863964064164264364464564664764864965065165265365465565665765865966066166266366466566666766866967067167267367467567667767867968068168268368468568668768868969069169269369469569669769869970070170270370470570670770870971071171271371471571671771871972072172272372472572672772872973073173273373473573673773873974074174274374474574674774874975075175275375475575675775875976076176276376476576676776876977077177277377477577677777877978078178278378478578678778878979079179279379479579679779879980080180280380480580680780880981081181281381481581681781881982082182282382482582682782882983083183283383483583683783883984084184284384484584684784884985085185285385485585685785885986086186286386486586686786886987087187287387487587687787887988088188288388488588688788888989089189289389489589689789889990090190290390490590690790890991091191291391491591691791891992092192292392492592692792892993093193293393493593693793893994094194294394494594694794894995095195295395495595695795895996096196296396496596696796896997097197297397497597697797897998098198298398498598698798898999099199299399499599699799899910001001100210031004100510061007100810091010101110121013101410151016101710181019102010211022102310241025102610271028102910301031103210331034103510361037103810391040104110421043104410451046104710481049105010511052105310541055105610571058105910601061106210631064106510661067106810691070107110721073107410751076107710781079108010811082108310841085108610871088108910901091109210931094109510961097109810991100110111021103110411051106110711081109111011111112111311141115111611171118111911201121112211231124112511261127112811291130113111321133113411351136113711381139114011411142114311441145114611471148114911501151115211531154115511561157115811591160116111621163116411651166116711681169117011711172117311741175117611771178117911801181118211831184118511861187118811891190119111921193119411951196119711981199120012011202120312041205120612071208120912101211121212131214121512161217121812191220122112221223122412251226122712281229123012311232123312341235123612371238123912401241124212431244124512461247124812491250125112521253125412551256125712581259126012611262126312641265126612671268126912701271127212731274127512761277127812791280128112821283128412851286128712881289129012911292129312941295129612971298129913001301130213031304130513061307130813091310131113121313131413151316131713181319132013211322132313241325132613271328132913301331133213331334133513361337133813391340134113421343134413451346134713481349135013511352135313541355135613571358135913601361136213631364136513661367136813691370137113721373137413751376137713781379138013811382138313841385138613871388138913901391139213931394139513961397139813991400140114021403140414051406140714081409141014111412141314141415141614171418141914201421142214231424142514261427142814291430143114321433143414351436143714381439144014411442144314441445144614471448144914501451145214531454145514561457145814591460146114621463146414651466146714681469147014711472147314741475147614771478147914801481148214831484148514861487148814891490149114921493149414951496149714981499150015011502150315041505150615071508150915101511151215131514151515161517151815191520152115221523152415251526152715281529153015311532153315341535153615371538153915401541154215431544154515461547154815491550155115521553155415551556155715581559156015611562156315641565156615671568156915701571157215731574157515761577157815791580158115821583158415851586158715881589159015911592159315941595159615971598159916001601160216031604160516061607160816091610161116121613161416151616161716181619162016211622162316241625162616271628162916301631163216331634163516361637163816391640164116421643164416451646164716481649165016511652165316541655165616571658165916601661166216631664166516661667166816691670167116721673167416751676167716781679168016811682168316841685168616871688168916901691169216931694169516961697169816991700170117021703170417051706170717081709171017111712171317141715171617171718171917201721172217231724172517261727172817291730173117321733173417351736173717381739174017411742174317441745174617471748174917501751175217531754175517561757175817591760176117621763176417651766176717681769177017711772177317741775177617771778177917801781178217831784178517861787178817891790179117921793179417951796179717981799180018011802180318041805180618071808180918101811181218131814181518161817181818191820182118221823182418251826182718281829183018311832183318341835183618371838183918401841184218431844184518461847184818491850185118521853185418551856185718581859186018611862186318641865186618671868186918701871187218731874187518761877187818791880188118821883188418851886188718881889189018911892189318941895189618971898189919001901190219031904190519061907190819091910191119121913191419151916191719181919192019211922192319241925192619271928192919301931193219331934193519361937193819391940194119421943194419451946194719481949195019511952195319541955195619571958195919601961196219631964196519661967196819691970197119721973197419751976197719781979198019811982198319841985198619871988198919901991199219931994199519961997199819992000200120022003200420052006200720082009201020112012201320142015201620172018201920202021202220232024
  1. // SPDX-License-Identifier: GPL-2.0-only
  2. /*
  3. * builtin-ftrace.c
  4. *
  5. * Copyright (c) 2013 LG Electronics, Namhyung Kim <namhyung@kernel.org>
  6. * Copyright (c) 2020 Changbin Du <changbin.du@gmail.com>, significant enhancement.
  7. */
  8. #include "builtin.h"
  9. #include <errno.h>
  10. #include <unistd.h>
  11. #include <signal.h>
  12. #include <stdlib.h>
  13. #include <fcntl.h>
  14. #include <inttypes.h>
  15. #include <math.h>
  16. #include <poll.h>
  17. #include <ctype.h>
  18. #include <linux/capability.h>
  19. #include <linux/err.h>
  20. #include <linux/string.h>
  21. #include <sys/stat.h>
  22. #include "debug.h"
  23. #include <subcmd/pager.h>
  24. #include <subcmd/parse-options.h>
  25. #include <api/io.h>
  26. #include <api/fs/tracing_path.h>
  27. #include "evlist.h"
  28. #include "target.h"
  29. #include "cpumap.h"
  30. #include "hashmap.h"
  31. #include "thread_map.h"
  32. #include "strfilter.h"
  33. #include "util/cap.h"
  34. #include "util/config.h"
  35. #include "util/ftrace.h"
  36. #include "util/stat.h"
  37. #include "util/units.h"
  38. #include "util/parse-sublevel-options.h"
  39. #define DEFAULT_TRACER "function_graph"
  40. static volatile sig_atomic_t workload_exec_errno;
  41. static volatile sig_atomic_t done;
  42. static struct stats latency_stats; /* for tracepoints */
  43. static char tracing_instance[PATH_MAX]; /* Trace instance directory */
  44. static void sig_handler(int sig __maybe_unused)
  45. {
  46. done = true;
  47. }
  48. /*
  49. * evlist__prepare_workload will send a SIGUSR1 if the fork fails, since
  50. * we asked by setting its exec_error to the function below,
  51. * ftrace__workload_exec_failed_signal.
  52. *
  53. * XXX We need to handle this more appropriately, emitting an error, etc.
  54. */
  55. static void ftrace__workload_exec_failed_signal(int signo __maybe_unused,
  56. siginfo_t *info __maybe_unused,
  57. void *ucontext __maybe_unused)
  58. {
  59. workload_exec_errno = info->si_value.sival_int;
  60. done = true;
  61. }
  62. static bool check_ftrace_capable(void)
  63. {
  64. bool used_root;
  65. if (perf_cap__capable(CAP_PERFMON, &used_root))
  66. return true;
  67. if (!used_root && perf_cap__capable(CAP_SYS_ADMIN, &used_root))
  68. return true;
  69. pr_err("ftrace only works for %s!\n",
  70. used_root ? "root"
  71. : "users with the CAP_PERFMON or CAP_SYS_ADMIN capability"
  72. );
  73. return false;
  74. }
  75. static bool is_ftrace_supported(void)
  76. {
  77. char *file;
  78. bool supported = false;
  79. file = get_tracing_file("set_ftrace_pid");
  80. if (!file) {
  81. pr_debug("cannot get tracing file set_ftrace_pid\n");
  82. return false;
  83. }
  84. if (!access(file, F_OK))
  85. supported = true;
  86. put_tracing_file(file);
  87. return supported;
  88. }
  89. /*
  90. * Wrapper to test if a file in directory .../tracing/instances/XXX
  91. * exists. If so return the .../tracing/instances/XXX file for use.
  92. * Otherwise the file exists only in directory .../tracing and
  93. * is applicable to all instances, for example file available_filter_functions.
  94. * Return that file name in this case.
  95. *
  96. * This functions works similar to get_tracing_file() and expects its caller
  97. * to free the returned file name.
  98. *
  99. * The global variable tracing_instance is set in init_tracing_instance()
  100. * called at the beginning to a process specific tracing subdirectory.
  101. */
  102. static char *get_tracing_instance_file(const char *name)
  103. {
  104. char *file;
  105. if (asprintf(&file, "%s/%s", tracing_instance, name) < 0)
  106. return NULL;
  107. if (!access(file, F_OK))
  108. return file;
  109. free(file);
  110. file = get_tracing_file(name);
  111. return file;
  112. }
  113. static int __write_tracing_file(const char *name, const char *val, bool append)
  114. {
  115. char *file;
  116. int fd, ret = -1;
  117. ssize_t size = strlen(val);
  118. int flags = O_WRONLY;
  119. char errbuf[512];
  120. char *val_copy;
  121. file = get_tracing_instance_file(name);
  122. if (!file) {
  123. pr_debug("cannot get tracing file: %s\n", name);
  124. return -1;
  125. }
  126. if (append)
  127. flags |= O_APPEND;
  128. else
  129. flags |= O_TRUNC;
  130. fd = open(file, flags);
  131. if (fd < 0) {
  132. pr_debug("cannot open tracing file: %s: %s\n",
  133. name, str_error_r(errno, errbuf, sizeof(errbuf)));
  134. goto out;
  135. }
  136. /*
  137. * Copy the original value and append a '\n'. Without this,
  138. * the kernel can hide possible errors.
  139. */
  140. val_copy = strdup(val);
  141. if (!val_copy)
  142. goto out_close;
  143. val_copy[size] = '\n';
  144. if (write(fd, val_copy, size + 1) == size + 1)
  145. ret = 0;
  146. else
  147. pr_debug("write '%s' to tracing/%s failed: %s\n",
  148. val, name, str_error_r(errno, errbuf, sizeof(errbuf)));
  149. free(val_copy);
  150. out_close:
  151. close(fd);
  152. out:
  153. put_tracing_file(file);
  154. return ret;
  155. }
  156. static int write_tracing_file(const char *name, const char *val)
  157. {
  158. return __write_tracing_file(name, val, false);
  159. }
  160. static int append_tracing_file(const char *name, const char *val)
  161. {
  162. return __write_tracing_file(name, val, true);
  163. }
  164. static int read_tracing_file_to_stdout(const char *name)
  165. {
  166. char buf[4096];
  167. char *file;
  168. int fd;
  169. int ret = -1;
  170. file = get_tracing_instance_file(name);
  171. if (!file) {
  172. pr_debug("cannot get tracing file: %s\n", name);
  173. return -1;
  174. }
  175. fd = open(file, O_RDONLY);
  176. if (fd < 0) {
  177. pr_debug("cannot open tracing file: %s: %s\n",
  178. name, str_error_r(errno, buf, sizeof(buf)));
  179. goto out;
  180. }
  181. /* read contents to stdout */
  182. while (true) {
  183. int n = read(fd, buf, sizeof(buf));
  184. if (n == 0)
  185. break;
  186. else if (n < 0)
  187. goto out_close;
  188. if (fwrite(buf, n, 1, stdout) != 1)
  189. goto out_close;
  190. }
  191. ret = 0;
  192. out_close:
  193. close(fd);
  194. out:
  195. put_tracing_file(file);
  196. return ret;
  197. }
  198. static int read_tracing_file_by_line(const char *name,
  199. void (*cb)(char *str, void *arg),
  200. void *cb_arg)
  201. {
  202. char *line = NULL;
  203. size_t len = 0;
  204. char *file;
  205. FILE *fp;
  206. file = get_tracing_instance_file(name);
  207. if (!file) {
  208. pr_debug("cannot get tracing file: %s\n", name);
  209. return -1;
  210. }
  211. fp = fopen(file, "r");
  212. if (fp == NULL) {
  213. pr_debug("cannot open tracing file: %s\n", name);
  214. put_tracing_file(file);
  215. return -1;
  216. }
  217. while (getline(&line, &len, fp) != -1) {
  218. cb(line, cb_arg);
  219. }
  220. if (line)
  221. free(line);
  222. fclose(fp);
  223. put_tracing_file(file);
  224. return 0;
  225. }
  226. static int write_tracing_file_int(const char *name, int value)
  227. {
  228. char buf[16];
  229. snprintf(buf, sizeof(buf), "%d", value);
  230. if (write_tracing_file(name, buf) < 0)
  231. return -1;
  232. return 0;
  233. }
  234. static int write_tracing_option_file(const char *name, const char *val)
  235. {
  236. char *file;
  237. int ret;
  238. if (asprintf(&file, "options/%s", name) < 0)
  239. return -1;
  240. ret = __write_tracing_file(file, val, false);
  241. free(file);
  242. return ret;
  243. }
  244. static int reset_tracing_cpu(void);
  245. static void reset_tracing_filters(void);
  246. static void reset_tracing_options(struct perf_ftrace *ftrace __maybe_unused)
  247. {
  248. write_tracing_option_file("function-fork", "0");
  249. write_tracing_option_file("func_stack_trace", "0");
  250. write_tracing_option_file("sleep-time", "1");
  251. write_tracing_option_file("funcgraph-irqs", "1");
  252. write_tracing_option_file("funcgraph-proc", "0");
  253. write_tracing_option_file("funcgraph-abstime", "0");
  254. write_tracing_option_file("funcgraph-tail", "0");
  255. write_tracing_option_file("funcgraph-args", "0");
  256. write_tracing_option_file("funcgraph-retval", "0");
  257. write_tracing_option_file("funcgraph-retval-hex", "0");
  258. write_tracing_option_file("funcgraph-retaddr", "0");
  259. write_tracing_option_file("latency-format", "0");
  260. write_tracing_option_file("irq-info", "0");
  261. }
  262. static int reset_tracing_files(struct perf_ftrace *ftrace __maybe_unused)
  263. {
  264. if (write_tracing_file("tracing_on", "0") < 0)
  265. return -1;
  266. if (write_tracing_file("current_tracer", "nop") < 0)
  267. return -1;
  268. if (write_tracing_file("set_ftrace_pid", " ") < 0)
  269. return -1;
  270. if (reset_tracing_cpu() < 0)
  271. return -1;
  272. if (write_tracing_file("max_graph_depth", "0") < 0)
  273. return -1;
  274. if (write_tracing_file("tracing_thresh", "0") < 0)
  275. return -1;
  276. reset_tracing_filters();
  277. reset_tracing_options(ftrace);
  278. return 0;
  279. }
  280. /* Remove .../tracing/instances/XXX subdirectory created with
  281. * init_tracing_instance().
  282. */
  283. static void exit_tracing_instance(void)
  284. {
  285. if (rmdir(tracing_instance))
  286. pr_err("failed to delete tracing/instances directory\n");
  287. }
  288. /* Create subdirectory within .../tracing/instances/XXX to have session
  289. * or process specific setup. To delete this setup, simply remove the
  290. * subdirectory.
  291. */
  292. static int init_tracing_instance(void)
  293. {
  294. char dirname[] = "instances/perf-ftrace-XXXXXX";
  295. char *path;
  296. path = get_tracing_file(dirname);
  297. if (!path)
  298. goto error;
  299. strncpy(tracing_instance, path, sizeof(tracing_instance) - 1);
  300. put_tracing_file(path);
  301. path = mkdtemp(tracing_instance);
  302. if (!path)
  303. goto error;
  304. return 0;
  305. error:
  306. pr_err("failed to create tracing/instances directory\n");
  307. return -1;
  308. }
  309. static int set_tracing_pid(struct perf_ftrace *ftrace)
  310. {
  311. int i;
  312. char buf[16];
  313. if (target__has_cpu(&ftrace->target))
  314. return 0;
  315. for (i = 0; i < perf_thread_map__nr(ftrace->evlist->core.threads); i++) {
  316. scnprintf(buf, sizeof(buf), "%d",
  317. perf_thread_map__pid(ftrace->evlist->core.threads, i));
  318. if (append_tracing_file("set_ftrace_pid", buf) < 0)
  319. return -1;
  320. }
  321. return 0;
  322. }
  323. static int set_tracing_cpumask(struct perf_cpu_map *cpumap)
  324. {
  325. char *cpumask;
  326. size_t mask_size;
  327. int ret;
  328. int last_cpu;
  329. last_cpu = perf_cpu_map__cpu(cpumap, perf_cpu_map__nr(cpumap) - 1).cpu;
  330. mask_size = last_cpu / 4 + 2; /* one more byte for EOS */
  331. mask_size += last_cpu / 32; /* ',' is needed for every 32th cpus */
  332. cpumask = malloc(mask_size);
  333. if (cpumask == NULL) {
  334. pr_debug("failed to allocate cpu mask\n");
  335. return -1;
  336. }
  337. cpu_map__snprint_mask(cpumap, cpumask, mask_size);
  338. ret = write_tracing_file("tracing_cpumask", cpumask);
  339. free(cpumask);
  340. return ret;
  341. }
  342. static int set_tracing_cpu(struct perf_ftrace *ftrace)
  343. {
  344. struct perf_cpu_map *cpumap = ftrace->evlist->core.user_requested_cpus;
  345. if (!target__has_cpu(&ftrace->target))
  346. return 0;
  347. return set_tracing_cpumask(cpumap);
  348. }
  349. static int set_tracing_func_stack_trace(struct perf_ftrace *ftrace)
  350. {
  351. if (!ftrace->func_stack_trace)
  352. return 0;
  353. if (write_tracing_option_file("func_stack_trace", "1") < 0)
  354. return -1;
  355. return 0;
  356. }
  357. static int set_tracing_func_irqinfo(struct perf_ftrace *ftrace)
  358. {
  359. if (!ftrace->func_irq_info)
  360. return 0;
  361. if (write_tracing_option_file("irq-info", "1") < 0)
  362. return -1;
  363. return 0;
  364. }
  365. static int reset_tracing_cpu(void)
  366. {
  367. struct perf_cpu_map *cpumap = perf_cpu_map__new_online_cpus();
  368. int ret;
  369. ret = set_tracing_cpumask(cpumap);
  370. perf_cpu_map__put(cpumap);
  371. return ret;
  372. }
  373. static int __set_tracing_filter(const char *filter_file, struct list_head *funcs)
  374. {
  375. struct filter_entry *pos;
  376. list_for_each_entry(pos, funcs, list) {
  377. if (append_tracing_file(filter_file, pos->name) < 0)
  378. return -1;
  379. }
  380. return 0;
  381. }
  382. static int set_tracing_filters(struct perf_ftrace *ftrace)
  383. {
  384. int ret;
  385. ret = __set_tracing_filter("set_ftrace_filter", &ftrace->filters);
  386. if (ret < 0)
  387. return ret;
  388. ret = __set_tracing_filter("set_ftrace_notrace", &ftrace->notrace);
  389. if (ret < 0)
  390. return ret;
  391. ret = __set_tracing_filter("set_graph_function", &ftrace->graph_funcs);
  392. if (ret < 0)
  393. return ret;
  394. /* old kernels do not have this filter */
  395. __set_tracing_filter("set_graph_notrace", &ftrace->nograph_funcs);
  396. return ret;
  397. }
  398. static void reset_tracing_filters(void)
  399. {
  400. write_tracing_file("set_ftrace_filter", " ");
  401. write_tracing_file("set_ftrace_notrace", " ");
  402. write_tracing_file("set_graph_function", " ");
  403. write_tracing_file("set_graph_notrace", " ");
  404. }
  405. static int set_tracing_depth(struct perf_ftrace *ftrace)
  406. {
  407. if (ftrace->graph_depth == 0)
  408. return 0;
  409. if (ftrace->graph_depth < 0) {
  410. pr_err("invalid graph depth: %d\n", ftrace->graph_depth);
  411. return -1;
  412. }
  413. if (write_tracing_file_int("max_graph_depth", ftrace->graph_depth) < 0)
  414. return -1;
  415. return 0;
  416. }
  417. static int set_tracing_percpu_buffer_size(struct perf_ftrace *ftrace)
  418. {
  419. int ret;
  420. if (ftrace->percpu_buffer_size == 0)
  421. return 0;
  422. ret = write_tracing_file_int("buffer_size_kb",
  423. ftrace->percpu_buffer_size / 1024);
  424. if (ret < 0)
  425. return ret;
  426. return 0;
  427. }
  428. static int set_tracing_trace_inherit(struct perf_ftrace *ftrace)
  429. {
  430. if (!ftrace->inherit)
  431. return 0;
  432. if (write_tracing_option_file("function-fork", "1") < 0)
  433. return -1;
  434. return 0;
  435. }
  436. static int set_tracing_sleep_time(struct perf_ftrace *ftrace)
  437. {
  438. if (!ftrace->graph_nosleep_time)
  439. return 0;
  440. if (write_tracing_option_file("sleep-time", "0") < 0)
  441. return -1;
  442. return 0;
  443. }
  444. static int set_tracing_funcgraph_args(struct perf_ftrace *ftrace)
  445. {
  446. if (ftrace->graph_args) {
  447. if (write_tracing_option_file("funcgraph-args", "1") < 0)
  448. return -1;
  449. }
  450. return 0;
  451. }
  452. static int set_tracing_funcgraph_retval(struct perf_ftrace *ftrace)
  453. {
  454. if (ftrace->graph_retval || ftrace->graph_retval_hex) {
  455. if (write_tracing_option_file("funcgraph-retval", "1") < 0)
  456. return -1;
  457. }
  458. if (ftrace->graph_retval_hex) {
  459. if (write_tracing_option_file("funcgraph-retval-hex", "1") < 0)
  460. return -1;
  461. }
  462. return 0;
  463. }
  464. static int set_tracing_funcgraph_retaddr(struct perf_ftrace *ftrace)
  465. {
  466. if (ftrace->graph_retaddr) {
  467. if (write_tracing_option_file("funcgraph-retaddr", "1") < 0)
  468. return -1;
  469. }
  470. return 0;
  471. }
  472. static int set_tracing_funcgraph_irqs(struct perf_ftrace *ftrace)
  473. {
  474. if (!ftrace->graph_noirqs)
  475. return 0;
  476. if (write_tracing_option_file("funcgraph-irqs", "0") < 0)
  477. return -1;
  478. return 0;
  479. }
  480. static int set_tracing_funcgraph_verbose(struct perf_ftrace *ftrace)
  481. {
  482. if (!ftrace->graph_verbose)
  483. return 0;
  484. if (write_tracing_option_file("funcgraph-proc", "1") < 0)
  485. return -1;
  486. if (write_tracing_option_file("funcgraph-abstime", "1") < 0)
  487. return -1;
  488. if (write_tracing_option_file("latency-format", "1") < 0)
  489. return -1;
  490. return 0;
  491. }
  492. static int set_tracing_funcgraph_tail(struct perf_ftrace *ftrace)
  493. {
  494. if (!ftrace->graph_tail)
  495. return 0;
  496. if (write_tracing_option_file("funcgraph-tail", "1") < 0)
  497. return -1;
  498. return 0;
  499. }
  500. static int set_tracing_thresh(struct perf_ftrace *ftrace)
  501. {
  502. int ret;
  503. if (ftrace->graph_thresh == 0)
  504. return 0;
  505. ret = write_tracing_file_int("tracing_thresh", ftrace->graph_thresh);
  506. if (ret < 0)
  507. return ret;
  508. return 0;
  509. }
  510. static int set_tracing_options(struct perf_ftrace *ftrace)
  511. {
  512. if (set_tracing_pid(ftrace) < 0) {
  513. pr_err("failed to set ftrace pid\n");
  514. return -1;
  515. }
  516. if (set_tracing_cpu(ftrace) < 0) {
  517. pr_err("failed to set tracing cpumask\n");
  518. return -1;
  519. }
  520. if (set_tracing_func_stack_trace(ftrace) < 0) {
  521. pr_err("failed to set tracing option func_stack_trace\n");
  522. return -1;
  523. }
  524. if (set_tracing_func_irqinfo(ftrace) < 0) {
  525. pr_err("failed to set tracing option irq-info\n");
  526. return -1;
  527. }
  528. if (set_tracing_filters(ftrace) < 0) {
  529. pr_err("failed to set tracing filters\n");
  530. return -1;
  531. }
  532. if (set_tracing_depth(ftrace) < 0) {
  533. pr_err("failed to set graph depth\n");
  534. return -1;
  535. }
  536. if (set_tracing_percpu_buffer_size(ftrace) < 0) {
  537. pr_err("failed to set tracing per-cpu buffer size\n");
  538. return -1;
  539. }
  540. if (set_tracing_trace_inherit(ftrace) < 0) {
  541. pr_err("failed to set tracing option function-fork\n");
  542. return -1;
  543. }
  544. if (set_tracing_sleep_time(ftrace) < 0) {
  545. pr_err("failed to set tracing option sleep-time\n");
  546. return -1;
  547. }
  548. if (set_tracing_funcgraph_args(ftrace) < 0) {
  549. pr_err("failed to set tracing option funcgraph-args\n");
  550. return -1;
  551. }
  552. if (set_tracing_funcgraph_retval(ftrace) < 0) {
  553. pr_err("failed to set tracing option funcgraph-retval\n");
  554. return -1;
  555. }
  556. if (set_tracing_funcgraph_retaddr(ftrace) < 0) {
  557. pr_err("failed to set tracing option funcgraph-retaddr\n");
  558. return -1;
  559. }
  560. if (set_tracing_funcgraph_irqs(ftrace) < 0) {
  561. pr_err("failed to set tracing option funcgraph-irqs\n");
  562. return -1;
  563. }
  564. if (set_tracing_funcgraph_verbose(ftrace) < 0) {
  565. pr_err("failed to set tracing option funcgraph-proc/funcgraph-abstime\n");
  566. return -1;
  567. }
  568. if (set_tracing_thresh(ftrace) < 0) {
  569. pr_err("failed to set tracing thresh\n");
  570. return -1;
  571. }
  572. if (set_tracing_funcgraph_tail(ftrace) < 0) {
  573. pr_err("failed to set tracing option funcgraph-tail\n");
  574. return -1;
  575. }
  576. return 0;
  577. }
  578. static void select_tracer(struct perf_ftrace *ftrace)
  579. {
  580. bool graph = !list_empty(&ftrace->graph_funcs) ||
  581. !list_empty(&ftrace->nograph_funcs);
  582. bool func = !list_empty(&ftrace->filters) ||
  583. !list_empty(&ftrace->notrace);
  584. /* The function_graph has priority over function tracer. */
  585. if (graph)
  586. ftrace->tracer = "function_graph";
  587. else if (func)
  588. ftrace->tracer = "function";
  589. /* Otherwise, the default tracer is used. */
  590. pr_debug("%s tracer is used\n", ftrace->tracer);
  591. }
  592. static int __cmd_ftrace(struct perf_ftrace *ftrace)
  593. {
  594. char *trace_file;
  595. int trace_fd;
  596. char buf[4096];
  597. struct pollfd pollfd = {
  598. .events = POLLIN,
  599. };
  600. select_tracer(ftrace);
  601. if (init_tracing_instance() < 0)
  602. goto out;
  603. if (reset_tracing_files(ftrace) < 0) {
  604. pr_err("failed to reset ftrace\n");
  605. goto out_reset;
  606. }
  607. /* reset ftrace buffer */
  608. if (write_tracing_file("trace", "0") < 0)
  609. goto out_reset;
  610. if (set_tracing_options(ftrace) < 0)
  611. goto out_reset;
  612. if (write_tracing_file("current_tracer", ftrace->tracer) < 0) {
  613. pr_err("failed to set current_tracer to %s\n", ftrace->tracer);
  614. goto out_reset;
  615. }
  616. setup_pager();
  617. trace_file = get_tracing_instance_file("trace_pipe");
  618. if (!trace_file) {
  619. pr_err("failed to open trace_pipe\n");
  620. goto out_reset;
  621. }
  622. trace_fd = open(trace_file, O_RDONLY);
  623. put_tracing_file(trace_file);
  624. if (trace_fd < 0) {
  625. pr_err("failed to open trace_pipe\n");
  626. goto out_reset;
  627. }
  628. fcntl(trace_fd, F_SETFL, O_NONBLOCK);
  629. pollfd.fd = trace_fd;
  630. /* display column headers */
  631. read_tracing_file_to_stdout("trace");
  632. if (!ftrace->target.initial_delay) {
  633. if (write_tracing_file("tracing_on", "1") < 0) {
  634. pr_err("can't enable tracing\n");
  635. goto out_close_fd;
  636. }
  637. }
  638. evlist__start_workload(ftrace->evlist);
  639. if (ftrace->target.initial_delay > 0) {
  640. usleep(ftrace->target.initial_delay * 1000);
  641. if (write_tracing_file("tracing_on", "1") < 0) {
  642. pr_err("can't enable tracing\n");
  643. goto out_close_fd;
  644. }
  645. }
  646. while (!done) {
  647. if (poll(&pollfd, 1, -1) < 0)
  648. break;
  649. if (pollfd.revents & POLLIN) {
  650. int n = read(trace_fd, buf, sizeof(buf));
  651. if (n < 0)
  652. break;
  653. if (fwrite(buf, n, 1, stdout) != 1)
  654. break;
  655. /* flush output since stdout is in full buffering mode due to pager */
  656. fflush(stdout);
  657. }
  658. }
  659. write_tracing_file("tracing_on", "0");
  660. if (workload_exec_errno) {
  661. const char *emsg = str_error_r(workload_exec_errno, buf, sizeof(buf));
  662. /* flush stdout first so below error msg appears at the end. */
  663. fflush(stdout);
  664. pr_err("workload failed: %s\n", emsg);
  665. goto out_close_fd;
  666. }
  667. /* read remaining buffer contents */
  668. while (true) {
  669. int n = read(trace_fd, buf, sizeof(buf));
  670. if (n <= 0)
  671. break;
  672. if (fwrite(buf, n, 1, stdout) != 1)
  673. break;
  674. }
  675. out_close_fd:
  676. close(trace_fd);
  677. out_reset:
  678. exit_tracing_instance();
  679. out:
  680. return (done && !workload_exec_errno) ? 0 : -1;
  681. }
  682. static void make_histogram(struct perf_ftrace *ftrace, int buckets[],
  683. char *buf, size_t len, char *linebuf)
  684. {
  685. int min_latency = ftrace->min_latency;
  686. int max_latency = ftrace->max_latency;
  687. unsigned int bucket_num = ftrace->bucket_num;
  688. char *p, *q;
  689. char *unit;
  690. double num;
  691. int i;
  692. /* ensure NUL termination */
  693. buf[len] = '\0';
  694. /* handle data line by line */
  695. for (p = buf; (q = strchr(p, '\n')) != NULL; p = q + 1) {
  696. *q = '\0';
  697. /* move it to the line buffer */
  698. strcat(linebuf, p);
  699. /*
  700. * parse trace output to get function duration like in
  701. *
  702. * # tracer: function_graph
  703. * #
  704. * # CPU DURATION FUNCTION CALLS
  705. * # | | | | | | |
  706. * 1) + 10.291 us | do_filp_open();
  707. * 1) 4.889 us | do_filp_open();
  708. * 1) 6.086 us | do_filp_open();
  709. *
  710. */
  711. if (linebuf[0] == '#')
  712. goto next;
  713. /* ignore CPU */
  714. p = strchr(linebuf, ')');
  715. if (p == NULL)
  716. p = linebuf;
  717. while (*p && !isdigit(*p) && (*p != '|'))
  718. p++;
  719. /* no duration */
  720. if (*p == '\0' || *p == '|')
  721. goto next;
  722. num = strtod(p, &unit);
  723. if (!unit || strncmp(unit, " us", 3))
  724. goto next;
  725. if (ftrace->use_nsec)
  726. num *= 1000;
  727. i = 0;
  728. if (num < min_latency)
  729. goto do_inc;
  730. num -= min_latency;
  731. if (!ftrace->bucket_range) {
  732. i = log2(num);
  733. if (i < 0)
  734. i = 0;
  735. } else {
  736. // Less than 1 unit (ms or ns), or, in the future,
  737. // than the min latency desired.
  738. if (num > 0) // 1st entry: [ 1 unit .. bucket_range units ]
  739. i = num / ftrace->bucket_range + 1;
  740. if (num >= max_latency - min_latency)
  741. i = bucket_num -1;
  742. }
  743. if ((unsigned)i >= bucket_num)
  744. i = bucket_num - 1;
  745. num += min_latency;
  746. do_inc:
  747. buckets[i]++;
  748. update_stats(&latency_stats, num);
  749. next:
  750. /* empty the line buffer for the next output */
  751. linebuf[0] = '\0';
  752. }
  753. /* preserve any remaining output (before newline) */
  754. strcat(linebuf, p);
  755. }
  756. static void display_histogram(struct perf_ftrace *ftrace, int buckets[])
  757. {
  758. int min_latency = ftrace->min_latency;
  759. bool use_nsec = ftrace->use_nsec;
  760. unsigned int bucket_num = ftrace->bucket_num;
  761. unsigned int i;
  762. int total = 0;
  763. int bar_total = 46; /* to fit in 80 column */
  764. char bar[] = "###############################################";
  765. int bar_len;
  766. for (i = 0; i < bucket_num; i++)
  767. total += buckets[i];
  768. if (total == 0) {
  769. printf("No data found\n");
  770. return;
  771. }
  772. printf("# %14s | %10s | %-*s |\n",
  773. " DURATION ", "COUNT", bar_total, "GRAPH");
  774. bar_len = buckets[0] * bar_total / total;
  775. if (!ftrace->hide_empty || buckets[0])
  776. printf(" %4d - %4d %s | %10d | %.*s%*s |\n",
  777. 0, min_latency ?: 1, use_nsec ? "ns" : "us",
  778. buckets[0], bar_len, bar, bar_total - bar_len, "");
  779. for (i = 1; i < bucket_num - 1; i++) {
  780. unsigned int start, stop;
  781. const char *unit = use_nsec ? "ns" : "us";
  782. if (ftrace->hide_empty && !buckets[i])
  783. continue;
  784. if (!ftrace->bucket_range) {
  785. start = (1 << (i - 1));
  786. stop = 1 << i;
  787. if (start >= 1024) {
  788. start >>= 10;
  789. stop >>= 10;
  790. unit = use_nsec ? "us" : "ms";
  791. }
  792. } else {
  793. start = (i - 1) * ftrace->bucket_range + min_latency;
  794. stop = i * ftrace->bucket_range + min_latency;
  795. if (start >= ftrace->max_latency)
  796. break;
  797. if (stop > ftrace->max_latency)
  798. stop = ftrace->max_latency;
  799. if (start >= 1000) {
  800. double dstart = start / 1000.0,
  801. dstop = stop / 1000.0;
  802. printf(" %4.2f - %-4.2f", dstart, dstop);
  803. unit = use_nsec ? "us" : "ms";
  804. goto print_bucket_info;
  805. }
  806. }
  807. printf(" %4d - %4d", start, stop);
  808. print_bucket_info:
  809. bar_len = buckets[i] * bar_total / total;
  810. printf(" %s | %10d | %.*s%*s |\n", unit, buckets[i], bar_len, bar,
  811. bar_total - bar_len, "");
  812. }
  813. bar_len = buckets[bucket_num - 1] * bar_total / total;
  814. if (ftrace->hide_empty && !buckets[bucket_num - 1])
  815. goto print_stats;
  816. if (!ftrace->bucket_range) {
  817. printf(" %4d - %-4s %s", 1, "...", use_nsec ? "ms" : "s ");
  818. } else {
  819. unsigned int upper_outlier = (bucket_num - 2) * ftrace->bucket_range + min_latency;
  820. if (upper_outlier > ftrace->max_latency)
  821. upper_outlier = ftrace->max_latency;
  822. if (upper_outlier >= 1000) {
  823. double dstart = upper_outlier / 1000.0;
  824. printf(" %4.2f - %-4s %s", dstart, "...", use_nsec ? "us" : "ms");
  825. } else {
  826. printf(" %4d - %4s %s", upper_outlier, "...", use_nsec ? "ns" : "us");
  827. }
  828. }
  829. printf(" | %10d | %.*s%*s |\n", buckets[bucket_num - 1],
  830. bar_len, bar, bar_total - bar_len, "");
  831. print_stats:
  832. printf("\n# statistics (in %s)\n", ftrace->use_nsec ? "nsec" : "usec");
  833. printf(" total time: %20.0f\n", latency_stats.mean * latency_stats.n);
  834. printf(" avg time: %20.0f\n", latency_stats.mean);
  835. printf(" max time: %20"PRIu64"\n", latency_stats.max);
  836. printf(" min time: %20"PRIu64"\n", latency_stats.min);
  837. printf(" count: %20.0f\n", latency_stats.n);
  838. }
  839. static int prepare_func_latency(struct perf_ftrace *ftrace)
  840. {
  841. char *trace_file;
  842. int fd;
  843. if (ftrace->target.use_bpf)
  844. return perf_ftrace__latency_prepare_bpf(ftrace);
  845. if (init_tracing_instance() < 0)
  846. return -1;
  847. if (reset_tracing_files(ftrace) < 0) {
  848. pr_err("failed to reset ftrace\n");
  849. return -1;
  850. }
  851. /* reset ftrace buffer */
  852. if (write_tracing_file("trace", "0") < 0)
  853. return -1;
  854. if (set_tracing_options(ftrace) < 0)
  855. return -1;
  856. /* force to use the function_graph tracer to track duration */
  857. if (write_tracing_file("current_tracer", "function_graph") < 0) {
  858. pr_err("failed to set current_tracer to function_graph\n");
  859. return -1;
  860. }
  861. trace_file = get_tracing_instance_file("trace_pipe");
  862. if (!trace_file) {
  863. pr_err("failed to open trace_pipe\n");
  864. return -1;
  865. }
  866. fd = open(trace_file, O_RDONLY);
  867. if (fd < 0)
  868. pr_err("failed to open trace_pipe\n");
  869. init_stats(&latency_stats);
  870. put_tracing_file(trace_file);
  871. return fd;
  872. }
  873. static int start_func_latency(struct perf_ftrace *ftrace)
  874. {
  875. if (ftrace->target.use_bpf)
  876. return perf_ftrace__latency_start_bpf(ftrace);
  877. if (write_tracing_file("tracing_on", "1") < 0) {
  878. pr_err("can't enable tracing\n");
  879. return -1;
  880. }
  881. return 0;
  882. }
  883. static int stop_func_latency(struct perf_ftrace *ftrace)
  884. {
  885. if (ftrace->target.use_bpf)
  886. return perf_ftrace__latency_stop_bpf(ftrace);
  887. write_tracing_file("tracing_on", "0");
  888. return 0;
  889. }
  890. static int read_func_latency(struct perf_ftrace *ftrace, int buckets[])
  891. {
  892. if (ftrace->target.use_bpf)
  893. return perf_ftrace__latency_read_bpf(ftrace, buckets, &latency_stats);
  894. return 0;
  895. }
  896. static int cleanup_func_latency(struct perf_ftrace *ftrace)
  897. {
  898. if (ftrace->target.use_bpf)
  899. return perf_ftrace__latency_cleanup_bpf(ftrace);
  900. exit_tracing_instance();
  901. return 0;
  902. }
  903. static int __cmd_latency(struct perf_ftrace *ftrace)
  904. {
  905. int trace_fd;
  906. char buf[4096];
  907. char line[256];
  908. struct pollfd pollfd = {
  909. .events = POLLIN,
  910. };
  911. int *buckets;
  912. trace_fd = prepare_func_latency(ftrace);
  913. if (trace_fd < 0)
  914. goto out;
  915. fcntl(trace_fd, F_SETFL, O_NONBLOCK);
  916. pollfd.fd = trace_fd;
  917. if (start_func_latency(ftrace) < 0)
  918. goto out;
  919. evlist__start_workload(ftrace->evlist);
  920. buckets = calloc(ftrace->bucket_num, sizeof(*buckets));
  921. if (buckets == NULL) {
  922. pr_err("failed to allocate memory for the buckets\n");
  923. goto out;
  924. }
  925. line[0] = '\0';
  926. while (!done) {
  927. if (poll(&pollfd, 1, -1) < 0)
  928. break;
  929. if (pollfd.revents & POLLIN) {
  930. int n = read(trace_fd, buf, sizeof(buf) - 1);
  931. if (n < 0)
  932. break;
  933. make_histogram(ftrace, buckets, buf, n, line);
  934. }
  935. }
  936. stop_func_latency(ftrace);
  937. if (workload_exec_errno) {
  938. const char *emsg = str_error_r(workload_exec_errno, buf, sizeof(buf));
  939. pr_err("workload failed: %s\n", emsg);
  940. goto out_free_buckets;
  941. }
  942. /* read remaining buffer contents */
  943. while (!ftrace->target.use_bpf) {
  944. int n = read(trace_fd, buf, sizeof(buf) - 1);
  945. if (n <= 0)
  946. break;
  947. make_histogram(ftrace, buckets, buf, n, line);
  948. }
  949. read_func_latency(ftrace, buckets);
  950. display_histogram(ftrace, buckets);
  951. out_free_buckets:
  952. free(buckets);
  953. out:
  954. close(trace_fd);
  955. cleanup_func_latency(ftrace);
  956. return (done && !workload_exec_errno) ? 0 : -1;
  957. }
  958. static size_t profile_hash(long func, void *ctx __maybe_unused)
  959. {
  960. return str_hash((char *)func);
  961. }
  962. static bool profile_equal(long func1, long func2, void *ctx __maybe_unused)
  963. {
  964. return !strcmp((char *)func1, (char *)func2);
  965. }
  966. static int prepare_func_profile(struct perf_ftrace *ftrace)
  967. {
  968. ftrace->tracer = "function_graph";
  969. ftrace->graph_tail = 1;
  970. ftrace->graph_verbose = 0;
  971. ftrace->profile_hash = hashmap__new(profile_hash, profile_equal, NULL);
  972. if (IS_ERR(ftrace->profile_hash)) {
  973. int err = PTR_ERR(ftrace->profile_hash);
  974. ftrace->profile_hash = NULL;
  975. return err;
  976. }
  977. return 0;
  978. }
  979. /* This is saved in a hashmap keyed by the function name */
  980. struct ftrace_profile_data {
  981. struct stats st;
  982. };
  983. static int add_func_duration(struct perf_ftrace *ftrace, char *func, double time_ns)
  984. {
  985. struct ftrace_profile_data *prof = NULL;
  986. if (!hashmap__find(ftrace->profile_hash, func, &prof)) {
  987. char *key = strdup(func);
  988. if (key == NULL)
  989. return -ENOMEM;
  990. prof = zalloc(sizeof(*prof));
  991. if (prof == NULL) {
  992. free(key);
  993. return -ENOMEM;
  994. }
  995. init_stats(&prof->st);
  996. hashmap__add(ftrace->profile_hash, key, prof);
  997. }
  998. update_stats(&prof->st, time_ns);
  999. return 0;
  1000. }
  1001. /*
  1002. * The ftrace function_graph text output normally looks like below:
  1003. *
  1004. * CPU DURATION FUNCTION
  1005. *
  1006. * 0) | syscall_trace_enter.isra.0() {
  1007. * 0) | __audit_syscall_entry() {
  1008. * 0) | auditd_test_task() {
  1009. * 0) 0.271 us | __rcu_read_lock();
  1010. * 0) 0.275 us | __rcu_read_unlock();
  1011. * 0) 1.254 us | } /\* auditd_test_task *\/
  1012. * 0) 0.279 us | ktime_get_coarse_real_ts64();
  1013. * 0) 2.227 us | } /\* __audit_syscall_entry *\/
  1014. * 0) 2.713 us | } /\* syscall_trace_enter.isra.0 *\/
  1015. *
  1016. * Parse the line and get the duration and function name.
  1017. */
  1018. static int parse_func_duration(struct perf_ftrace *ftrace, char *line, size_t len)
  1019. {
  1020. char *p;
  1021. char *func;
  1022. double duration;
  1023. /* skip CPU */
  1024. p = strchr(line, ')');
  1025. if (p == NULL)
  1026. return 0;
  1027. /* get duration */
  1028. p = skip_spaces(p + 1);
  1029. /* no duration? */
  1030. if (p == NULL || *p == '|')
  1031. return 0;
  1032. /* skip markers like '*' or '!' for longer than ms */
  1033. if (!isdigit(*p))
  1034. p++;
  1035. duration = strtod(p, &p);
  1036. if (strncmp(p, " us", 3)) {
  1037. pr_debug("non-usec time found.. ignoring\n");
  1038. return 0;
  1039. }
  1040. /*
  1041. * profile stat keeps the max and min values as integer,
  1042. * convert to nsec time so that we can have accurate max.
  1043. */
  1044. duration *= 1000;
  1045. /* skip to the pipe */
  1046. while (p < line + len && *p != '|')
  1047. p++;
  1048. if (*p++ != '|')
  1049. return -EINVAL;
  1050. /* get function name */
  1051. func = skip_spaces(p);
  1052. /* skip the closing bracket and the start of comment */
  1053. if (*func == '}')
  1054. func += 5;
  1055. /* remove semi-colon or end of comment at the end */
  1056. p = line + len - 1;
  1057. while (!isalnum(*p) && *p != ']') {
  1058. *p = '\0';
  1059. --p;
  1060. }
  1061. return add_func_duration(ftrace, func, duration);
  1062. }
  1063. enum perf_ftrace_profile_sort_key {
  1064. PFP_SORT_TOTAL = 0,
  1065. PFP_SORT_AVG,
  1066. PFP_SORT_MAX,
  1067. PFP_SORT_COUNT,
  1068. PFP_SORT_NAME,
  1069. };
  1070. static enum perf_ftrace_profile_sort_key profile_sort = PFP_SORT_TOTAL;
  1071. static int cmp_profile_data(const void *a, const void *b)
  1072. {
  1073. const struct hashmap_entry *e1 = *(const struct hashmap_entry **)a;
  1074. const struct hashmap_entry *e2 = *(const struct hashmap_entry **)b;
  1075. struct ftrace_profile_data *p1 = e1->pvalue;
  1076. struct ftrace_profile_data *p2 = e2->pvalue;
  1077. double v1, v2;
  1078. switch (profile_sort) {
  1079. case PFP_SORT_NAME:
  1080. return strcmp(e1->pkey, e2->pkey);
  1081. case PFP_SORT_AVG:
  1082. v1 = p1->st.mean;
  1083. v2 = p2->st.mean;
  1084. break;
  1085. case PFP_SORT_MAX:
  1086. v1 = p1->st.max;
  1087. v2 = p2->st.max;
  1088. break;
  1089. case PFP_SORT_COUNT:
  1090. v1 = p1->st.n;
  1091. v2 = p2->st.n;
  1092. break;
  1093. case PFP_SORT_TOTAL:
  1094. default:
  1095. v1 = p1->st.n * p1->st.mean;
  1096. v2 = p2->st.n * p2->st.mean;
  1097. break;
  1098. }
  1099. if (v1 > v2)
  1100. return -1;
  1101. if (v1 < v2)
  1102. return 1;
  1103. return 0;
  1104. }
  1105. static void print_profile_result(struct perf_ftrace *ftrace)
  1106. {
  1107. struct hashmap_entry *entry, **profile;
  1108. size_t i, nr, bkt;
  1109. nr = hashmap__size(ftrace->profile_hash);
  1110. if (nr == 0)
  1111. return;
  1112. profile = calloc(nr, sizeof(*profile));
  1113. if (profile == NULL) {
  1114. pr_err("failed to allocate memory for the result\n");
  1115. return;
  1116. }
  1117. i = 0;
  1118. hashmap__for_each_entry(ftrace->profile_hash, entry, bkt)
  1119. profile[i++] = entry;
  1120. assert(i == nr);
  1121. //cmp_profile_data(profile[0], profile[1]);
  1122. qsort(profile, nr, sizeof(*profile), cmp_profile_data);
  1123. printf("# %10s %10s %10s %10s %s\n",
  1124. "Total (us)", "Avg (us)", "Max (us)", "Count", "Function");
  1125. for (i = 0; i < nr; i++) {
  1126. const char *name = profile[i]->pkey;
  1127. struct ftrace_profile_data *p = profile[i]->pvalue;
  1128. printf("%12.3f %10.3f %6"PRIu64".%03"PRIu64" %10.0f %s\n",
  1129. p->st.n * p->st.mean / 1000, p->st.mean / 1000,
  1130. p->st.max / 1000, p->st.max % 1000, p->st.n, name);
  1131. }
  1132. free(profile);
  1133. hashmap__for_each_entry(ftrace->profile_hash, entry, bkt) {
  1134. free((char *)entry->pkey);
  1135. free(entry->pvalue);
  1136. }
  1137. hashmap__free(ftrace->profile_hash);
  1138. ftrace->profile_hash = NULL;
  1139. }
  1140. static int __cmd_profile(struct perf_ftrace *ftrace)
  1141. {
  1142. char *trace_file;
  1143. int trace_fd;
  1144. char buf[4096];
  1145. struct io io;
  1146. char *line = NULL;
  1147. size_t line_len = 0;
  1148. if (prepare_func_profile(ftrace) < 0) {
  1149. pr_err("failed to prepare func profiler\n");
  1150. goto out;
  1151. }
  1152. if (init_tracing_instance() < 0)
  1153. goto out;
  1154. if (reset_tracing_files(ftrace) < 0) {
  1155. pr_err("failed to reset ftrace\n");
  1156. goto out_reset;
  1157. }
  1158. /* reset ftrace buffer */
  1159. if (write_tracing_file("trace", "0") < 0)
  1160. goto out_reset;
  1161. if (set_tracing_options(ftrace) < 0)
  1162. goto out_reset;
  1163. if (write_tracing_file("current_tracer", ftrace->tracer) < 0) {
  1164. pr_err("failed to set current_tracer to %s\n", ftrace->tracer);
  1165. goto out_reset;
  1166. }
  1167. setup_pager();
  1168. trace_file = get_tracing_instance_file("trace_pipe");
  1169. if (!trace_file) {
  1170. pr_err("failed to open trace_pipe\n");
  1171. goto out_reset;
  1172. }
  1173. trace_fd = open(trace_file, O_RDONLY);
  1174. put_tracing_file(trace_file);
  1175. if (trace_fd < 0) {
  1176. pr_err("failed to open trace_pipe\n");
  1177. goto out_reset;
  1178. }
  1179. fcntl(trace_fd, F_SETFL, O_NONBLOCK);
  1180. if (write_tracing_file("tracing_on", "1") < 0) {
  1181. pr_err("can't enable tracing\n");
  1182. goto out_close_fd;
  1183. }
  1184. evlist__start_workload(ftrace->evlist);
  1185. io__init(&io, trace_fd, buf, sizeof(buf));
  1186. io.timeout_ms = -1;
  1187. while (!done && !io.eof) {
  1188. if (io__getline(&io, &line, &line_len) < 0)
  1189. break;
  1190. if (parse_func_duration(ftrace, line, line_len) < 0)
  1191. break;
  1192. }
  1193. write_tracing_file("tracing_on", "0");
  1194. if (workload_exec_errno) {
  1195. const char *emsg = str_error_r(workload_exec_errno, buf, sizeof(buf));
  1196. /* flush stdout first so below error msg appears at the end. */
  1197. fflush(stdout);
  1198. pr_err("workload failed: %s\n", emsg);
  1199. goto out_free_line;
  1200. }
  1201. /* read remaining buffer contents */
  1202. io.timeout_ms = 0;
  1203. while (!io.eof) {
  1204. if (io__getline(&io, &line, &line_len) < 0)
  1205. break;
  1206. if (parse_func_duration(ftrace, line, line_len) < 0)
  1207. break;
  1208. }
  1209. print_profile_result(ftrace);
  1210. out_free_line:
  1211. free(line);
  1212. out_close_fd:
  1213. close(trace_fd);
  1214. out_reset:
  1215. exit_tracing_instance();
  1216. out:
  1217. return (done && !workload_exec_errno) ? 0 : -1;
  1218. }
  1219. static int perf_ftrace_config(const char *var, const char *value, void *cb)
  1220. {
  1221. struct perf_ftrace *ftrace = cb;
  1222. if (!strstarts(var, "ftrace."))
  1223. return 0;
  1224. if (strcmp(var, "ftrace.tracer"))
  1225. return -1;
  1226. if (!strcmp(value, "function_graph") ||
  1227. !strcmp(value, "function")) {
  1228. ftrace->tracer = value;
  1229. return 0;
  1230. }
  1231. pr_err("Please select \"function_graph\" (default) or \"function\"\n");
  1232. return -1;
  1233. }
  1234. static void list_function_cb(char *str, void *arg)
  1235. {
  1236. struct strfilter *filter = (struct strfilter *)arg;
  1237. if (strfilter__compare(filter, str))
  1238. printf("%s", str);
  1239. }
  1240. static int opt_list_avail_functions(const struct option *opt __maybe_unused,
  1241. const char *str, int unset)
  1242. {
  1243. struct strfilter *filter;
  1244. const char *err = NULL;
  1245. int ret;
  1246. if (unset || !str)
  1247. return -1;
  1248. filter = strfilter__new(str, &err);
  1249. if (!filter)
  1250. return err ? -EINVAL : -ENOMEM;
  1251. ret = strfilter__or(filter, str, &err);
  1252. if (ret == -EINVAL) {
  1253. pr_err("Filter parse error at %td.\n", err - str + 1);
  1254. pr_err("Source: \"%s\"\n", str);
  1255. pr_err(" %*c\n", (int)(err - str + 1), '^');
  1256. strfilter__delete(filter);
  1257. return ret;
  1258. }
  1259. ret = read_tracing_file_by_line("available_filter_functions",
  1260. list_function_cb, filter);
  1261. strfilter__delete(filter);
  1262. if (ret < 0)
  1263. return ret;
  1264. exit(0);
  1265. }
  1266. static int parse_filter_func(const struct option *opt, const char *str,
  1267. int unset __maybe_unused)
  1268. {
  1269. struct list_head *head = opt->value;
  1270. struct filter_entry *entry;
  1271. entry = malloc(sizeof(*entry) + strlen(str) + 1);
  1272. if (entry == NULL)
  1273. return -ENOMEM;
  1274. strcpy(entry->name, str);
  1275. list_add_tail(&entry->list, head);
  1276. return 0;
  1277. }
  1278. static void delete_filter_func(struct list_head *head)
  1279. {
  1280. struct filter_entry *pos, *tmp;
  1281. list_for_each_entry_safe(pos, tmp, head, list) {
  1282. list_del_init(&pos->list);
  1283. free(pos);
  1284. }
  1285. }
  1286. static int parse_filter_event(const struct option *opt, const char *str,
  1287. int unset __maybe_unused)
  1288. {
  1289. struct list_head *head = opt->value;
  1290. struct filter_entry *entry;
  1291. char *s, *p;
  1292. int ret = -ENOMEM;
  1293. s = strdup(str);
  1294. if (s == NULL)
  1295. return -ENOMEM;
  1296. while ((p = strsep(&s, ",")) != NULL) {
  1297. entry = malloc(sizeof(*entry) + strlen(p) + 1);
  1298. if (entry == NULL)
  1299. goto out;
  1300. strcpy(entry->name, p);
  1301. list_add_tail(&entry->list, head);
  1302. }
  1303. ret = 0;
  1304. out:
  1305. free(s);
  1306. return ret;
  1307. }
  1308. static int parse_buffer_size(const struct option *opt,
  1309. const char *str, int unset)
  1310. {
  1311. unsigned long *s = (unsigned long *)opt->value;
  1312. static struct parse_tag tags_size[] = {
  1313. { .tag = 'B', .mult = 1 },
  1314. { .tag = 'K', .mult = 1 << 10 },
  1315. { .tag = 'M', .mult = 1 << 20 },
  1316. { .tag = 'G', .mult = 1 << 30 },
  1317. { .tag = 0 },
  1318. };
  1319. unsigned long val;
  1320. if (unset) {
  1321. *s = 0;
  1322. return 0;
  1323. }
  1324. val = parse_tag_value(str, tags_size);
  1325. if (val != (unsigned long) -1) {
  1326. if (val < 1024) {
  1327. pr_err("buffer size too small, must larger than 1KB.");
  1328. return -1;
  1329. }
  1330. *s = val;
  1331. return 0;
  1332. }
  1333. return -1;
  1334. }
  1335. static int parse_func_tracer_opts(const struct option *opt,
  1336. const char *str, int unset)
  1337. {
  1338. int ret;
  1339. struct perf_ftrace *ftrace = (struct perf_ftrace *) opt->value;
  1340. struct sublevel_option func_tracer_opts[] = {
  1341. { .name = "call-graph", .value_ptr = &ftrace->func_stack_trace },
  1342. { .name = "irq-info", .value_ptr = &ftrace->func_irq_info },
  1343. { .name = NULL, }
  1344. };
  1345. if (unset)
  1346. return 0;
  1347. ret = perf_parse_sublevel_options(str, func_tracer_opts);
  1348. if (ret)
  1349. return ret;
  1350. return 0;
  1351. }
  1352. static int parse_graph_tracer_opts(const struct option *opt,
  1353. const char *str, int unset)
  1354. {
  1355. int ret;
  1356. struct perf_ftrace *ftrace = (struct perf_ftrace *) opt->value;
  1357. struct sublevel_option graph_tracer_opts[] = {
  1358. { .name = "args", .value_ptr = &ftrace->graph_args },
  1359. { .name = "retval", .value_ptr = &ftrace->graph_retval },
  1360. { .name = "retval-hex", .value_ptr = &ftrace->graph_retval_hex },
  1361. { .name = "retaddr", .value_ptr = &ftrace->graph_retaddr },
  1362. { .name = "nosleep-time", .value_ptr = &ftrace->graph_nosleep_time },
  1363. { .name = "noirqs", .value_ptr = &ftrace->graph_noirqs },
  1364. { .name = "verbose", .value_ptr = &ftrace->graph_verbose },
  1365. { .name = "thresh", .value_ptr = &ftrace->graph_thresh },
  1366. { .name = "depth", .value_ptr = &ftrace->graph_depth },
  1367. { .name = "tail", .value_ptr = &ftrace->graph_tail },
  1368. { .name = NULL, }
  1369. };
  1370. if (unset)
  1371. return 0;
  1372. ret = perf_parse_sublevel_options(str, graph_tracer_opts);
  1373. if (ret)
  1374. return ret;
  1375. return 0;
  1376. }
  1377. static int parse_sort_key(const struct option *opt, const char *str, int unset)
  1378. {
  1379. enum perf_ftrace_profile_sort_key *key = (void *)opt->value;
  1380. if (unset)
  1381. return 0;
  1382. if (!strcmp(str, "total"))
  1383. *key = PFP_SORT_TOTAL;
  1384. else if (!strcmp(str, "avg"))
  1385. *key = PFP_SORT_AVG;
  1386. else if (!strcmp(str, "max"))
  1387. *key = PFP_SORT_MAX;
  1388. else if (!strcmp(str, "count"))
  1389. *key = PFP_SORT_COUNT;
  1390. else if (!strcmp(str, "name"))
  1391. *key = PFP_SORT_NAME;
  1392. else {
  1393. pr_err("Unknown sort key: %s\n", str);
  1394. return -1;
  1395. }
  1396. return 0;
  1397. }
  1398. enum perf_ftrace_subcommand {
  1399. PERF_FTRACE_NONE,
  1400. PERF_FTRACE_TRACE,
  1401. PERF_FTRACE_LATENCY,
  1402. PERF_FTRACE_PROFILE,
  1403. };
  1404. int cmd_ftrace(int argc, const char **argv)
  1405. {
  1406. int ret;
  1407. int (*cmd_func)(struct perf_ftrace *) = NULL;
  1408. struct perf_ftrace ftrace = {
  1409. .tracer = DEFAULT_TRACER,
  1410. };
  1411. const struct option common_options[] = {
  1412. OPT_STRING('p', "pid", &ftrace.target.pid, "pid",
  1413. "Trace on existing process id"),
  1414. /* TODO: Add short option -t after -t/--tracer can be removed. */
  1415. OPT_STRING(0, "tid", &ftrace.target.tid, "tid",
  1416. "Trace on existing thread id (exclusive to --pid)"),
  1417. OPT_INCR('v', "verbose", &verbose,
  1418. "Be more verbose"),
  1419. OPT_BOOLEAN('a', "all-cpus", &ftrace.target.system_wide,
  1420. "System-wide collection from all CPUs"),
  1421. OPT_STRING('C', "cpu", &ftrace.target.cpu_list, "cpu",
  1422. "List of cpus to monitor"),
  1423. OPT_END()
  1424. };
  1425. const struct option ftrace_options[] = {
  1426. OPT_STRING('t', "tracer", &ftrace.tracer, "tracer",
  1427. "Tracer to use: function_graph(default) or function"),
  1428. OPT_CALLBACK_DEFAULT('F', "funcs", NULL, "[FILTER]",
  1429. "Show available functions to filter",
  1430. opt_list_avail_functions, "*"),
  1431. OPT_CALLBACK('T', "trace-funcs", &ftrace.filters, "func",
  1432. "Trace given functions using function tracer",
  1433. parse_filter_func),
  1434. OPT_CALLBACK('N', "notrace-funcs", &ftrace.notrace, "func",
  1435. "Do not trace given functions", parse_filter_func),
  1436. OPT_CALLBACK(0, "func-opts", &ftrace, "options",
  1437. "Function tracer options, available options: call-graph,irq-info",
  1438. parse_func_tracer_opts),
  1439. OPT_CALLBACK('G', "graph-funcs", &ftrace.graph_funcs, "func",
  1440. "Trace given functions using function_graph tracer",
  1441. parse_filter_func),
  1442. OPT_CALLBACK('g', "nograph-funcs", &ftrace.nograph_funcs, "func",
  1443. "Set nograph filter on given functions", parse_filter_func),
  1444. OPT_CALLBACK(0, "graph-opts", &ftrace, "options",
  1445. "Graph tracer options, available options: args,retval,retval-hex,retaddr,nosleep-time,noirqs,verbose,thresh=<n>,depth=<n>",
  1446. parse_graph_tracer_opts),
  1447. OPT_CALLBACK('m', "buffer-size", &ftrace.percpu_buffer_size, "size",
  1448. "Size of per cpu buffer, needs to use a B, K, M or G suffix.", parse_buffer_size),
  1449. OPT_BOOLEAN(0, "inherit", &ftrace.inherit,
  1450. "Trace children processes"),
  1451. OPT_INTEGER('D', "delay", &ftrace.target.initial_delay,
  1452. "Number of milliseconds to wait before starting tracing after program start"),
  1453. OPT_PARENT(common_options),
  1454. };
  1455. const struct option latency_options[] = {
  1456. OPT_CALLBACK('T', "trace-funcs", &ftrace.filters, "func",
  1457. "Show latency of given function", parse_filter_func),
  1458. OPT_CALLBACK('e', "events", &ftrace.event_pair, "event1,event2",
  1459. "Show latency between the two events", parse_filter_event),
  1460. #ifdef HAVE_BPF_SKEL
  1461. OPT_BOOLEAN('b', "use-bpf", &ftrace.target.use_bpf,
  1462. "Use BPF to measure function latency"),
  1463. #endif
  1464. OPT_BOOLEAN('n', "use-nsec", &ftrace.use_nsec,
  1465. "Use nano-second histogram"),
  1466. OPT_UINTEGER(0, "bucket-range", &ftrace.bucket_range,
  1467. "Bucket range in ms or ns (-n/--use-nsec), default is log2() mode"),
  1468. OPT_UINTEGER(0, "min-latency", &ftrace.min_latency,
  1469. "Minimum latency (1st bucket). Works only with --bucket-range."),
  1470. OPT_UINTEGER(0, "max-latency", &ftrace.max_latency,
  1471. "Maximum latency (last bucket). Works only with --bucket-range."),
  1472. OPT_BOOLEAN(0, "hide-empty", &ftrace.hide_empty,
  1473. "Hide empty buckets in the histogram"),
  1474. OPT_PARENT(common_options),
  1475. };
  1476. const struct option profile_options[] = {
  1477. OPT_CALLBACK('T', "trace-funcs", &ftrace.filters, "func",
  1478. "Trace given functions using function tracer",
  1479. parse_filter_func),
  1480. OPT_CALLBACK('N', "notrace-funcs", &ftrace.notrace, "func",
  1481. "Do not trace given functions", parse_filter_func),
  1482. OPT_CALLBACK('G', "graph-funcs", &ftrace.graph_funcs, "func",
  1483. "Trace given functions using function_graph tracer",
  1484. parse_filter_func),
  1485. OPT_CALLBACK('g', "nograph-funcs", &ftrace.nograph_funcs, "func",
  1486. "Set nograph filter on given functions", parse_filter_func),
  1487. OPT_CALLBACK('m', "buffer-size", &ftrace.percpu_buffer_size, "size",
  1488. "Size of per cpu buffer, needs to use a B, K, M or G suffix.", parse_buffer_size),
  1489. OPT_CALLBACK('s', "sort", &profile_sort, "key",
  1490. "Sort result by key: total (default), avg, max, count, name.",
  1491. parse_sort_key),
  1492. OPT_CALLBACK(0, "graph-opts", &ftrace, "options",
  1493. "Graph tracer options, available options: nosleep-time,noirqs,thresh=<n>,depth=<n>",
  1494. parse_graph_tracer_opts),
  1495. OPT_PARENT(common_options),
  1496. };
  1497. const struct option *options = ftrace_options;
  1498. const char * const ftrace_usage[] = {
  1499. "perf ftrace [<options>] [<command>]",
  1500. "perf ftrace [<options>] -- [<command>] [<options>]",
  1501. "perf ftrace {trace|latency|profile} [<options>] [<command>]",
  1502. "perf ftrace {trace|latency|profile} [<options>] -- [<command>] [<options>]",
  1503. NULL
  1504. };
  1505. enum perf_ftrace_subcommand subcmd = PERF_FTRACE_NONE;
  1506. INIT_LIST_HEAD(&ftrace.filters);
  1507. INIT_LIST_HEAD(&ftrace.notrace);
  1508. INIT_LIST_HEAD(&ftrace.graph_funcs);
  1509. INIT_LIST_HEAD(&ftrace.nograph_funcs);
  1510. INIT_LIST_HEAD(&ftrace.event_pair);
  1511. signal(SIGINT, sig_handler);
  1512. signal(SIGUSR1, sig_handler);
  1513. signal(SIGCHLD, sig_handler);
  1514. signal(SIGPIPE, sig_handler);
  1515. if (!check_ftrace_capable())
  1516. return -1;
  1517. if (!is_ftrace_supported()) {
  1518. pr_err("ftrace is not supported on this system\n");
  1519. return -ENOTSUP;
  1520. }
  1521. ret = perf_config(perf_ftrace_config, &ftrace);
  1522. if (ret < 0)
  1523. return -1;
  1524. if (argc > 1) {
  1525. if (!strcmp(argv[1], "trace")) {
  1526. subcmd = PERF_FTRACE_TRACE;
  1527. } else if (!strcmp(argv[1], "latency")) {
  1528. subcmd = PERF_FTRACE_LATENCY;
  1529. options = latency_options;
  1530. } else if (!strcmp(argv[1], "profile")) {
  1531. subcmd = PERF_FTRACE_PROFILE;
  1532. options = profile_options;
  1533. }
  1534. if (subcmd != PERF_FTRACE_NONE) {
  1535. argc--;
  1536. argv++;
  1537. }
  1538. }
  1539. /* for backward compatibility */
  1540. if (subcmd == PERF_FTRACE_NONE)
  1541. subcmd = PERF_FTRACE_TRACE;
  1542. argc = parse_options(argc, argv, options, ftrace_usage,
  1543. PARSE_OPT_STOP_AT_NON_OPTION);
  1544. if (argc < 0) {
  1545. ret = -EINVAL;
  1546. goto out_delete_filters;
  1547. }
  1548. /* Make system wide (-a) the default target. */
  1549. if (!argc && target__none(&ftrace.target))
  1550. ftrace.target.system_wide = true;
  1551. switch (subcmd) {
  1552. case PERF_FTRACE_TRACE:
  1553. cmd_func = __cmd_ftrace;
  1554. break;
  1555. case PERF_FTRACE_LATENCY:
  1556. if (list_empty(&ftrace.filters) && list_empty(&ftrace.event_pair)) {
  1557. pr_err("Should provide a function or events to measure\n");
  1558. parse_options_usage(ftrace_usage, options, "T", 1);
  1559. parse_options_usage(NULL, options, "e", 1);
  1560. ret = -EINVAL;
  1561. goto out_delete_filters;
  1562. }
  1563. if (!list_empty(&ftrace.filters) && !list_empty(&ftrace.event_pair)) {
  1564. pr_err("Please specify either of function or events\n");
  1565. parse_options_usage(ftrace_usage, options, "T", 1);
  1566. parse_options_usage(NULL, options, "e", 1);
  1567. ret = -EINVAL;
  1568. goto out_delete_filters;
  1569. }
  1570. if (!list_empty(&ftrace.event_pair) && !ftrace.target.use_bpf) {
  1571. pr_err("Event processing needs BPF\n");
  1572. parse_options_usage(ftrace_usage, options, "b", 1);
  1573. parse_options_usage(NULL, options, "e", 1);
  1574. ret = -EINVAL;
  1575. goto out_delete_filters;
  1576. }
  1577. if (!ftrace.bucket_range && ftrace.min_latency) {
  1578. pr_err("--min-latency works only with --bucket-range\n");
  1579. parse_options_usage(ftrace_usage, options,
  1580. "min-latency", /*short_opt=*/false);
  1581. ret = -EINVAL;
  1582. goto out_delete_filters;
  1583. }
  1584. if (ftrace.bucket_range && !ftrace.min_latency) {
  1585. /* default min latency should be the bucket range */
  1586. ftrace.min_latency = ftrace.bucket_range;
  1587. }
  1588. if (!ftrace.bucket_range && ftrace.max_latency) {
  1589. pr_err("--max-latency works only with --bucket-range\n");
  1590. parse_options_usage(ftrace_usage, options,
  1591. "max-latency", /*short_opt=*/false);
  1592. ret = -EINVAL;
  1593. goto out_delete_filters;
  1594. }
  1595. if (ftrace.bucket_range && ftrace.max_latency &&
  1596. ftrace.max_latency < ftrace.min_latency + ftrace.bucket_range) {
  1597. /* we need at least 1 bucket excluding min and max buckets */
  1598. pr_err("--max-latency must be larger than min-latency + bucket-range\n");
  1599. parse_options_usage(ftrace_usage, options,
  1600. "max-latency", /*short_opt=*/false);
  1601. ret = -EINVAL;
  1602. goto out_delete_filters;
  1603. }
  1604. /* set default unless max_latency is set and valid */
  1605. ftrace.bucket_num = NUM_BUCKET;
  1606. if (ftrace.bucket_range) {
  1607. if (ftrace.max_latency)
  1608. ftrace.bucket_num = (ftrace.max_latency - ftrace.min_latency) /
  1609. ftrace.bucket_range + 2;
  1610. else
  1611. /* default max latency should depend on bucket range and num_buckets */
  1612. ftrace.max_latency = (NUM_BUCKET - 2) * ftrace.bucket_range +
  1613. ftrace.min_latency;
  1614. }
  1615. cmd_func = __cmd_latency;
  1616. break;
  1617. case PERF_FTRACE_PROFILE:
  1618. cmd_func = __cmd_profile;
  1619. break;
  1620. case PERF_FTRACE_NONE:
  1621. default:
  1622. pr_err("Invalid subcommand\n");
  1623. ret = -EINVAL;
  1624. goto out_delete_filters;
  1625. }
  1626. ret = target__validate(&ftrace.target);
  1627. if (ret) {
  1628. char errbuf[512];
  1629. target__strerror(&ftrace.target, ret, errbuf, 512);
  1630. pr_err("%s\n", errbuf);
  1631. goto out_delete_filters;
  1632. }
  1633. ftrace.evlist = evlist__new();
  1634. if (ftrace.evlist == NULL) {
  1635. ret = -ENOMEM;
  1636. goto out_delete_filters;
  1637. }
  1638. ret = evlist__create_maps(ftrace.evlist, &ftrace.target);
  1639. if (ret < 0)
  1640. goto out_delete_evlist;
  1641. if (argc) {
  1642. ret = evlist__prepare_workload(ftrace.evlist, &ftrace.target,
  1643. argv, false,
  1644. ftrace__workload_exec_failed_signal);
  1645. if (ret < 0)
  1646. goto out_delete_evlist;
  1647. }
  1648. ret = cmd_func(&ftrace);
  1649. out_delete_evlist:
  1650. evlist__delete(ftrace.evlist);
  1651. out_delete_filters:
  1652. delete_filter_func(&ftrace.filters);
  1653. delete_filter_func(&ftrace.notrace);
  1654. delete_filter_func(&ftrace.graph_funcs);
  1655. delete_filter_func(&ftrace.nograph_funcs);
  1656. delete_filter_func(&ftrace.event_pair);
  1657. return ret;
  1658. }