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