tools/perf/builtin-ftrace.c

0001 // SPDX-License-Identifier: GPL-2.0-only
0002 /*
0003  * builtin-ftrace.c
0004  *
0005  * Copyright (c) 2013  LG Electronics,  Namhyung Kim <namhyung@kernel.org>
0006  * Copyright (c) 2020  Changbin Du <changbin.du@gmail.com>, significant enhancement.
0007  */
0008
0009 #include "builtin.h"
0010
0011 #include <errno.h>
0012 #include <unistd.h>
0013 #include <signal.h>
0014 #include <stdlib.h>
0015 #include <fcntl.h>
0016 #include <math.h>
0017 #include <poll.h>
0018 #include <ctype.h>
0019 #include <linux/capability.h>
0020 #include <linux/string.h>
0021
0022 #include "debug.h"
0023 #include <subcmd/pager.h>
0024 #include <subcmd/parse-options.h>
0025 #include <api/fs/tracing_path.h>
0026 #include "evlist.h"
0027 #include "target.h"
0028 #include "cpumap.h"
0029 #include "thread_map.h"
0030 #include "strfilter.h"
0031 #include "util/cap.h"
0032 #include "util/config.h"
0033 #include "util/ftrace.h"
0034 #include "util/units.h"
0035 #include "util/parse-sublevel-options.h"
0036
0037 #define DEFAULT_TRACER  "function_graph"
0038
0039 static volatile int workload_exec_errno;
0040 static bool done;
0041
0042 static void sig_handler(int sig __maybe_unused)
0043 {
0044     done = true;
0045 }
0046
0047 /*
0048  * evlist__prepare_workload will send a SIGUSR1 if the fork fails, since
0049  * we asked by setting its exec_error to the function below,
0050  * ftrace__workload_exec_failed_signal.
0051  *
0052  * XXX We need to handle this more appropriately, emitting an error, etc.
0053  */
0054 static void ftrace__workload_exec_failed_signal(int signo __maybe_unused,
0055                         siginfo_t *info __maybe_unused,
0056                         void *ucontext __maybe_unused)
0057 {
0058     workload_exec_errno = info->si_value.sival_int;
0059     done = true;
0060 }
0061
0062 static int __write_tracing_file(const char *name, const char *val, bool append)
0063 {
0064     char *file;
0065     int fd, ret = -1;
0066     ssize_t size = strlen(val);
0067     int flags = O_WRONLY;
0068     char errbuf[512];
0069     char *val_copy;
0070
0071     file = get_tracing_file(name);
0072     if (!file) {
0073         pr_debug("cannot get tracing file: %s\n", name);
0074         return -1;
0075     }
0076
0077     if (append)
0078         flags |= O_APPEND;
0079     else
0080         flags |= O_TRUNC;
0081
0082     fd = open(file, flags);
0083     if (fd < 0) {
0084         pr_debug("cannot open tracing file: %s: %s\n",
0085              name, str_error_r(errno, errbuf, sizeof(errbuf)));
0086         goto out;
0087     }
0088
0089     /*
0090      * Copy the original value and append a '\n'. Without this,
0091      * the kernel can hide possible errors.
0092      */
0093     val_copy = strdup(val);
0094     if (!val_copy)
0095         goto out_close;
0096     val_copy[size] = '\n';
0097
0098     if (write(fd, val_copy, size + 1) == size + 1)
0099         ret = 0;
0100     else
0101         pr_debug("write '%s' to tracing/%s failed: %s\n",
0102              val, name, str_error_r(errno, errbuf, sizeof(errbuf)));
0103
0104     free(val_copy);
0105 out_close:
0106     close(fd);
0107 out:
0108     put_tracing_file(file);
0109     return ret;
0110 }
0111
0112 static int write_tracing_file(const char *name, const char *val)
0113 {
0114     return __write_tracing_file(name, val, false);
0115 }
0116
0117 static int append_tracing_file(const char *name, const char *val)
0118 {
0119     return __write_tracing_file(name, val, true);
0120 }
0121
0122 static int read_tracing_file_to_stdout(const char *name)
0123 {
0124     char buf[4096];
0125     char *file;
0126     int fd;
0127     int ret = -1;
0128
0129     file = get_tracing_file(name);
0130     if (!file) {
0131         pr_debug("cannot get tracing file: %s\n", name);
0132         return -1;
0133     }
0134
0135     fd = open(file, O_RDONLY);
0136     if (fd < 0) {
0137         pr_debug("cannot open tracing file: %s: %s\n",
0138              name, str_error_r(errno, buf, sizeof(buf)));
0139         goto out;
0140     }
0141
0142     /* read contents to stdout */
0143     while (true) {
0144         int n = read(fd, buf, sizeof(buf));
0145         if (n == 0)
0146             break;
0147         else if (n < 0)
0148             goto out_close;
0149
0150         if (fwrite(buf, n, 1, stdout) != 1)
0151             goto out_close;
0152     }
0153     ret = 0;
0154
0155 out_close:
0156     close(fd);
0157 out:
0158     put_tracing_file(file);
0159     return ret;
0160 }
0161
0162 static int read_tracing_file_by_line(const char *name,
0163                      void (*cb)(char *str, void *arg),
0164                      void *cb_arg)
0165 {
0166     char *line = NULL;
0167     size_t len = 0;
0168     char *file;
0169     FILE *fp;
0170
0171     file = get_tracing_file(name);
0172     if (!file) {
0173         pr_debug("cannot get tracing file: %s\n", name);
0174         return -1;
0175     }
0176
0177     fp = fopen(file, "r");
0178     if (fp == NULL) {
0179         pr_debug("cannot open tracing file: %s\n", name);
0180         put_tracing_file(file);
0181         return -1;
0182     }
0183
0184     while (getline(&line, &len, fp) != -1) {
0185         cb(line, cb_arg);
0186     }
0187
0188     if (line)
0189         free(line);
0190
0191     fclose(fp);
0192     put_tracing_file(file);
0193     return 0;
0194 }
0195
0196 static int write_tracing_file_int(const char *name, int value)
0197 {
0198     char buf[16];
0199
0200     snprintf(buf, sizeof(buf), "%d", value);
0201     if (write_tracing_file(name, buf) < 0)
0202         return -1;
0203
0204     return 0;
0205 }
0206
0207 static int write_tracing_option_file(const char *name, const char *val)
0208 {
0209     char *file;
0210     int ret;
0211
0212     if (asprintf(&file, "options/%s", name) < 0)
0213         return -1;
0214
0215     ret = __write_tracing_file(file, val, false);
0216     free(file);
0217     return ret;
0218 }
0219
0220 static int reset_tracing_cpu(void);
0221 static void reset_tracing_filters(void);
0222
0223 static void reset_tracing_options(struct perf_ftrace *ftrace __maybe_unused)
0224 {
0225     write_tracing_option_file("function-fork", "0");
0226     write_tracing_option_file("func_stack_trace", "0");
0227     write_tracing_option_file("sleep-time", "1");
0228     write_tracing_option_file("funcgraph-irqs", "1");
0229     write_tracing_option_file("funcgraph-proc", "0");
0230     write_tracing_option_file("funcgraph-abstime", "0");
0231     write_tracing_option_file("latency-format", "0");
0232     write_tracing_option_file("irq-info", "0");
0233 }
0234
0235 static int reset_tracing_files(struct perf_ftrace *ftrace __maybe_unused)
0236 {
0237     if (write_tracing_file("tracing_on", "0") < 0)
0238         return -1;
0239
0240     if (write_tracing_file("current_tracer", "nop") < 0)
0241         return -1;
0242
0243     if (write_tracing_file("set_ftrace_pid", " ") < 0)
0244         return -1;
0245
0246     if (reset_tracing_cpu() < 0)
0247         return -1;
0248
0249     if (write_tracing_file("max_graph_depth", "0") < 0)
0250         return -1;
0251
0252     if (write_tracing_file("tracing_thresh", "0") < 0)
0253         return -1;
0254
0255     reset_tracing_filters();
0256     reset_tracing_options(ftrace);
0257     return 0;
0258 }
0259
0260 static int set_tracing_pid(struct perf_ftrace *ftrace)
0261 {
0262     int i;
0263     char buf[16];
0264
0265     if (target__has_cpu(&ftrace->target))
0266         return 0;
0267
0268     for (i = 0; i < perf_thread_map__nr(ftrace->evlist->core.threads); i++) {
0269         scnprintf(buf, sizeof(buf), "%d",
0270               perf_thread_map__pid(ftrace->evlist->core.threads, i));
0271         if (append_tracing_file("set_ftrace_pid", buf) < 0)
0272             return -1;
0273     }
0274     return 0;
0275 }
0276
0277 static int set_tracing_cpumask(struct perf_cpu_map *cpumap)
0278 {
0279     char *cpumask;
0280     size_t mask_size;
0281     int ret;
0282     int last_cpu;
0283
0284     last_cpu = perf_cpu_map__cpu(cpumap, perf_cpu_map__nr(cpumap) - 1).cpu;
0285     mask_size = last_cpu / 4 + 2; /* one more byte for EOS */
0286     mask_size += last_cpu / 32; /* ',' is needed for every 32th cpus */
0287
0288     cpumask = malloc(mask_size);
0289     if (cpumask == NULL) {
0290         pr_debug("failed to allocate cpu mask\n");
0291         return -1;
0292     }
0293
0294     cpu_map__snprint_mask(cpumap, cpumask, mask_size);
0295
0296     ret = write_tracing_file("tracing_cpumask", cpumask);
0297
0298     free(cpumask);
0299     return ret;
0300 }
0301
0302 static int set_tracing_cpu(struct perf_ftrace *ftrace)
0303 {
0304     struct perf_cpu_map *cpumap = ftrace->evlist->core.user_requested_cpus;
0305
0306     if (!target__has_cpu(&ftrace->target))
0307         return 0;
0308
0309     return set_tracing_cpumask(cpumap);
0310 }
0311
0312 static int set_tracing_func_stack_trace(struct perf_ftrace *ftrace)
0313 {
0314     if (!ftrace->func_stack_trace)
0315         return 0;
0316
0317     if (write_tracing_option_file("func_stack_trace", "1") < 0)
0318         return -1;
0319
0320     return 0;
0321 }
0322
0323 static int set_tracing_func_irqinfo(struct perf_ftrace *ftrace)
0324 {
0325     if (!ftrace->func_irq_info)
0326         return 0;
0327
0328     if (write_tracing_option_file("irq-info", "1") < 0)
0329         return -1;
0330
0331     return 0;
0332 }
0333
0334 static int reset_tracing_cpu(void)
0335 {
0336     struct perf_cpu_map *cpumap = perf_cpu_map__new(NULL);
0337     int ret;
0338
0339     ret = set_tracing_cpumask(cpumap);
0340     perf_cpu_map__put(cpumap);
0341     return ret;
0342 }
0343
0344 static int __set_tracing_filter(const char *filter_file, struct list_head *funcs)
0345 {
0346     struct filter_entry *pos;
0347
0348     list_for_each_entry(pos, funcs, list) {
0349         if (append_tracing_file(filter_file, pos->name) < 0)
0350             return -1;
0351     }
0352
0353     return 0;
0354 }
0355
0356 static int set_tracing_filters(struct perf_ftrace *ftrace)
0357 {
0358     int ret;
0359
0360     ret = __set_tracing_filter("set_ftrace_filter", &ftrace->filters);
0361     if (ret < 0)
0362         return ret;
0363
0364     ret = __set_tracing_filter("set_ftrace_notrace", &ftrace->notrace);
0365     if (ret < 0)
0366         return ret;
0367
0368     ret = __set_tracing_filter("set_graph_function", &ftrace->graph_funcs);
0369     if (ret < 0)
0370         return ret;
0371
0372     /* old kernels do not have this filter */
0373     __set_tracing_filter("set_graph_notrace", &ftrace->nograph_funcs);
0374
0375     return ret;
0376 }
0377
0378 static void reset_tracing_filters(void)
0379 {
0380     write_tracing_file("set_ftrace_filter", " ");
0381     write_tracing_file("set_ftrace_notrace", " ");
0382     write_tracing_file("set_graph_function", " ");
0383     write_tracing_file("set_graph_notrace", " ");
0384 }
0385
0386 static int set_tracing_depth(struct perf_ftrace *ftrace)
0387 {
0388     if (ftrace->graph_depth == 0)
0389         return 0;
0390
0391     if (ftrace->graph_depth < 0) {
0392         pr_err("invalid graph depth: %d\n", ftrace->graph_depth);
0393         return -1;
0394     }
0395
0396     if (write_tracing_file_int("max_graph_depth", ftrace->graph_depth) < 0)
0397         return -1;
0398
0399     return 0;
0400 }
0401
0402 static int set_tracing_percpu_buffer_size(struct perf_ftrace *ftrace)
0403 {
0404     int ret;
0405
0406     if (ftrace->percpu_buffer_size == 0)
0407         return 0;
0408
0409     ret = write_tracing_file_int("buffer_size_kb",
0410                      ftrace->percpu_buffer_size / 1024);
0411     if (ret < 0)
0412         return ret;
0413
0414     return 0;
0415 }
0416
0417 static int set_tracing_trace_inherit(struct perf_ftrace *ftrace)
0418 {
0419     if (!ftrace->inherit)
0420         return 0;
0421
0422     if (write_tracing_option_file("function-fork", "1") < 0)
0423         return -1;
0424
0425     return 0;
0426 }
0427
0428 static int set_tracing_sleep_time(struct perf_ftrace *ftrace)
0429 {
0430     if (!ftrace->graph_nosleep_time)
0431         return 0;
0432
0433     if (write_tracing_option_file("sleep-time", "0") < 0)
0434         return -1;
0435
0436     return 0;
0437 }
0438
0439 static int set_tracing_funcgraph_irqs(struct perf_ftrace *ftrace)
0440 {
0441     if (!ftrace->graph_noirqs)
0442         return 0;
0443
0444     if (write_tracing_option_file("funcgraph-irqs", "0") < 0)
0445         return -1;
0446
0447     return 0;
0448 }
0449
0450 static int set_tracing_funcgraph_verbose(struct perf_ftrace *ftrace)
0451 {
0452     if (!ftrace->graph_verbose)
0453         return 0;
0454
0455     if (write_tracing_option_file("funcgraph-proc", "1") < 0)
0456         return -1;
0457
0458     if (write_tracing_option_file("funcgraph-abstime", "1") < 0)
0459         return -1;
0460
0461     if (write_tracing_option_file("latency-format", "1") < 0)
0462         return -1;
0463
0464     return 0;
0465 }
0466
0467 static int set_tracing_thresh(struct perf_ftrace *ftrace)
0468 {
0469     int ret;
0470
0471     if (ftrace->graph_thresh == 0)
0472         return 0;
0473
0474     ret = write_tracing_file_int("tracing_thresh", ftrace->graph_thresh);
0475     if (ret < 0)
0476         return ret;
0477
0478     return 0;
0479 }
0480
0481 static int set_tracing_options(struct perf_ftrace *ftrace)
0482 {
0483     if (set_tracing_pid(ftrace) < 0) {
0484         pr_err("failed to set ftrace pid\n");
0485         return -1;
0486     }
0487
0488     if (set_tracing_cpu(ftrace) < 0) {
0489         pr_err("failed to set tracing cpumask\n");
0490         return -1;
0491     }
0492
0493     if (set_tracing_func_stack_trace(ftrace) < 0) {
0494         pr_err("failed to set tracing option func_stack_trace\n");
0495         return -1;
0496     }
0497
0498     if (set_tracing_func_irqinfo(ftrace) < 0) {
0499         pr_err("failed to set tracing option irq-info\n");
0500         return -1;
0501     }
0502
0503     if (set_tracing_filters(ftrace) < 0) {
0504         pr_err("failed to set tracing filters\n");
0505         return -1;
0506     }
0507
0508     if (set_tracing_depth(ftrace) < 0) {
0509         pr_err("failed to set graph depth\n");
0510         return -1;
0511     }
0512
0513     if (set_tracing_percpu_buffer_size(ftrace) < 0) {
0514         pr_err("failed to set tracing per-cpu buffer size\n");
0515         return -1;
0516     }
0517
0518     if (set_tracing_trace_inherit(ftrace) < 0) {
0519         pr_err("failed to set tracing option function-fork\n");
0520         return -1;
0521     }
0522
0523     if (set_tracing_sleep_time(ftrace) < 0) {
0524         pr_err("failed to set tracing option sleep-time\n");
0525         return -1;
0526     }
0527
0528     if (set_tracing_funcgraph_irqs(ftrace) < 0) {
0529         pr_err("failed to set tracing option funcgraph-irqs\n");
0530         return -1;
0531     }
0532
0533     if (set_tracing_funcgraph_verbose(ftrace) < 0) {
0534         pr_err("failed to set tracing option funcgraph-proc/funcgraph-abstime\n");
0535         return -1;
0536     }
0537
0538     if (set_tracing_thresh(ftrace) < 0) {
0539         pr_err("failed to set tracing thresh\n");
0540         return -1;
0541     }
0542
0543     return 0;
0544 }
0545
0546 static void select_tracer(struct perf_ftrace *ftrace)
0547 {
0548     bool graph = !list_empty(&ftrace->graph_funcs) ||
0549              !list_empty(&ftrace->nograph_funcs);
0550     bool func = !list_empty(&ftrace->filters) ||
0551             !list_empty(&ftrace->notrace);
0552
0553     /* The function_graph has priority over function tracer. */
0554     if (graph)
0555         ftrace->tracer = "function_graph";
0556     else if (func)
0557         ftrace->tracer = "function";
0558     /* Otherwise, the default tracer is used. */
0559
0560     pr_debug("%s tracer is used\n", ftrace->tracer);
0561 }
0562
0563 static int __cmd_ftrace(struct perf_ftrace *ftrace)
0564 {
0565     char *trace_file;
0566     int trace_fd;
0567     char buf[4096];
0568     struct pollfd pollfd = {
0569         .events = POLLIN,
0570     };
0571
0572     if (!(perf_cap__capable(CAP_PERFMON) ||
0573           perf_cap__capable(CAP_SYS_ADMIN))) {
0574         pr_err("ftrace only works for %s!\n",
0575 #ifdef HAVE_LIBCAP_SUPPORT
0576         "users with the CAP_PERFMON or CAP_SYS_ADMIN capability"
0577 #else
0578         "root"
0579 #endif
0580         );
0581         return -1;
0582     }
0583
0584     select_tracer(ftrace);
0585
0586     if (reset_tracing_files(ftrace) < 0) {
0587         pr_err("failed to reset ftrace\n");
0588         goto out;
0589     }
0590
0591     /* reset ftrace buffer */
0592     if (write_tracing_file("trace", "0") < 0)
0593         goto out;
0594
0595     if (set_tracing_options(ftrace) < 0)
0596         goto out_reset;
0597
0598     if (write_tracing_file("current_tracer", ftrace->tracer) < 0) {
0599         pr_err("failed to set current_tracer to %s\n", ftrace->tracer);
0600         goto out_reset;
0601     }
0602
0603     setup_pager();
0604
0605     trace_file = get_tracing_file("trace_pipe");
0606     if (!trace_file) {
0607         pr_err("failed to open trace_pipe\n");
0608         goto out_reset;
0609     }
0610
0611     trace_fd = open(trace_file, O_RDONLY);
0612
0613     put_tracing_file(trace_file);
0614
0615     if (trace_fd < 0) {
0616         pr_err("failed to open trace_pipe\n");
0617         goto out_reset;
0618     }
0619
0620     fcntl(trace_fd, F_SETFL, O_NONBLOCK);
0621     pollfd.fd = trace_fd;
0622
0623     /* display column headers */
0624     read_tracing_file_to_stdout("trace");
0625
0626     if (!ftrace->initial_delay) {
0627         if (write_tracing_file("tracing_on", "1") < 0) {
0628             pr_err("can't enable tracing\n");
0629             goto out_close_fd;
0630         }
0631     }
0632
0633     evlist__start_workload(ftrace->evlist);
0634
0635     if (ftrace->initial_delay) {
0636         usleep(ftrace->initial_delay * 1000);
0637         if (write_tracing_file("tracing_on", "1") < 0) {
0638             pr_err("can't enable tracing\n");
0639             goto out_close_fd;
0640         }
0641     }
0642
0643     while (!done) {
0644         if (poll(&pollfd, 1, -1) < 0)
0645             break;
0646
0647         if (pollfd.revents & POLLIN) {
0648             int n = read(trace_fd, buf, sizeof(buf));
0649             if (n < 0)
0650                 break;
0651             if (fwrite(buf, n, 1, stdout) != 1)
0652                 break;
0653         }
0654     }
0655
0656     write_tracing_file("tracing_on", "0");
0657
0658     if (workload_exec_errno) {
0659         const char *emsg = str_error_r(workload_exec_errno, buf, sizeof(buf));
0660         /* flush stdout first so below error msg appears at the end. */
0661         fflush(stdout);
0662         pr_err("workload failed: %s\n", emsg);
0663         goto out_close_fd;
0664     }
0665
0666     /* read remaining buffer contents */
0667     while (true) {
0668         int n = read(trace_fd, buf, sizeof(buf));
0669         if (n <= 0)
0670             break;
0671         if (fwrite(buf, n, 1, stdout) != 1)
0672             break;
0673     }
0674
0675 out_close_fd:
0676     close(trace_fd);
0677 out_reset:
0678     reset_tracing_files(ftrace);
0679 out:
0680     return (done && !workload_exec_errno) ? 0 : -1;
0681 }
0682
0683 static void make_histogram(int buckets[], char *buf, size_t len, char *linebuf,
0684                bool use_nsec)
0685 {
0686     char *p, *q;
0687     char *unit;
0688     double num;
0689     int i;
0690
0691     /* ensure NUL termination */
0692     buf[len] = '\0';
0693
0694     /* handle data line by line */
0695     for (p = buf; (q = strchr(p, '\n')) != NULL; p = q + 1) {
0696         *q = '\0';
0697         /* move it to the line buffer */
0698         strcat(linebuf, p);
0699
0700         /*
0701          * parse trace output to get function duration like in
0702          *
0703          * # tracer: function_graph
0704          * #
0705          * # CPU  DURATION                  FUNCTION CALLS
0706          * # |     |   |                     |   |   |   |
0707          *  1) + 10.291 us   |  do_filp_open();
0708          *  1)   4.889 us    |  do_filp_open();
0709          *  1)   6.086 us    |  do_filp_open();
0710          *
0711          */
0712         if (linebuf[0] == '#')
0713             goto next;
0714
0715         /* ignore CPU */
0716         p = strchr(linebuf, ')');
0717         if (p == NULL)
0718             p = linebuf;
0719
0720         while (*p && !isdigit(*p) && (*p != '|'))
0721             p++;
0722
0723         /* no duration */
0724         if (*p == '\0' || *p == '|')
0725             goto next;
0726
0727         num = strtod(p, &unit);
0728         if (!unit || strncmp(unit, " us", 3))
0729             goto next;
0730
0731         if (use_nsec)
0732             num *= 1000;
0733
0734         i = log2(num);
0735         if (i < 0)
0736             i = 0;
0737         if (i >= NUM_BUCKET)
0738             i = NUM_BUCKET - 1;
0739
0740         buckets[i]++;
0741
0742 next:
0743         /* empty the line buffer for the next output  */
0744         linebuf[0] = '\0';
0745     }
0746
0747     /* preserve any remaining output (before newline) */
0748     strcat(linebuf, p);
0749 }
0750
0751 static void display_histogram(int buckets[], bool use_nsec)
0752 {
0753     int i;
0754     int total = 0;
0755     int bar_total = 46;  /* to fit in 80 column */
0756     char bar[] = "###############################################";
0757     int bar_len;
0758
0759     for (i = 0; i < NUM_BUCKET; i++)
0760         total += buckets[i];
0761
0762     if (total == 0) {
0763         printf("No data found\n");
0764         return;
0765     }
0766
0767     printf("# %14s | %10s | %-*s |\n",
0768            "  DURATION    ", "COUNT", bar_total, "GRAPH");
0769
0770     bar_len = buckets[0] * bar_total / total;
0771     printf("  %4d - %-4d %s | %10d | %.*s%*s |\n",
0772            0, 1, "us", buckets[0], bar_len, bar, bar_total - bar_len, "");
0773
0774     for (i = 1; i < NUM_BUCKET - 1; i++) {
0775         int start = (1 << (i - 1));
0776         int stop = 1 << i;
0777         const char *unit = use_nsec ? "ns" : "us";
0778
0779         if (start >= 1024) {
0780             start >>= 10;
0781             stop >>= 10;
0782             unit = use_nsec ? "us" : "ms";
0783         }
0784         bar_len = buckets[i] * bar_total / total;
0785         printf("  %4d - %-4d %s | %10d | %.*s%*s |\n",
0786                start, stop, unit, buckets[i], bar_len, bar,
0787                bar_total - bar_len, "");
0788     }
0789
0790     bar_len = buckets[NUM_BUCKET - 1] * bar_total / total;
0791     printf("  %4d - %-4s %s | %10d | %.*s%*s |\n",
0792            1, "...", use_nsec ? "ms" : " s", buckets[NUM_BUCKET - 1],
0793            bar_len, bar, bar_total - bar_len, "");
0794
0795 }
0796
0797 static int prepare_func_latency(struct perf_ftrace *ftrace)
0798 {
0799     char *trace_file;
0800     int fd;
0801
0802     if (ftrace->target.use_bpf)
0803         return perf_ftrace__latency_prepare_bpf(ftrace);
0804
0805     if (reset_tracing_files(ftrace) < 0) {
0806         pr_err("failed to reset ftrace\n");
0807         return -1;
0808     }
0809
0810     /* reset ftrace buffer */
0811     if (write_tracing_file("trace", "0") < 0)
0812         return -1;
0813
0814     if (set_tracing_options(ftrace) < 0)
0815         return -1;
0816
0817     /* force to use the function_graph tracer to track duration */
0818     if (write_tracing_file("current_tracer", "function_graph") < 0) {
0819         pr_err("failed to set current_tracer to function_graph\n");
0820         return -1;
0821     }
0822
0823     trace_file = get_tracing_file("trace_pipe");
0824     if (!trace_file) {
0825         pr_err("failed to open trace_pipe\n");
0826         return -1;
0827     }
0828
0829     fd = open(trace_file, O_RDONLY);
0830     if (fd < 0)
0831         pr_err("failed to open trace_pipe\n");
0832
0833     put_tracing_file(trace_file);
0834     return fd;
0835 }
0836
0837 static int start_func_latency(struct perf_ftrace *ftrace)
0838 {
0839     if (ftrace->target.use_bpf)
0840         return perf_ftrace__latency_start_bpf(ftrace);
0841
0842     if (write_tracing_file("tracing_on", "1") < 0) {
0843         pr_err("can't enable tracing\n");
0844         return -1;
0845     }
0846
0847     return 0;
0848 }
0849
0850 static int stop_func_latency(struct perf_ftrace *ftrace)
0851 {
0852     if (ftrace->target.use_bpf)
0853         return perf_ftrace__latency_stop_bpf(ftrace);
0854
0855     write_tracing_file("tracing_on", "0");
0856     return 0;
0857 }
0858
0859 static int read_func_latency(struct perf_ftrace *ftrace, int buckets[])
0860 {
0861     if (ftrace->target.use_bpf)
0862         return perf_ftrace__latency_read_bpf(ftrace, buckets);
0863
0864     return 0;
0865 }
0866
0867 static int cleanup_func_latency(struct perf_ftrace *ftrace)
0868 {
0869     if (ftrace->target.use_bpf)
0870         return perf_ftrace__latency_cleanup_bpf(ftrace);
0871
0872     reset_tracing_files(ftrace);
0873     return 0;
0874 }
0875
0876 static int __cmd_latency(struct perf_ftrace *ftrace)
0877 {
0878     int trace_fd;
0879     char buf[4096];
0880     char line[256];
0881     struct pollfd pollfd = {
0882         .events = POLLIN,
0883     };
0884     int buckets[NUM_BUCKET] = { };
0885
0886     if (!(perf_cap__capable(CAP_PERFMON) ||
0887           perf_cap__capable(CAP_SYS_ADMIN))) {
0888         pr_err("ftrace only works for %s!\n",
0889 #ifdef HAVE_LIBCAP_SUPPORT
0890         "users with the CAP_PERFMON or CAP_SYS_ADMIN capability"
0891 #else
0892         "root"
0893 #endif
0894         );
0895         return -1;
0896     }
0897
0898     trace_fd = prepare_func_latency(ftrace);
0899     if (trace_fd < 0)
0900         goto out;
0901
0902     fcntl(trace_fd, F_SETFL, O_NONBLOCK);
0903     pollfd.fd = trace_fd;
0904
0905     if (start_func_latency(ftrace) < 0)
0906         goto out;
0907
0908     evlist__start_workload(ftrace->evlist);
0909
0910     line[0] = '\0';
0911     while (!done) {
0912         if (poll(&pollfd, 1, -1) < 0)
0913             break;
0914
0915         if (pollfd.revents & POLLIN) {
0916             int n = read(trace_fd, buf, sizeof(buf) - 1);
0917             if (n < 0)
0918                 break;
0919
0920             make_histogram(buckets, buf, n, line, ftrace->use_nsec);
0921         }
0922     }
0923
0924     stop_func_latency(ftrace);
0925
0926     if (workload_exec_errno) {
0927         const char *emsg = str_error_r(workload_exec_errno, buf, sizeof(buf));
0928         pr_err("workload failed: %s\n", emsg);
0929         goto out;
0930     }
0931
0932     /* read remaining buffer contents */
0933     while (!ftrace->target.use_bpf) {
0934         int n = read(trace_fd, buf, sizeof(buf) - 1);
0935         if (n <= 0)
0936             break;
0937         make_histogram(buckets, buf, n, line, ftrace->use_nsec);
0938     }
0939
0940     read_func_latency(ftrace, buckets);
0941
0942     display_histogram(buckets, ftrace->use_nsec);
0943
0944 out:
0945     close(trace_fd);
0946     cleanup_func_latency(ftrace);
0947
0948     return (done && !workload_exec_errno) ? 0 : -1;
0949 }
0950
0951 static int perf_ftrace_config(const char *var, const char *value, void *cb)
0952 {
0953     struct perf_ftrace *ftrace = cb;
0954
0955     if (!strstarts(var, "ftrace."))
0956         return 0;
0957
0958     if (strcmp(var, "ftrace.tracer"))
0959         return -1;
0960
0961     if (!strcmp(value, "function_graph") ||
0962         !strcmp(value, "function")) {
0963         ftrace->tracer = value;
0964         return 0;
0965     }
0966
0967     pr_err("Please select \"function_graph\" (default) or \"function\"\n");
0968     return -1;
0969 }
0970
0971 static void list_function_cb(char *str, void *arg)
0972 {
0973     struct strfilter *filter = (struct strfilter *)arg;
0974
0975     if (strfilter__compare(filter, str))
0976         printf("%s", str);
0977 }
0978
0979 static int opt_list_avail_functions(const struct option *opt __maybe_unused,
0980                     const char *str, int unset)
0981 {
0982     struct strfilter *filter;
0983     const char *err = NULL;
0984     int ret;
0985
0986     if (unset || !str)
0987         return -1;
0988
0989     filter = strfilter__new(str, &err);
0990     if (!filter)
0991         return err ? -EINVAL : -ENOMEM;
0992
0993     ret = strfilter__or(filter, str, &err);
0994     if (ret == -EINVAL) {
0995         pr_err("Filter parse error at %td.\n", err - str + 1);
0996         pr_err("Source: \"%s\"\n", str);
0997         pr_err("         %*c\n", (int)(err - str + 1), '^');
0998         strfilter__delete(filter);
0999         return ret;
1000     }
1001
1002     ret = read_tracing_file_by_line("available_filter_functions",
1003                     list_function_cb, filter);
1004     strfilter__delete(filter);
1005     if (ret < 0)
1006         return ret;
1007
1008     exit(0);
1009 }
1010
1011 static int parse_filter_func(const struct option *opt, const char *str,
1012                  int unset __maybe_unused)
1013 {
1014     struct list_head *head = opt->value;
1015     struct filter_entry *entry;
1016
1017     entry = malloc(sizeof(*entry) + strlen(str) + 1);
1018     if (entry == NULL)
1019         return -ENOMEM;
1020
1021     strcpy(entry->name, str);
1022     list_add_tail(&entry->list, head);
1023
1024     return 0;
1025 }
1026
1027 static void delete_filter_func(struct list_head *head)
1028 {
1029     struct filter_entry *pos, *tmp;
1030
1031     list_for_each_entry_safe(pos, tmp, head, list) {
1032         list_del_init(&pos->list);
1033         free(pos);
1034     }
1035 }
1036
1037 static int parse_buffer_size(const struct option *opt,
1038                  const char *str, int unset)
1039 {
1040     unsigned long *s = (unsigned long *)opt->value;
1041     static struct parse_tag tags_size[] = {
1042         { .tag  = 'B', .mult = 1       },
1043         { .tag  = 'K', .mult = 1 << 10 },
1044         { .tag  = 'M', .mult = 1 << 20 },
1045         { .tag  = 'G', .mult = 1 << 30 },
1046         { .tag  = 0 },
1047     };
1048     unsigned long val;
1049
1050     if (unset) {
1051         *s = 0;
1052         return 0;
1053     }
1054
1055     val = parse_tag_value(str, tags_size);
1056     if (val != (unsigned long) -1) {
1057         if (val < 1024) {
1058             pr_err("buffer size too small, must larger than 1KB.");
1059             return -1;
1060         }
1061         *s = val;
1062         return 0;
1063     }
1064
1065     return -1;
1066 }
1067
1068 static int parse_func_tracer_opts(const struct option *opt,
1069                   const char *str, int unset)
1070 {
1071     int ret;
1072     struct perf_ftrace *ftrace = (struct perf_ftrace *) opt->value;
1073     struct sublevel_option func_tracer_opts[] = {
1074         { .name = "call-graph", .value_ptr = &ftrace->func_stack_trace },
1075         { .name = "irq-info",   .value_ptr = &ftrace->func_irq_info },
1076         { .name = NULL, }
1077     };
1078
1079     if (unset)
1080         return 0;
1081
1082     ret = perf_parse_sublevel_options(str, func_tracer_opts);
1083     if (ret)
1084         return ret;
1085
1086     return 0;
1087 }
1088
1089 static int parse_graph_tracer_opts(const struct option *opt,
1090                   const char *str, int unset)
1091 {
1092     int ret;
1093     struct perf_ftrace *ftrace = (struct perf_ftrace *) opt->value;
1094     struct sublevel_option graph_tracer_opts[] = {
1095         { .name = "nosleep-time",   .value_ptr = &ftrace->graph_nosleep_time },
1096         { .name = "noirqs",     .value_ptr = &ftrace->graph_noirqs },
1097         { .name = "verbose",        .value_ptr = &ftrace->graph_verbose },
1098         { .name = "thresh",     .value_ptr = &ftrace->graph_thresh },
1099         { .name = "depth",      .value_ptr = &ftrace->graph_depth },
1100         { .name = NULL, }
1101     };
1102
1103     if (unset)
1104         return 0;
1105
1106     ret = perf_parse_sublevel_options(str, graph_tracer_opts);
1107     if (ret)
1108         return ret;
1109
1110     return 0;
1111 }
1112
1113 enum perf_ftrace_subcommand {
1114     PERF_FTRACE_NONE,
1115     PERF_FTRACE_TRACE,
1116     PERF_FTRACE_LATENCY,
1117 };
1118
1119 int cmd_ftrace(int argc, const char **argv)
1120 {
1121     int ret;
1122     int (*cmd_func)(struct perf_ftrace *) = NULL;
1123     struct perf_ftrace ftrace = {
1124         .tracer = DEFAULT_TRACER,
1125         .target = { .uid = UINT_MAX, },
1126     };
1127     const struct option common_options[] = {
1128     OPT_STRING('p', "pid", &ftrace.target.pid, "pid",
1129            "Trace on existing process id"),
1130     /* TODO: Add short option -t after -t/--tracer can be removed. */
1131     OPT_STRING(0, "tid", &ftrace.target.tid, "tid",
1132            "Trace on existing thread id (exclusive to --pid)"),
1133     OPT_INCR('v', "verbose", &verbose,
1134          "Be more verbose"),
1135     OPT_BOOLEAN('a', "all-cpus", &ftrace.target.system_wide,
1136             "System-wide collection from all CPUs"),
1137     OPT_STRING('C', "cpu", &ftrace.target.cpu_list, "cpu",
1138             "List of cpus to monitor"),
1139     OPT_END()
1140     };
1141     const struct option ftrace_options[] = {
1142     OPT_STRING('t', "tracer", &ftrace.tracer, "tracer",
1143            "Tracer to use: function_graph(default) or function"),
1144     OPT_CALLBACK_DEFAULT('F', "funcs", NULL, "[FILTER]",
1145                  "Show available functions to filter",
1146                  opt_list_avail_functions, "*"),
1147     OPT_CALLBACK('T', "trace-funcs", &ftrace.filters, "func",
1148              "Trace given functions using function tracer",
1149              parse_filter_func),
1150     OPT_CALLBACK('N', "notrace-funcs", &ftrace.notrace, "func",
1151              "Do not trace given functions", parse_filter_func),
1152     OPT_CALLBACK(0, "func-opts", &ftrace, "options",
1153              "Function tracer options, available options: call-graph,irq-info",
1154              parse_func_tracer_opts),
1155     OPT_CALLBACK('G', "graph-funcs", &ftrace.graph_funcs, "func",
1156              "Trace given functions using function_graph tracer",
1157              parse_filter_func),
1158     OPT_CALLBACK('g', "nograph-funcs", &ftrace.nograph_funcs, "func",
1159              "Set nograph filter on given functions", parse_filter_func),
1160     OPT_CALLBACK(0, "graph-opts", &ftrace, "options",
1161              "Graph tracer options, available options: nosleep-time,noirqs,verbose,thresh=<n>,depth=<n>",
1162              parse_graph_tracer_opts),
1163     OPT_CALLBACK('m', "buffer-size", &ftrace.percpu_buffer_size, "size",
1164              "Size of per cpu buffer, needs to use a B, K, M or G suffix.", parse_buffer_size),
1165     OPT_BOOLEAN(0, "inherit", &ftrace.inherit,
1166             "Trace children processes"),
1167     OPT_UINTEGER('D', "delay", &ftrace.initial_delay,
1168              "Number of milliseconds to wait before starting tracing after program start"),
1169     OPT_PARENT(common_options),
1170     };
1171     const struct option latency_options[] = {
1172     OPT_CALLBACK('T', "trace-funcs", &ftrace.filters, "func",
1173              "Show latency of given function", parse_filter_func),
1174 #ifdef HAVE_BPF_SKEL
1175     OPT_BOOLEAN('b', "use-bpf", &ftrace.target.use_bpf,
1176             "Use BPF to measure function latency"),
1177 #endif
1178     OPT_BOOLEAN('n', "--use-nsec", &ftrace.use_nsec,
1179             "Use nano-second histogram"),
1180     OPT_PARENT(common_options),
1181     };
1182     const struct option *options = ftrace_options;
1183
1184     const char * const ftrace_usage[] = {
1185         "perf ftrace [<options>] [<command>]",
1186         "perf ftrace [<options>] -- [<command>] [<options>]",
1187         "perf ftrace {trace|latency} [<options>] [<command>]",
1188         "perf ftrace {trace|latency} [<options>] -- [<command>] [<options>]",
1189         NULL
1190     };
1191     enum perf_ftrace_subcommand subcmd = PERF_FTRACE_NONE;
1192
1193     INIT_LIST_HEAD(&ftrace.filters);
1194     INIT_LIST_HEAD(&ftrace.notrace);
1195     INIT_LIST_HEAD(&ftrace.graph_funcs);
1196     INIT_LIST_HEAD(&ftrace.nograph_funcs);
1197
1198     signal(SIGINT, sig_handler);
1199     signal(SIGUSR1, sig_handler);
1200     signal(SIGCHLD, sig_handler);
1201     signal(SIGPIPE, sig_handler);
1202
1203     ret = perf_config(perf_ftrace_config, &ftrace);
1204     if (ret < 0)
1205         return -1;
1206
1207     if (argc > 1) {
1208         if (!strcmp(argv[1], "trace")) {
1209             subcmd = PERF_FTRACE_TRACE;
1210         } else if (!strcmp(argv[1], "latency")) {
1211             subcmd = PERF_FTRACE_LATENCY;
1212             options = latency_options;
1213         }
1214
1215         if (subcmd != PERF_FTRACE_NONE) {
1216             argc--;
1217             argv++;
1218         }
1219     }
1220     /* for backward compatibility */
1221     if (subcmd == PERF_FTRACE_NONE)
1222         subcmd = PERF_FTRACE_TRACE;
1223
1224     argc = parse_options(argc, argv, options, ftrace_usage,
1225                 PARSE_OPT_STOP_AT_NON_OPTION);
1226     if (argc < 0) {
1227         ret = -EINVAL;
1228         goto out_delete_filters;
1229     }
1230
1231     switch (subcmd) {
1232     case PERF_FTRACE_TRACE:
1233         if (!argc && target__none(&ftrace.target))
1234             ftrace.target.system_wide = true;
1235         cmd_func = __cmd_ftrace;
1236         break;
1237     case PERF_FTRACE_LATENCY:
1238         if (list_empty(&ftrace.filters)) {
1239             pr_err("Should provide a function to measure\n");
1240             parse_options_usage(ftrace_usage, options, "T", 1);
1241             ret = -EINVAL;
1242             goto out_delete_filters;
1243         }
1244         cmd_func = __cmd_latency;
1245         break;
1246     case PERF_FTRACE_NONE:
1247     default:
1248         pr_err("Invalid subcommand\n");
1249         ret = -EINVAL;
1250         goto out_delete_filters;
1251     }
1252
1253     ret = target__validate(&ftrace.target);
1254     if (ret) {
1255         char errbuf[512];
1256
1257         target__strerror(&ftrace.target, ret, errbuf, 512);
1258         pr_err("%s\n", errbuf);
1259         goto out_delete_filters;
1260     }
1261
1262     ftrace.evlist = evlist__new();
1263     if (ftrace.evlist == NULL) {
1264         ret = -ENOMEM;
1265         goto out_delete_filters;
1266     }
1267
1268     ret = evlist__create_maps(ftrace.evlist, &ftrace.target);
1269     if (ret < 0)
1270         goto out_delete_evlist;
1271
1272     if (argc) {
1273         ret = evlist__prepare_workload(ftrace.evlist, &ftrace.target,
1274                            argv, false,
1275                            ftrace__workload_exec_failed_signal);
1276         if (ret < 0)
1277             goto out_delete_evlist;
1278     }
1279
1280     ret = cmd_func(&ftrace);
1281
1282 out_delete_evlist:
1283     evlist__delete(ftrace.evlist);
1284
1285 out_delete_filters:
1286     delete_filter_func(&ftrace.filters);
1287     delete_filter_func(&ftrace.notrace);
1288     delete_filter_func(&ftrace.graph_funcs);
1289     delete_filter_func(&ftrace.nograph_funcs);
1290
1291     return ret;
1292 }