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 unsigned int bucket_num = ftrace->bucket_num;
737 char *p, *q;
738 char *unit;
739 double num;
740 int i;
741
742 /* ensure NUL termination */
743 buf[len] = '\0';
744
745 /* handle data line by line */
746 for (p = buf; (q = strchr(p, '\n')) != NULL; p = q + 1) {
747 *q = '\0';
748 /* move it to the line buffer */
749 strcat(linebuf, p);
750
751 /*
752 * parse trace output to get function duration like in
753 *
754 * # tracer: function_graph
755 * #
756 * # CPU DURATION FUNCTION CALLS
757 * # | | | | | | |
758 * 1) + 10.291 us | do_filp_open();
759 * 1) 4.889 us | do_filp_open();
760 * 1) 6.086 us | do_filp_open();
761 *
762 */
763 if (linebuf[0] == '#')
764 goto next;
765
766 /* ignore CPU */
767 p = strchr(linebuf, ')');
768 if (p == NULL)
769 p = linebuf;
770
771 while (*p && !isdigit(*p) && (*p != '|'))
772 p++;
773
774 /* no duration */
775 if (*p == '\0' || *p == '|')
776 goto next;
777
778 num = strtod(p, &unit);
779 if (!unit || strncmp(unit, " us", 3))
780 goto next;
781
782 if (ftrace->use_nsec)
783 num *= 1000;
784
785 i = 0;
786 if (num < min_latency)
787 goto do_inc;
788
789 num -= min_latency;
790
791 if (!ftrace->bucket_range) {
792 i = log2(num);
793 if (i < 0)
794 i = 0;
795 } else {
796 // Less than 1 unit (ms or ns), or, in the future,
797 // than the min latency desired.
798 if (num > 0) // 1st entry: [ 1 unit .. bucket_range units ]
799 i = num / ftrace->bucket_range + 1;
800 if (num >= max_latency - min_latency)
801 i = bucket_num -1;
802 }
803 if ((unsigned)i >= bucket_num)
804 i = bucket_num - 1;
805
806 num += min_latency;
807 do_inc:
808 buckets[i]++;
809 update_stats(&latency_stats, num);
810
811 next:
812 /* empty the line buffer for the next output */
813 linebuf[0] = '\0';
814 }
815
816 /* preserve any remaining output (before newline) */
817 strcat(linebuf, p);
818 }
819
display_histogram(struct perf_ftrace * ftrace,int buckets[])820 static void display_histogram(struct perf_ftrace *ftrace, int buckets[])
821 {
822 int min_latency = ftrace->min_latency;
823 bool use_nsec = ftrace->use_nsec;
824 unsigned int bucket_num = ftrace->bucket_num;
825 unsigned int i;
826 int total = 0;
827 int bar_total = 46; /* to fit in 80 column */
828 char bar[] = "###############################################";
829 int bar_len;
830
831 for (i = 0; i < bucket_num; i++)
832 total += buckets[i];
833
834 if (total == 0) {
835 printf("No data found\n");
836 return;
837 }
838
839 printf("# %14s | %10s | %-*s |\n",
840 " DURATION ", "COUNT", bar_total, "GRAPH");
841
842 bar_len = buckets[0] * bar_total / total;
843
844 if (!ftrace->hide_empty || buckets[0])
845 printf(" %4d - %4d %s | %10d | %.*s%*s |\n",
846 0, min_latency ?: 1, use_nsec ? "ns" : "us",
847 buckets[0], bar_len, bar, bar_total - bar_len, "");
848
849 for (i = 1; i < bucket_num - 1; i++) {
850 unsigned int start, stop;
851 const char *unit = use_nsec ? "ns" : "us";
852
853 if (ftrace->hide_empty && !buckets[i])
854 continue;
855 if (!ftrace->bucket_range) {
856 start = (1 << (i - 1));
857 stop = 1 << i;
858
859 if (start >= 1024) {
860 start >>= 10;
861 stop >>= 10;
862 unit = use_nsec ? "us" : "ms";
863 }
864 } else {
865 start = (i - 1) * ftrace->bucket_range + min_latency;
866 stop = i * ftrace->bucket_range + min_latency;
867
868 if (start >= ftrace->max_latency)
869 break;
870 if (stop > ftrace->max_latency)
871 stop = ftrace->max_latency;
872
873 if (start >= 1000) {
874 double dstart = start / 1000.0,
875 dstop = stop / 1000.0;
876 printf(" %4.2f - %-4.2f", dstart, dstop);
877 unit = use_nsec ? "us" : "ms";
878 goto print_bucket_info;
879 }
880 }
881
882 printf(" %4d - %4d", start, stop);
883 print_bucket_info:
884 bar_len = buckets[i] * bar_total / total;
885 printf(" %s | %10d | %.*s%*s |\n", unit, buckets[i], bar_len, bar,
886 bar_total - bar_len, "");
887 }
888
889 bar_len = buckets[bucket_num - 1] * bar_total / total;
890 if (ftrace->hide_empty && !buckets[bucket_num - 1])
891 goto print_stats;
892 if (!ftrace->bucket_range) {
893 printf(" %4d - %-4s %s", 1, "...", use_nsec ? "ms" : "s ");
894 } else {
895 unsigned int upper_outlier = (bucket_num - 2) * ftrace->bucket_range + min_latency;
896 if (upper_outlier > ftrace->max_latency)
897 upper_outlier = ftrace->max_latency;
898
899 if (upper_outlier >= 1000) {
900 double dstart = upper_outlier / 1000.0;
901
902 printf(" %4.2f - %-4s %s", dstart, "...", use_nsec ? "us" : "ms");
903 } else {
904 printf(" %4d - %4s %s", upper_outlier, "...", use_nsec ? "ns" : "us");
905 }
906 }
907 printf(" | %10d | %.*s%*s |\n", buckets[bucket_num - 1],
908 bar_len, bar, bar_total - bar_len, "");
909
910 print_stats:
911 printf("\n# statistics (in %s)\n", ftrace->use_nsec ? "nsec" : "usec");
912 printf(" total time: %20.0f\n", latency_stats.mean * latency_stats.n);
913 printf(" avg time: %20.0f\n", latency_stats.mean);
914 printf(" max time: %20"PRIu64"\n", latency_stats.max);
915 printf(" min time: %20"PRIu64"\n", latency_stats.min);
916 printf(" count: %20.0f\n", latency_stats.n);
917 }
918
prepare_func_latency(struct perf_ftrace * ftrace)919 static int prepare_func_latency(struct perf_ftrace *ftrace)
920 {
921 char *trace_file;
922 int fd;
923
924 if (ftrace->target.use_bpf)
925 return perf_ftrace__latency_prepare_bpf(ftrace);
926
927 if (reset_tracing_files(ftrace) < 0) {
928 pr_err("failed to reset ftrace\n");
929 return -1;
930 }
931
932 /* reset ftrace buffer */
933 if (write_tracing_file("trace", "0") < 0)
934 return -1;
935
936 if (set_tracing_options(ftrace) < 0)
937 return -1;
938
939 /* force to use the function_graph tracer to track duration */
940 if (write_tracing_file("current_tracer", "function_graph") < 0) {
941 pr_err("failed to set current_tracer to function_graph\n");
942 return -1;
943 }
944
945 trace_file = get_tracing_file("trace_pipe");
946 if (!trace_file) {
947 pr_err("failed to open trace_pipe\n");
948 return -1;
949 }
950
951 fd = open(trace_file, O_RDONLY);
952 if (fd < 0)
953 pr_err("failed to open trace_pipe\n");
954
955 init_stats(&latency_stats);
956
957 put_tracing_file(trace_file);
958 return fd;
959 }
960
start_func_latency(struct perf_ftrace * ftrace)961 static int start_func_latency(struct perf_ftrace *ftrace)
962 {
963 if (ftrace->target.use_bpf)
964 return perf_ftrace__latency_start_bpf(ftrace);
965
966 if (write_tracing_file("tracing_on", "1") < 0) {
967 pr_err("can't enable tracing\n");
968 return -1;
969 }
970
971 return 0;
972 }
973
stop_func_latency(struct perf_ftrace * ftrace)974 static int stop_func_latency(struct perf_ftrace *ftrace)
975 {
976 if (ftrace->target.use_bpf)
977 return perf_ftrace__latency_stop_bpf(ftrace);
978
979 write_tracing_file("tracing_on", "0");
980 return 0;
981 }
982
read_func_latency(struct perf_ftrace * ftrace,int buckets[])983 static int read_func_latency(struct perf_ftrace *ftrace, int buckets[])
984 {
985 if (ftrace->target.use_bpf)
986 return perf_ftrace__latency_read_bpf(ftrace, buckets, &latency_stats);
987
988 return 0;
989 }
990
cleanup_func_latency(struct perf_ftrace * ftrace)991 static int cleanup_func_latency(struct perf_ftrace *ftrace)
992 {
993 if (ftrace->target.use_bpf)
994 return perf_ftrace__latency_cleanup_bpf(ftrace);
995
996 reset_tracing_files(ftrace);
997 return 0;
998 }
999
__cmd_latency(struct perf_ftrace * ftrace)1000 static int __cmd_latency(struct perf_ftrace *ftrace)
1001 {
1002 int trace_fd;
1003 char buf[4096];
1004 char line[256];
1005 struct pollfd pollfd = {
1006 .events = POLLIN,
1007 };
1008 int *buckets;
1009
1010 trace_fd = prepare_func_latency(ftrace);
1011 if (trace_fd < 0)
1012 goto out;
1013
1014 fcntl(trace_fd, F_SETFL, O_NONBLOCK);
1015 pollfd.fd = trace_fd;
1016
1017 if (start_func_latency(ftrace) < 0)
1018 goto out;
1019
1020 evlist__start_workload(ftrace->evlist);
1021
1022 buckets = calloc(ftrace->bucket_num, sizeof(*buckets));
1023 if (buckets == NULL) {
1024 pr_err("failed to allocate memory for the buckets\n");
1025 goto out;
1026 }
1027
1028 line[0] = '\0';
1029 while (!done) {
1030 if (poll(&pollfd, 1, -1) < 0)
1031 break;
1032
1033 if (pollfd.revents & POLLIN) {
1034 int n = read(trace_fd, buf, sizeof(buf) - 1);
1035 if (n < 0)
1036 break;
1037
1038 make_histogram(ftrace, buckets, buf, n, line);
1039 }
1040 }
1041
1042 stop_func_latency(ftrace);
1043
1044 if (workload_exec_errno) {
1045 const char *emsg = str_error_r(workload_exec_errno, buf, sizeof(buf));
1046 pr_err("workload failed: %s\n", emsg);
1047 goto out_free_buckets;
1048 }
1049
1050 /* read remaining buffer contents */
1051 while (!ftrace->target.use_bpf) {
1052 int n = read(trace_fd, buf, sizeof(buf) - 1);
1053 if (n <= 0)
1054 break;
1055 make_histogram(ftrace, buckets, buf, n, line);
1056 }
1057
1058 read_func_latency(ftrace, buckets);
1059
1060 display_histogram(ftrace, buckets);
1061
1062 out_free_buckets:
1063 free(buckets);
1064 out:
1065 close(trace_fd);
1066 cleanup_func_latency(ftrace);
1067
1068 return (done && !workload_exec_errno) ? 0 : -1;
1069 }
1070
profile_hash(long func,void * ctx __maybe_unused)1071 static size_t profile_hash(long func, void *ctx __maybe_unused)
1072 {
1073 return str_hash((char *)func);
1074 }
1075
profile_equal(long func1,long func2,void * ctx __maybe_unused)1076 static bool profile_equal(long func1, long func2, void *ctx __maybe_unused)
1077 {
1078 return !strcmp((char *)func1, (char *)func2);
1079 }
1080
prepare_func_profile(struct perf_ftrace * ftrace)1081 static int prepare_func_profile(struct perf_ftrace *ftrace)
1082 {
1083 ftrace->tracer = "function_graph";
1084 ftrace->graph_tail = 1;
1085 ftrace->graph_verbose = 0;
1086
1087 ftrace->profile_hash = hashmap__new(profile_hash, profile_equal, NULL);
1088 if (ftrace->profile_hash == NULL)
1089 return -ENOMEM;
1090
1091 return 0;
1092 }
1093
1094 /* This is saved in a hashmap keyed by the function name */
1095 struct ftrace_profile_data {
1096 struct stats st;
1097 };
1098
add_func_duration(struct perf_ftrace * ftrace,char * func,double time_ns)1099 static int add_func_duration(struct perf_ftrace *ftrace, char *func, double time_ns)
1100 {
1101 struct ftrace_profile_data *prof = NULL;
1102
1103 if (!hashmap__find(ftrace->profile_hash, func, &prof)) {
1104 char *key = strdup(func);
1105
1106 if (key == NULL)
1107 return -ENOMEM;
1108
1109 prof = zalloc(sizeof(*prof));
1110 if (prof == NULL) {
1111 free(key);
1112 return -ENOMEM;
1113 }
1114
1115 init_stats(&prof->st);
1116 hashmap__add(ftrace->profile_hash, key, prof);
1117 }
1118
1119 update_stats(&prof->st, time_ns);
1120 return 0;
1121 }
1122
1123 /*
1124 * The ftrace function_graph text output normally looks like below:
1125 *
1126 * CPU DURATION FUNCTION
1127 *
1128 * 0) | syscall_trace_enter.isra.0() {
1129 * 0) | __audit_syscall_entry() {
1130 * 0) | auditd_test_task() {
1131 * 0) 0.271 us | __rcu_read_lock();
1132 * 0) 0.275 us | __rcu_read_unlock();
1133 * 0) 1.254 us | } /\* auditd_test_task *\/
1134 * 0) 0.279 us | ktime_get_coarse_real_ts64();
1135 * 0) 2.227 us | } /\* __audit_syscall_entry *\/
1136 * 0) 2.713 us | } /\* syscall_trace_enter.isra.0 *\/
1137 *
1138 * Parse the line and get the duration and function name.
1139 */
parse_func_duration(struct perf_ftrace * ftrace,char * line,size_t len)1140 static int parse_func_duration(struct perf_ftrace *ftrace, char *line, size_t len)
1141 {
1142 char *p;
1143 char *func;
1144 double duration;
1145
1146 /* skip CPU */
1147 p = strchr(line, ')');
1148 if (p == NULL)
1149 return 0;
1150
1151 /* get duration */
1152 p = skip_spaces(p + 1);
1153
1154 /* no duration? */
1155 if (p == NULL || *p == '|')
1156 return 0;
1157
1158 /* skip markers like '*' or '!' for longer than ms */
1159 if (!isdigit(*p))
1160 p++;
1161
1162 duration = strtod(p, &p);
1163
1164 if (strncmp(p, " us", 3)) {
1165 pr_debug("non-usec time found.. ignoring\n");
1166 return 0;
1167 }
1168
1169 /*
1170 * profile stat keeps the max and min values as integer,
1171 * convert to nsec time so that we can have accurate max.
1172 */
1173 duration *= 1000;
1174
1175 /* skip to the pipe */
1176 while (p < line + len && *p != '|')
1177 p++;
1178
1179 if (*p++ != '|')
1180 return -EINVAL;
1181
1182 /* get function name */
1183 func = skip_spaces(p);
1184
1185 /* skip the closing bracket and the start of comment */
1186 if (*func == '}')
1187 func += 5;
1188
1189 /* remove semi-colon or end of comment at the end */
1190 p = line + len - 1;
1191 while (!isalnum(*p) && *p != ']') {
1192 *p = '\0';
1193 --p;
1194 }
1195
1196 return add_func_duration(ftrace, func, duration);
1197 }
1198
1199 enum perf_ftrace_profile_sort_key {
1200 PFP_SORT_TOTAL = 0,
1201 PFP_SORT_AVG,
1202 PFP_SORT_MAX,
1203 PFP_SORT_COUNT,
1204 PFP_SORT_NAME,
1205 };
1206
1207 static enum perf_ftrace_profile_sort_key profile_sort = PFP_SORT_TOTAL;
1208
cmp_profile_data(const void * a,const void * b)1209 static int cmp_profile_data(const void *a, const void *b)
1210 {
1211 const struct hashmap_entry *e1 = *(const struct hashmap_entry **)a;
1212 const struct hashmap_entry *e2 = *(const struct hashmap_entry **)b;
1213 struct ftrace_profile_data *p1 = e1->pvalue;
1214 struct ftrace_profile_data *p2 = e2->pvalue;
1215 double v1, v2;
1216
1217 switch (profile_sort) {
1218 case PFP_SORT_NAME:
1219 return strcmp(e1->pkey, e2->pkey);
1220 case PFP_SORT_AVG:
1221 v1 = p1->st.mean;
1222 v2 = p2->st.mean;
1223 break;
1224 case PFP_SORT_MAX:
1225 v1 = p1->st.max;
1226 v2 = p2->st.max;
1227 break;
1228 case PFP_SORT_COUNT:
1229 v1 = p1->st.n;
1230 v2 = p2->st.n;
1231 break;
1232 case PFP_SORT_TOTAL:
1233 default:
1234 v1 = p1->st.n * p1->st.mean;
1235 v2 = p2->st.n * p2->st.mean;
1236 break;
1237 }
1238
1239 if (v1 > v2)
1240 return -1;
1241 if (v1 < v2)
1242 return 1;
1243 return 0;
1244 }
1245
print_profile_result(struct perf_ftrace * ftrace)1246 static void print_profile_result(struct perf_ftrace *ftrace)
1247 {
1248 struct hashmap_entry *entry, **profile;
1249 size_t i, nr, bkt;
1250
1251 nr = hashmap__size(ftrace->profile_hash);
1252 if (nr == 0)
1253 return;
1254
1255 profile = calloc(nr, sizeof(*profile));
1256 if (profile == NULL) {
1257 pr_err("failed to allocate memory for the result\n");
1258 return;
1259 }
1260
1261 i = 0;
1262 hashmap__for_each_entry(ftrace->profile_hash, entry, bkt)
1263 profile[i++] = entry;
1264
1265 assert(i == nr);
1266
1267 //cmp_profile_data(profile[0], profile[1]);
1268 qsort(profile, nr, sizeof(*profile), cmp_profile_data);
1269
1270 printf("# %10s %10s %10s %10s %s\n",
1271 "Total (us)", "Avg (us)", "Max (us)", "Count", "Function");
1272
1273 for (i = 0; i < nr; i++) {
1274 const char *name = profile[i]->pkey;
1275 struct ftrace_profile_data *p = profile[i]->pvalue;
1276
1277 printf("%12.3f %10.3f %6"PRIu64".%03"PRIu64" %10.0f %s\n",
1278 p->st.n * p->st.mean / 1000, p->st.mean / 1000,
1279 p->st.max / 1000, p->st.max % 1000, p->st.n, name);
1280 }
1281
1282 free(profile);
1283
1284 hashmap__for_each_entry(ftrace->profile_hash, entry, bkt) {
1285 free((char *)entry->pkey);
1286 free(entry->pvalue);
1287 }
1288
1289 hashmap__free(ftrace->profile_hash);
1290 ftrace->profile_hash = NULL;
1291 }
1292
__cmd_profile(struct perf_ftrace * ftrace)1293 static int __cmd_profile(struct perf_ftrace *ftrace)
1294 {
1295 char *trace_file;
1296 int trace_fd;
1297 char buf[4096];
1298 struct io io;
1299 char *line = NULL;
1300 size_t line_len = 0;
1301
1302 if (prepare_func_profile(ftrace) < 0) {
1303 pr_err("failed to prepare func profiler\n");
1304 goto out;
1305 }
1306
1307 if (reset_tracing_files(ftrace) < 0) {
1308 pr_err("failed to reset ftrace\n");
1309 goto out;
1310 }
1311
1312 /* reset ftrace buffer */
1313 if (write_tracing_file("trace", "0") < 0)
1314 goto out;
1315
1316 if (set_tracing_options(ftrace) < 0)
1317 return -1;
1318
1319 if (write_tracing_file("current_tracer", ftrace->tracer) < 0) {
1320 pr_err("failed to set current_tracer to %s\n", ftrace->tracer);
1321 goto out_reset;
1322 }
1323
1324 setup_pager();
1325
1326 trace_file = get_tracing_file("trace_pipe");
1327 if (!trace_file) {
1328 pr_err("failed to open trace_pipe\n");
1329 goto out_reset;
1330 }
1331
1332 trace_fd = open(trace_file, O_RDONLY);
1333
1334 put_tracing_file(trace_file);
1335
1336 if (trace_fd < 0) {
1337 pr_err("failed to open trace_pipe\n");
1338 goto out_reset;
1339 }
1340
1341 fcntl(trace_fd, F_SETFL, O_NONBLOCK);
1342
1343 if (write_tracing_file("tracing_on", "1") < 0) {
1344 pr_err("can't enable tracing\n");
1345 goto out_close_fd;
1346 }
1347
1348 evlist__start_workload(ftrace->evlist);
1349
1350 io__init(&io, trace_fd, buf, sizeof(buf));
1351 io.timeout_ms = -1;
1352
1353 while (!done && !io.eof) {
1354 if (io__getline(&io, &line, &line_len) < 0)
1355 break;
1356
1357 if (parse_func_duration(ftrace, line, line_len) < 0)
1358 break;
1359 }
1360
1361 write_tracing_file("tracing_on", "0");
1362
1363 if (workload_exec_errno) {
1364 const char *emsg = str_error_r(workload_exec_errno, buf, sizeof(buf));
1365 /* flush stdout first so below error msg appears at the end. */
1366 fflush(stdout);
1367 pr_err("workload failed: %s\n", emsg);
1368 goto out_free_line;
1369 }
1370
1371 /* read remaining buffer contents */
1372 io.timeout_ms = 0;
1373 while (!io.eof) {
1374 if (io__getline(&io, &line, &line_len) < 0)
1375 break;
1376
1377 if (parse_func_duration(ftrace, line, line_len) < 0)
1378 break;
1379 }
1380
1381 print_profile_result(ftrace);
1382
1383 out_free_line:
1384 free(line);
1385 out_close_fd:
1386 close(trace_fd);
1387 out_reset:
1388 reset_tracing_files(ftrace);
1389 out:
1390 return (done && !workload_exec_errno) ? 0 : -1;
1391 }
1392
perf_ftrace_config(const char * var,const char * value,void * cb)1393 static int perf_ftrace_config(const char *var, const char *value, void *cb)
1394 {
1395 struct perf_ftrace *ftrace = cb;
1396
1397 if (!strstarts(var, "ftrace."))
1398 return 0;
1399
1400 if (strcmp(var, "ftrace.tracer"))
1401 return -1;
1402
1403 if (!strcmp(value, "function_graph") ||
1404 !strcmp(value, "function")) {
1405 ftrace->tracer = value;
1406 return 0;
1407 }
1408
1409 pr_err("Please select \"function_graph\" (default) or \"function\"\n");
1410 return -1;
1411 }
1412
list_function_cb(char * str,void * arg)1413 static void list_function_cb(char *str, void *arg)
1414 {
1415 struct strfilter *filter = (struct strfilter *)arg;
1416
1417 if (strfilter__compare(filter, str))
1418 printf("%s", str);
1419 }
1420
opt_list_avail_functions(const struct option * opt __maybe_unused,const char * str,int unset)1421 static int opt_list_avail_functions(const struct option *opt __maybe_unused,
1422 const char *str, int unset)
1423 {
1424 struct strfilter *filter;
1425 const char *err = NULL;
1426 int ret;
1427
1428 if (unset || !str)
1429 return -1;
1430
1431 filter = strfilter__new(str, &err);
1432 if (!filter)
1433 return err ? -EINVAL : -ENOMEM;
1434
1435 ret = strfilter__or(filter, str, &err);
1436 if (ret == -EINVAL) {
1437 pr_err("Filter parse error at %td.\n", err - str + 1);
1438 pr_err("Source: \"%s\"\n", str);
1439 pr_err(" %*c\n", (int)(err - str + 1), '^');
1440 strfilter__delete(filter);
1441 return ret;
1442 }
1443
1444 ret = read_tracing_file_by_line("available_filter_functions",
1445 list_function_cb, filter);
1446 strfilter__delete(filter);
1447 if (ret < 0)
1448 return ret;
1449
1450 exit(0);
1451 }
1452
parse_filter_func(const struct option * opt,const char * str,int unset __maybe_unused)1453 static int parse_filter_func(const struct option *opt, const char *str,
1454 int unset __maybe_unused)
1455 {
1456 struct list_head *head = opt->value;
1457 struct filter_entry *entry;
1458
1459 entry = malloc(sizeof(*entry) + strlen(str) + 1);
1460 if (entry == NULL)
1461 return -ENOMEM;
1462
1463 strcpy(entry->name, str);
1464 list_add_tail(&entry->list, head);
1465
1466 return 0;
1467 }
1468
delete_filter_func(struct list_head * head)1469 static void delete_filter_func(struct list_head *head)
1470 {
1471 struct filter_entry *pos, *tmp;
1472
1473 list_for_each_entry_safe(pos, tmp, head, list) {
1474 list_del_init(&pos->list);
1475 free(pos);
1476 }
1477 }
1478
parse_buffer_size(const struct option * opt,const char * str,int unset)1479 static int parse_buffer_size(const struct option *opt,
1480 const char *str, int unset)
1481 {
1482 unsigned long *s = (unsigned long *)opt->value;
1483 static struct parse_tag tags_size[] = {
1484 { .tag = 'B', .mult = 1 },
1485 { .tag = 'K', .mult = 1 << 10 },
1486 { .tag = 'M', .mult = 1 << 20 },
1487 { .tag = 'G', .mult = 1 << 30 },
1488 { .tag = 0 },
1489 };
1490 unsigned long val;
1491
1492 if (unset) {
1493 *s = 0;
1494 return 0;
1495 }
1496
1497 val = parse_tag_value(str, tags_size);
1498 if (val != (unsigned long) -1) {
1499 if (val < 1024) {
1500 pr_err("buffer size too small, must larger than 1KB.");
1501 return -1;
1502 }
1503 *s = val;
1504 return 0;
1505 }
1506
1507 return -1;
1508 }
1509
parse_func_tracer_opts(const struct option * opt,const char * str,int unset)1510 static int parse_func_tracer_opts(const struct option *opt,
1511 const char *str, int unset)
1512 {
1513 int ret;
1514 struct perf_ftrace *ftrace = (struct perf_ftrace *) opt->value;
1515 struct sublevel_option func_tracer_opts[] = {
1516 { .name = "call-graph", .value_ptr = &ftrace->func_stack_trace },
1517 { .name = "irq-info", .value_ptr = &ftrace->func_irq_info },
1518 { .name = NULL, }
1519 };
1520
1521 if (unset)
1522 return 0;
1523
1524 ret = perf_parse_sublevel_options(str, func_tracer_opts);
1525 if (ret)
1526 return ret;
1527
1528 return 0;
1529 }
1530
parse_graph_tracer_opts(const struct option * opt,const char * str,int unset)1531 static int parse_graph_tracer_opts(const struct option *opt,
1532 const char *str, int unset)
1533 {
1534 int ret;
1535 struct perf_ftrace *ftrace = (struct perf_ftrace *) opt->value;
1536 struct sublevel_option graph_tracer_opts[] = {
1537 { .name = "nosleep-time", .value_ptr = &ftrace->graph_nosleep_time },
1538 { .name = "noirqs", .value_ptr = &ftrace->graph_noirqs },
1539 { .name = "verbose", .value_ptr = &ftrace->graph_verbose },
1540 { .name = "thresh", .value_ptr = &ftrace->graph_thresh },
1541 { .name = "depth", .value_ptr = &ftrace->graph_depth },
1542 { .name = "tail", .value_ptr = &ftrace->graph_tail },
1543 { .name = NULL, }
1544 };
1545
1546 if (unset)
1547 return 0;
1548
1549 ret = perf_parse_sublevel_options(str, graph_tracer_opts);
1550 if (ret)
1551 return ret;
1552
1553 return 0;
1554 }
1555
parse_sort_key(const struct option * opt,const char * str,int unset)1556 static int parse_sort_key(const struct option *opt, const char *str, int unset)
1557 {
1558 enum perf_ftrace_profile_sort_key *key = (void *)opt->value;
1559
1560 if (unset)
1561 return 0;
1562
1563 if (!strcmp(str, "total"))
1564 *key = PFP_SORT_TOTAL;
1565 else if (!strcmp(str, "avg"))
1566 *key = PFP_SORT_AVG;
1567 else if (!strcmp(str, "max"))
1568 *key = PFP_SORT_MAX;
1569 else if (!strcmp(str, "count"))
1570 *key = PFP_SORT_COUNT;
1571 else if (!strcmp(str, "name"))
1572 *key = PFP_SORT_NAME;
1573 else {
1574 pr_err("Unknown sort key: %s\n", str);
1575 return -1;
1576 }
1577 return 0;
1578 }
1579
1580 enum perf_ftrace_subcommand {
1581 PERF_FTRACE_NONE,
1582 PERF_FTRACE_TRACE,
1583 PERF_FTRACE_LATENCY,
1584 PERF_FTRACE_PROFILE,
1585 };
1586
cmd_ftrace(int argc,const char ** argv)1587 int cmd_ftrace(int argc, const char **argv)
1588 {
1589 int ret;
1590 int (*cmd_func)(struct perf_ftrace *) = NULL;
1591 struct perf_ftrace ftrace = {
1592 .tracer = DEFAULT_TRACER,
1593 .target = { .uid = UINT_MAX, },
1594 };
1595 const struct option common_options[] = {
1596 OPT_STRING('p', "pid", &ftrace.target.pid, "pid",
1597 "Trace on existing process id"),
1598 /* TODO: Add short option -t after -t/--tracer can be removed. */
1599 OPT_STRING(0, "tid", &ftrace.target.tid, "tid",
1600 "Trace on existing thread id (exclusive to --pid)"),
1601 OPT_INCR('v', "verbose", &verbose,
1602 "Be more verbose"),
1603 OPT_BOOLEAN('a', "all-cpus", &ftrace.target.system_wide,
1604 "System-wide collection from all CPUs"),
1605 OPT_STRING('C', "cpu", &ftrace.target.cpu_list, "cpu",
1606 "List of cpus to monitor"),
1607 OPT_END()
1608 };
1609 const struct option ftrace_options[] = {
1610 OPT_STRING('t', "tracer", &ftrace.tracer, "tracer",
1611 "Tracer to use: function_graph(default) or function"),
1612 OPT_CALLBACK_DEFAULT('F', "funcs", NULL, "[FILTER]",
1613 "Show available functions to filter",
1614 opt_list_avail_functions, "*"),
1615 OPT_CALLBACK('T', "trace-funcs", &ftrace.filters, "func",
1616 "Trace given functions using function tracer",
1617 parse_filter_func),
1618 OPT_CALLBACK('N', "notrace-funcs", &ftrace.notrace, "func",
1619 "Do not trace given functions", parse_filter_func),
1620 OPT_CALLBACK(0, "func-opts", &ftrace, "options",
1621 "Function tracer options, available options: call-graph,irq-info",
1622 parse_func_tracer_opts),
1623 OPT_CALLBACK('G', "graph-funcs", &ftrace.graph_funcs, "func",
1624 "Trace given functions using function_graph tracer",
1625 parse_filter_func),
1626 OPT_CALLBACK('g', "nograph-funcs", &ftrace.nograph_funcs, "func",
1627 "Set nograph filter on given functions", parse_filter_func),
1628 OPT_CALLBACK(0, "graph-opts", &ftrace, "options",
1629 "Graph tracer options, available options: nosleep-time,noirqs,verbose,thresh=<n>,depth=<n>",
1630 parse_graph_tracer_opts),
1631 OPT_CALLBACK('m', "buffer-size", &ftrace.percpu_buffer_size, "size",
1632 "Size of per cpu buffer, needs to use a B, K, M or G suffix.", parse_buffer_size),
1633 OPT_BOOLEAN(0, "inherit", &ftrace.inherit,
1634 "Trace children processes"),
1635 OPT_INTEGER('D', "delay", &ftrace.target.initial_delay,
1636 "Number of milliseconds to wait before starting tracing after program start"),
1637 OPT_PARENT(common_options),
1638 };
1639 const struct option latency_options[] = {
1640 OPT_CALLBACK('T', "trace-funcs", &ftrace.filters, "func",
1641 "Show latency of given function", parse_filter_func),
1642 #ifdef HAVE_BPF_SKEL
1643 OPT_BOOLEAN('b', "use-bpf", &ftrace.target.use_bpf,
1644 "Use BPF to measure function latency"),
1645 #endif
1646 OPT_BOOLEAN('n', "use-nsec", &ftrace.use_nsec,
1647 "Use nano-second histogram"),
1648 OPT_UINTEGER(0, "bucket-range", &ftrace.bucket_range,
1649 "Bucket range in ms or ns (-n/--use-nsec), default is log2() mode"),
1650 OPT_UINTEGER(0, "min-latency", &ftrace.min_latency,
1651 "Minimum latency (1st bucket). Works only with --bucket-range."),
1652 OPT_UINTEGER(0, "max-latency", &ftrace.max_latency,
1653 "Maximum latency (last bucket). Works only with --bucket-range."),
1654 OPT_BOOLEAN(0, "hide-empty", &ftrace.hide_empty,
1655 "Hide empty buckets in the histogram"),
1656 OPT_PARENT(common_options),
1657 };
1658 const struct option profile_options[] = {
1659 OPT_CALLBACK('T', "trace-funcs", &ftrace.filters, "func",
1660 "Trace given functions using function tracer",
1661 parse_filter_func),
1662 OPT_CALLBACK('N', "notrace-funcs", &ftrace.notrace, "func",
1663 "Do not trace given functions", parse_filter_func),
1664 OPT_CALLBACK('G', "graph-funcs", &ftrace.graph_funcs, "func",
1665 "Trace given functions using function_graph tracer",
1666 parse_filter_func),
1667 OPT_CALLBACK('g', "nograph-funcs", &ftrace.nograph_funcs, "func",
1668 "Set nograph filter on given functions", parse_filter_func),
1669 OPT_CALLBACK('m', "buffer-size", &ftrace.percpu_buffer_size, "size",
1670 "Size of per cpu buffer, needs to use a B, K, M or G suffix.", parse_buffer_size),
1671 OPT_CALLBACK('s', "sort", &profile_sort, "key",
1672 "Sort result by key: total (default), avg, max, count, name.",
1673 parse_sort_key),
1674 OPT_CALLBACK(0, "graph-opts", &ftrace, "options",
1675 "Graph tracer options, available options: nosleep-time,noirqs,thresh=<n>,depth=<n>",
1676 parse_graph_tracer_opts),
1677 OPT_PARENT(common_options),
1678 };
1679 const struct option *options = ftrace_options;
1680
1681 const char * const ftrace_usage[] = {
1682 "perf ftrace [<options>] [<command>]",
1683 "perf ftrace [<options>] -- [<command>] [<options>]",
1684 "perf ftrace {trace|latency|profile} [<options>] [<command>]",
1685 "perf ftrace {trace|latency|profile} [<options>] -- [<command>] [<options>]",
1686 NULL
1687 };
1688 enum perf_ftrace_subcommand subcmd = PERF_FTRACE_NONE;
1689
1690 INIT_LIST_HEAD(&ftrace.filters);
1691 INIT_LIST_HEAD(&ftrace.notrace);
1692 INIT_LIST_HEAD(&ftrace.graph_funcs);
1693 INIT_LIST_HEAD(&ftrace.nograph_funcs);
1694
1695 signal(SIGINT, sig_handler);
1696 signal(SIGUSR1, sig_handler);
1697 signal(SIGCHLD, sig_handler);
1698 signal(SIGPIPE, sig_handler);
1699
1700 if (!check_ftrace_capable())
1701 return -1;
1702
1703 if (!is_ftrace_supported()) {
1704 pr_err("ftrace is not supported on this system\n");
1705 return -ENOTSUP;
1706 }
1707
1708 ret = perf_config(perf_ftrace_config, &ftrace);
1709 if (ret < 0)
1710 return -1;
1711
1712 if (argc > 1) {
1713 if (!strcmp(argv[1], "trace")) {
1714 subcmd = PERF_FTRACE_TRACE;
1715 } else if (!strcmp(argv[1], "latency")) {
1716 subcmd = PERF_FTRACE_LATENCY;
1717 options = latency_options;
1718 } else if (!strcmp(argv[1], "profile")) {
1719 subcmd = PERF_FTRACE_PROFILE;
1720 options = profile_options;
1721 }
1722
1723 if (subcmd != PERF_FTRACE_NONE) {
1724 argc--;
1725 argv++;
1726 }
1727 }
1728 /* for backward compatibility */
1729 if (subcmd == PERF_FTRACE_NONE)
1730 subcmd = PERF_FTRACE_TRACE;
1731
1732 argc = parse_options(argc, argv, options, ftrace_usage,
1733 PARSE_OPT_STOP_AT_NON_OPTION);
1734 if (argc < 0) {
1735 ret = -EINVAL;
1736 goto out_delete_filters;
1737 }
1738
1739 /* Make system wide (-a) the default target. */
1740 if (!argc && target__none(&ftrace.target))
1741 ftrace.target.system_wide = true;
1742
1743 switch (subcmd) {
1744 case PERF_FTRACE_TRACE:
1745 cmd_func = __cmd_ftrace;
1746 break;
1747 case PERF_FTRACE_LATENCY:
1748 if (list_empty(&ftrace.filters)) {
1749 pr_err("Should provide a function to measure\n");
1750 parse_options_usage(ftrace_usage, options, "T", 1);
1751 ret = -EINVAL;
1752 goto out_delete_filters;
1753 }
1754 if (!ftrace.bucket_range && ftrace.min_latency) {
1755 pr_err("--min-latency works only with --bucket-range\n");
1756 parse_options_usage(ftrace_usage, options,
1757 "min-latency", /*short_opt=*/false);
1758 ret = -EINVAL;
1759 goto out_delete_filters;
1760 }
1761 if (ftrace.bucket_range && !ftrace.min_latency) {
1762 /* default min latency should be the bucket range */
1763 ftrace.min_latency = ftrace.bucket_range;
1764 }
1765 if (!ftrace.bucket_range && ftrace.max_latency) {
1766 pr_err("--max-latency works only with --bucket-range\n");
1767 parse_options_usage(ftrace_usage, options,
1768 "max-latency", /*short_opt=*/false);
1769 ret = -EINVAL;
1770 goto out_delete_filters;
1771 }
1772 if (ftrace.bucket_range && ftrace.max_latency &&
1773 ftrace.max_latency < ftrace.min_latency + ftrace.bucket_range) {
1774 /* we need at least 1 bucket excluding min and max buckets */
1775 pr_err("--max-latency must be larger than min-latency + bucket-range\n");
1776 parse_options_usage(ftrace_usage, options,
1777 "max-latency", /*short_opt=*/false);
1778 ret = -EINVAL;
1779 goto out_delete_filters;
1780 }
1781 /* set default unless max_latency is set and valid */
1782 ftrace.bucket_num = NUM_BUCKET;
1783 if (ftrace.bucket_range) {
1784 if (ftrace.max_latency)
1785 ftrace.bucket_num = (ftrace.max_latency - ftrace.min_latency) /
1786 ftrace.bucket_range + 2;
1787 else
1788 /* default max latency should depend on bucket range and num_buckets */
1789 ftrace.max_latency = (NUM_BUCKET - 2) * ftrace.bucket_range +
1790 ftrace.min_latency;
1791 }
1792 cmd_func = __cmd_latency;
1793 break;
1794 case PERF_FTRACE_PROFILE:
1795 cmd_func = __cmd_profile;
1796 break;
1797 case PERF_FTRACE_NONE:
1798 default:
1799 pr_err("Invalid subcommand\n");
1800 ret = -EINVAL;
1801 goto out_delete_filters;
1802 }
1803
1804 ret = target__validate(&ftrace.target);
1805 if (ret) {
1806 char errbuf[512];
1807
1808 target__strerror(&ftrace.target, ret, errbuf, 512);
1809 pr_err("%s\n", errbuf);
1810 goto out_delete_filters;
1811 }
1812
1813 ftrace.evlist = evlist__new();
1814 if (ftrace.evlist == NULL) {
1815 ret = -ENOMEM;
1816 goto out_delete_filters;
1817 }
1818
1819 ret = evlist__create_maps(ftrace.evlist, &ftrace.target);
1820 if (ret < 0)
1821 goto out_delete_evlist;
1822
1823 if (argc) {
1824 ret = evlist__prepare_workload(ftrace.evlist, &ftrace.target,
1825 argv, false,
1826 ftrace__workload_exec_failed_signal);
1827 if (ret < 0)
1828 goto out_delete_evlist;
1829 }
1830
1831 ret = cmd_func(&ftrace);
1832
1833 out_delete_evlist:
1834 evlist__delete(ftrace.evlist);
1835
1836 out_delete_filters:
1837 delete_filter_func(&ftrace.filters);
1838 delete_filter_func(&ftrace.notrace);
1839 delete_filter_func(&ftrace.graph_funcs);
1840 delete_filter_func(&ftrace.nograph_funcs);
1841
1842 return ret;
1843 }
1844