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