1 // SPDX-License-Identifier: GPL-2.0-only 2 /* 3 * builtin-ftrace.c 4 * 5 * Copyright (c) 2013 LG Electronics, Namhyung Kim <namhyung@kernel.org> 6 * Copyright (c) 2020 Changbin Du <changbin.du@gmail.com>, significant enhancement. 7 */ 8 9 #include "builtin.h" 10 11 #include <errno.h> 12 #include <unistd.h> 13 #include <signal.h> 14 #include <stdlib.h> 15 #include <fcntl.h> 16 #include <math.h> 17 #include <poll.h> 18 #include <ctype.h> 19 #include <linux/capability.h> 20 #include <linux/string.h> 21 22 #include "debug.h" 23 #include <subcmd/pager.h> 24 #include <subcmd/parse-options.h> 25 #include <api/fs/tracing_path.h> 26 #include "evlist.h" 27 #include "target.h" 28 #include "cpumap.h" 29 #include "thread_map.h" 30 #include "strfilter.h" 31 #include "util/cap.h" 32 #include "util/config.h" 33 #include "util/ftrace.h" 34 #include "util/units.h" 35 #include "util/parse-sublevel-options.h" 36 37 #define DEFAULT_TRACER "function_graph" 38 39 static volatile int workload_exec_errno; 40 static bool done; 41 42 static void sig_handler(int sig __maybe_unused) 43 { 44 done = true; 45 } 46 47 /* 48 * evlist__prepare_workload will send a SIGUSR1 if the fork fails, since 49 * we asked by setting its exec_error to the function below, 50 * ftrace__workload_exec_failed_signal. 51 * 52 * XXX We need to handle this more appropriately, emitting an error, etc. 53 */ 54 static void ftrace__workload_exec_failed_signal(int signo __maybe_unused, 55 siginfo_t *info __maybe_unused, 56 void *ucontext __maybe_unused) 57 { 58 workload_exec_errno = info->si_value.sival_int; 59 done = true; 60 } 61 62 static int __write_tracing_file(const char *name, const char *val, bool append) 63 { 64 char *file; 65 int fd, ret = -1; 66 ssize_t size = strlen(val); 67 int flags = O_WRONLY; 68 char errbuf[512]; 69 char *val_copy; 70 71 file = get_tracing_file(name); 72 if (!file) { 73 pr_debug("cannot get tracing file: %s\n", name); 74 return -1; 75 } 76 77 if (append) 78 flags |= O_APPEND; 79 else 80 flags |= O_TRUNC; 81 82 fd = open(file, flags); 83 if (fd < 0) { 84 pr_debug("cannot open tracing file: %s: %s\n", 85 name, str_error_r(errno, errbuf, sizeof(errbuf))); 86 goto out; 87 } 88 89 /* 90 * Copy the original value and append a '\n'. Without this, 91 * the kernel can hide possible errors. 92 */ 93 val_copy = strdup(val); 94 if (!val_copy) 95 goto out_close; 96 val_copy[size] = '\n'; 97 98 if (write(fd, val_copy, size + 1) == size + 1) 99 ret = 0; 100 else 101 pr_debug("write '%s' to tracing/%s failed: %s\n", 102 val, name, str_error_r(errno, errbuf, sizeof(errbuf))); 103 104 free(val_copy); 105 out_close: 106 close(fd); 107 out: 108 put_tracing_file(file); 109 return ret; 110 } 111 112 static int write_tracing_file(const char *name, const char *val) 113 { 114 return __write_tracing_file(name, val, false); 115 } 116 117 static int append_tracing_file(const char *name, const char *val) 118 { 119 return __write_tracing_file(name, val, true); 120 } 121 122 static int read_tracing_file_to_stdout(const char *name) 123 { 124 char buf[4096]; 125 char *file; 126 int fd; 127 int ret = -1; 128 129 file = get_tracing_file(name); 130 if (!file) { 131 pr_debug("cannot get tracing file: %s\n", name); 132 return -1; 133 } 134 135 fd = open(file, O_RDONLY); 136 if (fd < 0) { 137 pr_debug("cannot open tracing file: %s: %s\n", 138 name, str_error_r(errno, buf, sizeof(buf))); 139 goto out; 140 } 141 142 /* read contents to stdout */ 143 while (true) { 144 int n = read(fd, buf, sizeof(buf)); 145 if (n == 0) 146 break; 147 else if (n < 0) 148 goto out_close; 149 150 if (fwrite(buf, n, 1, stdout) != 1) 151 goto out_close; 152 } 153 ret = 0; 154 155 out_close: 156 close(fd); 157 out: 158 put_tracing_file(file); 159 return ret; 160 } 161 162 static int read_tracing_file_by_line(const char *name, 163 void (*cb)(char *str, void *arg), 164 void *cb_arg) 165 { 166 char *line = NULL; 167 size_t len = 0; 168 char *file; 169 FILE *fp; 170 171 file = get_tracing_file(name); 172 if (!file) { 173 pr_debug("cannot get tracing file: %s\n", name); 174 return -1; 175 } 176 177 fp = fopen(file, "r"); 178 if (fp == NULL) { 179 pr_debug("cannot open tracing file: %s\n", name); 180 put_tracing_file(file); 181 return -1; 182 } 183 184 while (getline(&line, &len, fp) != -1) { 185 cb(line, cb_arg); 186 } 187 188 if (line) 189 free(line); 190 191 fclose(fp); 192 put_tracing_file(file); 193 return 0; 194 } 195 196 static int write_tracing_file_int(const char *name, int value) 197 { 198 char buf[16]; 199 200 snprintf(buf, sizeof(buf), "%d", value); 201 if (write_tracing_file(name, buf) < 0) 202 return -1; 203 204 return 0; 205 } 206 207 static int write_tracing_option_file(const char *name, const char *val) 208 { 209 char *file; 210 int ret; 211 212 if (asprintf(&file, "options/%s", name) < 0) 213 return -1; 214 215 ret = __write_tracing_file(file, val, false); 216 free(file); 217 return ret; 218 } 219 220 static int reset_tracing_cpu(void); 221 static void reset_tracing_filters(void); 222 223 static void reset_tracing_options(struct perf_ftrace *ftrace __maybe_unused) 224 { 225 write_tracing_option_file("function-fork", "0"); 226 write_tracing_option_file("func_stack_trace", "0"); 227 write_tracing_option_file("sleep-time", "1"); 228 write_tracing_option_file("funcgraph-irqs", "1"); 229 write_tracing_option_file("funcgraph-proc", "0"); 230 write_tracing_option_file("funcgraph-abstime", "0"); 231 write_tracing_option_file("latency-format", "0"); 232 write_tracing_option_file("irq-info", "0"); 233 } 234 235 static int reset_tracing_files(struct perf_ftrace *ftrace __maybe_unused) 236 { 237 if (write_tracing_file("tracing_on", "0") < 0) 238 return -1; 239 240 if (write_tracing_file("current_tracer", "nop") < 0) 241 return -1; 242 243 if (write_tracing_file("set_ftrace_pid", " ") < 0) 244 return -1; 245 246 if (reset_tracing_cpu() < 0) 247 return -1; 248 249 if (write_tracing_file("max_graph_depth", "0") < 0) 250 return -1; 251 252 if (write_tracing_file("tracing_thresh", "0") < 0) 253 return -1; 254 255 reset_tracing_filters(); 256 reset_tracing_options(ftrace); 257 return 0; 258 } 259 260 static int set_tracing_pid(struct perf_ftrace *ftrace) 261 { 262 int i; 263 char buf[16]; 264 265 if (target__has_cpu(&ftrace->target)) 266 return 0; 267 268 for (i = 0; i < perf_thread_map__nr(ftrace->evlist->core.threads); i++) { 269 scnprintf(buf, sizeof(buf), "%d", 270 perf_thread_map__pid(ftrace->evlist->core.threads, i)); 271 if (append_tracing_file("set_ftrace_pid", buf) < 0) 272 return -1; 273 } 274 return 0; 275 } 276 277 static int set_tracing_cpumask(struct perf_cpu_map *cpumap) 278 { 279 char *cpumask; 280 size_t mask_size; 281 int ret; 282 int last_cpu; 283 284 last_cpu = perf_cpu_map__cpu(cpumap, perf_cpu_map__nr(cpumap) - 1).cpu; 285 mask_size = last_cpu / 4 + 2; /* one more byte for EOS */ 286 mask_size += last_cpu / 32; /* ',' is needed for every 32th cpus */ 287 288 cpumask = malloc(mask_size); 289 if (cpumask == NULL) { 290 pr_debug("failed to allocate cpu mask\n"); 291 return -1; 292 } 293 294 cpu_map__snprint_mask(cpumap, cpumask, mask_size); 295 296 ret = write_tracing_file("tracing_cpumask", cpumask); 297 298 free(cpumask); 299 return ret; 300 } 301 302 static int set_tracing_cpu(struct perf_ftrace *ftrace) 303 { 304 struct perf_cpu_map *cpumap = ftrace->evlist->core.cpus; 305 306 if (!target__has_cpu(&ftrace->target)) 307 return 0; 308 309 return set_tracing_cpumask(cpumap); 310 } 311 312 static int set_tracing_func_stack_trace(struct perf_ftrace *ftrace) 313 { 314 if (!ftrace->func_stack_trace) 315 return 0; 316 317 if (write_tracing_option_file("func_stack_trace", "1") < 0) 318 return -1; 319 320 return 0; 321 } 322 323 static int set_tracing_func_irqinfo(struct perf_ftrace *ftrace) 324 { 325 if (!ftrace->func_irq_info) 326 return 0; 327 328 if (write_tracing_option_file("irq-info", "1") < 0) 329 return -1; 330 331 return 0; 332 } 333 334 static int reset_tracing_cpu(void) 335 { 336 struct perf_cpu_map *cpumap = perf_cpu_map__new(NULL); 337 int ret; 338 339 ret = set_tracing_cpumask(cpumap); 340 perf_cpu_map__put(cpumap); 341 return ret; 342 } 343 344 static int __set_tracing_filter(const char *filter_file, struct list_head *funcs) 345 { 346 struct filter_entry *pos; 347 348 list_for_each_entry(pos, funcs, list) { 349 if (append_tracing_file(filter_file, pos->name) < 0) 350 return -1; 351 } 352 353 return 0; 354 } 355 356 static int set_tracing_filters(struct perf_ftrace *ftrace) 357 { 358 int ret; 359 360 ret = __set_tracing_filter("set_ftrace_filter", &ftrace->filters); 361 if (ret < 0) 362 return ret; 363 364 ret = __set_tracing_filter("set_ftrace_notrace", &ftrace->notrace); 365 if (ret < 0) 366 return ret; 367 368 ret = __set_tracing_filter("set_graph_function", &ftrace->graph_funcs); 369 if (ret < 0) 370 return ret; 371 372 /* old kernels do not have this filter */ 373 __set_tracing_filter("set_graph_notrace", &ftrace->nograph_funcs); 374 375 return ret; 376 } 377 378 static void reset_tracing_filters(void) 379 { 380 write_tracing_file("set_ftrace_filter", " "); 381 write_tracing_file("set_ftrace_notrace", " "); 382 write_tracing_file("set_graph_function", " "); 383 write_tracing_file("set_graph_notrace", " "); 384 } 385 386 static int set_tracing_depth(struct perf_ftrace *ftrace) 387 { 388 if (ftrace->graph_depth == 0) 389 return 0; 390 391 if (ftrace->graph_depth < 0) { 392 pr_err("invalid graph depth: %d\n", ftrace->graph_depth); 393 return -1; 394 } 395 396 if (write_tracing_file_int("max_graph_depth", ftrace->graph_depth) < 0) 397 return -1; 398 399 return 0; 400 } 401 402 static int set_tracing_percpu_buffer_size(struct perf_ftrace *ftrace) 403 { 404 int ret; 405 406 if (ftrace->percpu_buffer_size == 0) 407 return 0; 408 409 ret = write_tracing_file_int("buffer_size_kb", 410 ftrace->percpu_buffer_size / 1024); 411 if (ret < 0) 412 return ret; 413 414 return 0; 415 } 416 417 static int set_tracing_trace_inherit(struct perf_ftrace *ftrace) 418 { 419 if (!ftrace->inherit) 420 return 0; 421 422 if (write_tracing_option_file("function-fork", "1") < 0) 423 return -1; 424 425 return 0; 426 } 427 428 static int set_tracing_sleep_time(struct perf_ftrace *ftrace) 429 { 430 if (!ftrace->graph_nosleep_time) 431 return 0; 432 433 if (write_tracing_option_file("sleep-time", "0") < 0) 434 return -1; 435 436 return 0; 437 } 438 439 static int set_tracing_funcgraph_irqs(struct perf_ftrace *ftrace) 440 { 441 if (!ftrace->graph_noirqs) 442 return 0; 443 444 if (write_tracing_option_file("funcgraph-irqs", "0") < 0) 445 return -1; 446 447 return 0; 448 } 449 450 static int set_tracing_funcgraph_verbose(struct perf_ftrace *ftrace) 451 { 452 if (!ftrace->graph_verbose) 453 return 0; 454 455 if (write_tracing_option_file("funcgraph-proc", "1") < 0) 456 return -1; 457 458 if (write_tracing_option_file("funcgraph-abstime", "1") < 0) 459 return -1; 460 461 if (write_tracing_option_file("latency-format", "1") < 0) 462 return -1; 463 464 return 0; 465 } 466 467 static int set_tracing_thresh(struct perf_ftrace *ftrace) 468 { 469 int ret; 470 471 if (ftrace->graph_thresh == 0) 472 return 0; 473 474 ret = write_tracing_file_int("tracing_thresh", ftrace->graph_thresh); 475 if (ret < 0) 476 return ret; 477 478 return 0; 479 } 480 481 static int set_tracing_options(struct perf_ftrace *ftrace) 482 { 483 if (set_tracing_pid(ftrace) < 0) { 484 pr_err("failed to set ftrace pid\n"); 485 return -1; 486 } 487 488 if (set_tracing_cpu(ftrace) < 0) { 489 pr_err("failed to set tracing cpumask\n"); 490 return -1; 491 } 492 493 if (set_tracing_func_stack_trace(ftrace) < 0) { 494 pr_err("failed to set tracing option func_stack_trace\n"); 495 return -1; 496 } 497 498 if (set_tracing_func_irqinfo(ftrace) < 0) { 499 pr_err("failed to set tracing option irq-info\n"); 500 return -1; 501 } 502 503 if (set_tracing_filters(ftrace) < 0) { 504 pr_err("failed to set tracing filters\n"); 505 return -1; 506 } 507 508 if (set_tracing_depth(ftrace) < 0) { 509 pr_err("failed to set graph depth\n"); 510 return -1; 511 } 512 513 if (set_tracing_percpu_buffer_size(ftrace) < 0) { 514 pr_err("failed to set tracing per-cpu buffer size\n"); 515 return -1; 516 } 517 518 if (set_tracing_trace_inherit(ftrace) < 0) { 519 pr_err("failed to set tracing option function-fork\n"); 520 return -1; 521 } 522 523 if (set_tracing_sleep_time(ftrace) < 0) { 524 pr_err("failed to set tracing option sleep-time\n"); 525 return -1; 526 } 527 528 if (set_tracing_funcgraph_irqs(ftrace) < 0) { 529 pr_err("failed to set tracing option funcgraph-irqs\n"); 530 return -1; 531 } 532 533 if (set_tracing_funcgraph_verbose(ftrace) < 0) { 534 pr_err("failed to set tracing option funcgraph-proc/funcgraph-abstime\n"); 535 return -1; 536 } 537 538 if (set_tracing_thresh(ftrace) < 0) { 539 pr_err("failed to set tracing thresh\n"); 540 return -1; 541 } 542 543 return 0; 544 } 545 546 static void select_tracer(struct perf_ftrace *ftrace) 547 { 548 bool graph = !list_empty(&ftrace->graph_funcs) || 549 !list_empty(&ftrace->nograph_funcs); 550 bool func = !list_empty(&ftrace->filters) || 551 !list_empty(&ftrace->notrace); 552 553 /* The function_graph has priority over function tracer. */ 554 if (graph) 555 ftrace->tracer = "function_graph"; 556 else if (func) 557 ftrace->tracer = "function"; 558 /* Otherwise, the default tracer is used. */ 559 560 pr_debug("%s tracer is used\n", ftrace->tracer); 561 } 562 563 static int __cmd_ftrace(struct perf_ftrace *ftrace) 564 { 565 char *trace_file; 566 int trace_fd; 567 char buf[4096]; 568 struct pollfd pollfd = { 569 .events = POLLIN, 570 }; 571 572 if (!(perf_cap__capable(CAP_PERFMON) || 573 perf_cap__capable(CAP_SYS_ADMIN))) { 574 pr_err("ftrace only works for %s!\n", 575 #ifdef HAVE_LIBCAP_SUPPORT 576 "users with the CAP_PERFMON or CAP_SYS_ADMIN capability" 577 #else 578 "root" 579 #endif 580 ); 581 return -1; 582 } 583 584 select_tracer(ftrace); 585 586 if (reset_tracing_files(ftrace) < 0) { 587 pr_err("failed to reset ftrace\n"); 588 goto out; 589 } 590 591 /* reset ftrace buffer */ 592 if (write_tracing_file("trace", "0") < 0) 593 goto out; 594 595 if (set_tracing_options(ftrace) < 0) 596 goto out_reset; 597 598 if (write_tracing_file("current_tracer", ftrace->tracer) < 0) { 599 pr_err("failed to set current_tracer to %s\n", ftrace->tracer); 600 goto out_reset; 601 } 602 603 setup_pager(); 604 605 trace_file = get_tracing_file("trace_pipe"); 606 if (!trace_file) { 607 pr_err("failed to open trace_pipe\n"); 608 goto out_reset; 609 } 610 611 trace_fd = open(trace_file, O_RDONLY); 612 613 put_tracing_file(trace_file); 614 615 if (trace_fd < 0) { 616 pr_err("failed to open trace_pipe\n"); 617 goto out_reset; 618 } 619 620 fcntl(trace_fd, F_SETFL, O_NONBLOCK); 621 pollfd.fd = trace_fd; 622 623 /* display column headers */ 624 read_tracing_file_to_stdout("trace"); 625 626 if (!ftrace->initial_delay) { 627 if (write_tracing_file("tracing_on", "1") < 0) { 628 pr_err("can't enable tracing\n"); 629 goto out_close_fd; 630 } 631 } 632 633 evlist__start_workload(ftrace->evlist); 634 635 if (ftrace->initial_delay) { 636 usleep(ftrace->initial_delay * 1000); 637 if (write_tracing_file("tracing_on", "1") < 0) { 638 pr_err("can't enable tracing\n"); 639 goto out_close_fd; 640 } 641 } 642 643 while (!done) { 644 if (poll(&pollfd, 1, -1) < 0) 645 break; 646 647 if (pollfd.revents & POLLIN) { 648 int n = read(trace_fd, buf, sizeof(buf)); 649 if (n < 0) 650 break; 651 if (fwrite(buf, n, 1, stdout) != 1) 652 break; 653 } 654 } 655 656 write_tracing_file("tracing_on", "0"); 657 658 if (workload_exec_errno) { 659 const char *emsg = str_error_r(workload_exec_errno, buf, sizeof(buf)); 660 /* flush stdout first so below error msg appears at the end. */ 661 fflush(stdout); 662 pr_err("workload failed: %s\n", emsg); 663 goto out_close_fd; 664 } 665 666 /* read remaining buffer contents */ 667 while (true) { 668 int n = read(trace_fd, buf, sizeof(buf)); 669 if (n <= 0) 670 break; 671 if (fwrite(buf, n, 1, stdout) != 1) 672 break; 673 } 674 675 out_close_fd: 676 close(trace_fd); 677 out_reset: 678 reset_tracing_files(ftrace); 679 out: 680 return (done && !workload_exec_errno) ? 0 : -1; 681 } 682 683 static void make_histogram(int buckets[], char *buf, size_t len, char *linebuf) 684 { 685 char *p, *q; 686 char *unit; 687 double num; 688 int i; 689 690 /* ensure NUL termination */ 691 buf[len] = '\0'; 692 693 /* handle data line by line */ 694 for (p = buf; (q = strchr(p, '\n')) != NULL; p = q + 1) { 695 *q = '\0'; 696 /* move it to the line buffer */ 697 strcat(linebuf, p); 698 699 /* 700 * parse trace output to get function duration like in 701 * 702 * # tracer: function_graph 703 * # 704 * # CPU DURATION FUNCTION CALLS 705 * # | | | | | | | 706 * 1) + 10.291 us | do_filp_open(); 707 * 1) 4.889 us | do_filp_open(); 708 * 1) 6.086 us | do_filp_open(); 709 * 710 */ 711 if (linebuf[0] == '#') 712 goto next; 713 714 /* ignore CPU */ 715 p = strchr(linebuf, ')'); 716 if (p == NULL) 717 p = linebuf; 718 719 while (*p && !isdigit(*p) && (*p != '|')) 720 p++; 721 722 /* no duration */ 723 if (*p == '\0' || *p == '|') 724 goto next; 725 726 num = strtod(p, &unit); 727 if (!unit || strncmp(unit, " us", 3)) 728 goto next; 729 730 i = log2(num); 731 if (i < 0) 732 i = 0; 733 if (i >= NUM_BUCKET) 734 i = NUM_BUCKET - 1; 735 736 buckets[i]++; 737 738 next: 739 /* empty the line buffer for the next output */ 740 linebuf[0] = '\0'; 741 } 742 743 /* preserve any remaining output (before newline) */ 744 strcat(linebuf, p); 745 } 746 747 static void display_histogram(int buckets[]) 748 { 749 int i; 750 int total = 0; 751 int bar_total = 46; /* to fit in 80 column */ 752 char bar[] = "###############################################"; 753 int bar_len; 754 755 for (i = 0; i < NUM_BUCKET; i++) 756 total += buckets[i]; 757 758 if (total == 0) { 759 printf("No data found\n"); 760 return; 761 } 762 763 printf("# %14s | %10s | %-*s |\n", 764 " DURATION ", "COUNT", bar_total, "GRAPH"); 765 766 bar_len = buckets[0] * bar_total / total; 767 printf(" %4d - %-4d %s | %10d | %.*s%*s |\n", 768 0, 1, "us", buckets[0], bar_len, bar, bar_total - bar_len, ""); 769 770 for (i = 1; i < NUM_BUCKET - 1; i++) { 771 int start = (1 << (i - 1)); 772 int stop = 1 << i; 773 const char *unit = "us"; 774 775 if (start >= 1024) { 776 start >>= 10; 777 stop >>= 10; 778 unit = "ms"; 779 } 780 bar_len = buckets[i] * bar_total / total; 781 printf(" %4d - %-4d %s | %10d | %.*s%*s |\n", 782 start, stop, unit, buckets[i], bar_len, bar, 783 bar_total - bar_len, ""); 784 } 785 786 bar_len = buckets[NUM_BUCKET - 1] * bar_total / total; 787 printf(" %4d - %-4s %s | %10d | %.*s%*s |\n", 788 1, "...", " s", buckets[NUM_BUCKET - 1], bar_len, bar, 789 bar_total - bar_len, ""); 790 791 } 792 793 static int prepare_func_latency(struct perf_ftrace *ftrace) 794 { 795 char *trace_file; 796 int fd; 797 798 if (ftrace->target.use_bpf) 799 return perf_ftrace__latency_prepare_bpf(ftrace); 800 801 if (reset_tracing_files(ftrace) < 0) { 802 pr_err("failed to reset ftrace\n"); 803 return -1; 804 } 805 806 /* reset ftrace buffer */ 807 if (write_tracing_file("trace", "0") < 0) 808 return -1; 809 810 if (set_tracing_options(ftrace) < 0) 811 return -1; 812 813 /* force to use the function_graph tracer to track duration */ 814 if (write_tracing_file("current_tracer", "function_graph") < 0) { 815 pr_err("failed to set current_tracer to function_graph\n"); 816 return -1; 817 } 818 819 trace_file = get_tracing_file("trace_pipe"); 820 if (!trace_file) { 821 pr_err("failed to open trace_pipe\n"); 822 return -1; 823 } 824 825 fd = open(trace_file, O_RDONLY); 826 if (fd < 0) 827 pr_err("failed to open trace_pipe\n"); 828 829 put_tracing_file(trace_file); 830 return fd; 831 } 832 833 static int start_func_latency(struct perf_ftrace *ftrace) 834 { 835 if (ftrace->target.use_bpf) 836 return perf_ftrace__latency_start_bpf(ftrace); 837 838 if (write_tracing_file("tracing_on", "1") < 0) { 839 pr_err("can't enable tracing\n"); 840 return -1; 841 } 842 843 return 0; 844 } 845 846 static int stop_func_latency(struct perf_ftrace *ftrace) 847 { 848 if (ftrace->target.use_bpf) 849 return perf_ftrace__latency_stop_bpf(ftrace); 850 851 write_tracing_file("tracing_on", "0"); 852 return 0; 853 } 854 855 static int read_func_latency(struct perf_ftrace *ftrace, int buckets[]) 856 { 857 if (ftrace->target.use_bpf) 858 return perf_ftrace__latency_read_bpf(ftrace, buckets); 859 860 return 0; 861 } 862 863 static int cleanup_func_latency(struct perf_ftrace *ftrace) 864 { 865 if (ftrace->target.use_bpf) 866 return perf_ftrace__latency_cleanup_bpf(ftrace); 867 868 reset_tracing_files(ftrace); 869 return 0; 870 } 871 872 static int __cmd_latency(struct perf_ftrace *ftrace) 873 { 874 int trace_fd; 875 char buf[4096]; 876 char line[256]; 877 struct pollfd pollfd = { 878 .events = POLLIN, 879 }; 880 int buckets[NUM_BUCKET] = { }; 881 882 if (!(perf_cap__capable(CAP_PERFMON) || 883 perf_cap__capable(CAP_SYS_ADMIN))) { 884 pr_err("ftrace only works for %s!\n", 885 #ifdef HAVE_LIBCAP_SUPPORT 886 "users with the CAP_PERFMON or CAP_SYS_ADMIN capability" 887 #else 888 "root" 889 #endif 890 ); 891 return -1; 892 } 893 894 trace_fd = prepare_func_latency(ftrace); 895 if (trace_fd < 0) 896 goto out; 897 898 fcntl(trace_fd, F_SETFL, O_NONBLOCK); 899 pollfd.fd = trace_fd; 900 901 if (start_func_latency(ftrace) < 0) 902 goto out; 903 904 evlist__start_workload(ftrace->evlist); 905 906 line[0] = '\0'; 907 while (!done) { 908 if (poll(&pollfd, 1, -1) < 0) 909 break; 910 911 if (pollfd.revents & POLLIN) { 912 int n = read(trace_fd, buf, sizeof(buf) - 1); 913 if (n < 0) 914 break; 915 916 make_histogram(buckets, buf, n, line); 917 } 918 } 919 920 stop_func_latency(ftrace); 921 922 if (workload_exec_errno) { 923 const char *emsg = str_error_r(workload_exec_errno, buf, sizeof(buf)); 924 pr_err("workload failed: %s\n", emsg); 925 goto out; 926 } 927 928 /* read remaining buffer contents */ 929 while (!ftrace->target.use_bpf) { 930 int n = read(trace_fd, buf, sizeof(buf) - 1); 931 if (n <= 0) 932 break; 933 make_histogram(buckets, buf, n, line); 934 } 935 936 read_func_latency(ftrace, buckets); 937 938 display_histogram(buckets); 939 940 out: 941 close(trace_fd); 942 cleanup_func_latency(ftrace); 943 944 return (done && !workload_exec_errno) ? 0 : -1; 945 } 946 947 static int perf_ftrace_config(const char *var, const char *value, void *cb) 948 { 949 struct perf_ftrace *ftrace = cb; 950 951 if (!strstarts(var, "ftrace.")) 952 return 0; 953 954 if (strcmp(var, "ftrace.tracer")) 955 return -1; 956 957 if (!strcmp(value, "function_graph") || 958 !strcmp(value, "function")) { 959 ftrace->tracer = value; 960 return 0; 961 } 962 963 pr_err("Please select \"function_graph\" (default) or \"function\"\n"); 964 return -1; 965 } 966 967 static void list_function_cb(char *str, void *arg) 968 { 969 struct strfilter *filter = (struct strfilter *)arg; 970 971 if (strfilter__compare(filter, str)) 972 printf("%s", str); 973 } 974 975 static int opt_list_avail_functions(const struct option *opt __maybe_unused, 976 const char *str, int unset) 977 { 978 struct strfilter *filter; 979 const char *err = NULL; 980 int ret; 981 982 if (unset || !str) 983 return -1; 984 985 filter = strfilter__new(str, &err); 986 if (!filter) 987 return err ? -EINVAL : -ENOMEM; 988 989 ret = strfilter__or(filter, str, &err); 990 if (ret == -EINVAL) { 991 pr_err("Filter parse error at %td.\n", err - str + 1); 992 pr_err("Source: \"%s\"\n", str); 993 pr_err(" %*c\n", (int)(err - str + 1), '^'); 994 strfilter__delete(filter); 995 return ret; 996 } 997 998 ret = read_tracing_file_by_line("available_filter_functions", 999 list_function_cb, filter); 1000 strfilter__delete(filter); 1001 if (ret < 0) 1002 return ret; 1003 1004 exit(0); 1005 } 1006 1007 static int parse_filter_func(const struct option *opt, const char *str, 1008 int unset __maybe_unused) 1009 { 1010 struct list_head *head = opt->value; 1011 struct filter_entry *entry; 1012 1013 entry = malloc(sizeof(*entry) + strlen(str) + 1); 1014 if (entry == NULL) 1015 return -ENOMEM; 1016 1017 strcpy(entry->name, str); 1018 list_add_tail(&entry->list, head); 1019 1020 return 0; 1021 } 1022 1023 static void delete_filter_func(struct list_head *head) 1024 { 1025 struct filter_entry *pos, *tmp; 1026 1027 list_for_each_entry_safe(pos, tmp, head, list) { 1028 list_del_init(&pos->list); 1029 free(pos); 1030 } 1031 } 1032 1033 static int parse_buffer_size(const struct option *opt, 1034 const char *str, int unset) 1035 { 1036 unsigned long *s = (unsigned long *)opt->value; 1037 static struct parse_tag tags_size[] = { 1038 { .tag = 'B', .mult = 1 }, 1039 { .tag = 'K', .mult = 1 << 10 }, 1040 { .tag = 'M', .mult = 1 << 20 }, 1041 { .tag = 'G', .mult = 1 << 30 }, 1042 { .tag = 0 }, 1043 }; 1044 unsigned long val; 1045 1046 if (unset) { 1047 *s = 0; 1048 return 0; 1049 } 1050 1051 val = parse_tag_value(str, tags_size); 1052 if (val != (unsigned long) -1) { 1053 if (val < 1024) { 1054 pr_err("buffer size too small, must larger than 1KB."); 1055 return -1; 1056 } 1057 *s = val; 1058 return 0; 1059 } 1060 1061 return -1; 1062 } 1063 1064 static int parse_func_tracer_opts(const struct option *opt, 1065 const char *str, int unset) 1066 { 1067 int ret; 1068 struct perf_ftrace *ftrace = (struct perf_ftrace *) opt->value; 1069 struct sublevel_option func_tracer_opts[] = { 1070 { .name = "call-graph", .value_ptr = &ftrace->func_stack_trace }, 1071 { .name = "irq-info", .value_ptr = &ftrace->func_irq_info }, 1072 { .name = NULL, } 1073 }; 1074 1075 if (unset) 1076 return 0; 1077 1078 ret = perf_parse_sublevel_options(str, func_tracer_opts); 1079 if (ret) 1080 return ret; 1081 1082 return 0; 1083 } 1084 1085 static int parse_graph_tracer_opts(const struct option *opt, 1086 const char *str, int unset) 1087 { 1088 int ret; 1089 struct perf_ftrace *ftrace = (struct perf_ftrace *) opt->value; 1090 struct sublevel_option graph_tracer_opts[] = { 1091 { .name = "nosleep-time", .value_ptr = &ftrace->graph_nosleep_time }, 1092 { .name = "noirqs", .value_ptr = &ftrace->graph_noirqs }, 1093 { .name = "verbose", .value_ptr = &ftrace->graph_verbose }, 1094 { .name = "thresh", .value_ptr = &ftrace->graph_thresh }, 1095 { .name = "depth", .value_ptr = &ftrace->graph_depth }, 1096 { .name = NULL, } 1097 }; 1098 1099 if (unset) 1100 return 0; 1101 1102 ret = perf_parse_sublevel_options(str, graph_tracer_opts); 1103 if (ret) 1104 return ret; 1105 1106 return 0; 1107 } 1108 1109 enum perf_ftrace_subcommand { 1110 PERF_FTRACE_NONE, 1111 PERF_FTRACE_TRACE, 1112 PERF_FTRACE_LATENCY, 1113 }; 1114 1115 int cmd_ftrace(int argc, const char **argv) 1116 { 1117 int ret; 1118 int (*cmd_func)(struct perf_ftrace *) = NULL; 1119 struct perf_ftrace ftrace = { 1120 .tracer = DEFAULT_TRACER, 1121 .target = { .uid = UINT_MAX, }, 1122 }; 1123 const struct option common_options[] = { 1124 OPT_STRING('p', "pid", &ftrace.target.pid, "pid", 1125 "Trace on existing process id"), 1126 /* TODO: Add short option -t after -t/--tracer can be removed. */ 1127 OPT_STRING(0, "tid", &ftrace.target.tid, "tid", 1128 "Trace on existing thread id (exclusive to --pid)"), 1129 OPT_INCR('v', "verbose", &verbose, 1130 "Be more verbose"), 1131 OPT_BOOLEAN('a', "all-cpus", &ftrace.target.system_wide, 1132 "System-wide collection from all CPUs"), 1133 OPT_STRING('C', "cpu", &ftrace.target.cpu_list, "cpu", 1134 "List of cpus to monitor"), 1135 OPT_END() 1136 }; 1137 const struct option ftrace_options[] = { 1138 OPT_STRING('t', "tracer", &ftrace.tracer, "tracer", 1139 "Tracer to use: function_graph(default) or function"), 1140 OPT_CALLBACK_DEFAULT('F', "funcs", NULL, "[FILTER]", 1141 "Show available functions to filter", 1142 opt_list_avail_functions, "*"), 1143 OPT_CALLBACK('T', "trace-funcs", &ftrace.filters, "func", 1144 "Trace given functions using function tracer", 1145 parse_filter_func), 1146 OPT_CALLBACK('N', "notrace-funcs", &ftrace.notrace, "func", 1147 "Do not trace given functions", parse_filter_func), 1148 OPT_CALLBACK(0, "func-opts", &ftrace, "options", 1149 "Function tracer options, available options: call-graph,irq-info", 1150 parse_func_tracer_opts), 1151 OPT_CALLBACK('G', "graph-funcs", &ftrace.graph_funcs, "func", 1152 "Trace given functions using function_graph tracer", 1153 parse_filter_func), 1154 OPT_CALLBACK('g', "nograph-funcs", &ftrace.nograph_funcs, "func", 1155 "Set nograph filter on given functions", parse_filter_func), 1156 OPT_CALLBACK(0, "graph-opts", &ftrace, "options", 1157 "Graph tracer options, available options: nosleep-time,noirqs,verbose,thresh=<n>,depth=<n>", 1158 parse_graph_tracer_opts), 1159 OPT_CALLBACK('m', "buffer-size", &ftrace.percpu_buffer_size, "size", 1160 "Size of per cpu buffer, needs to use a B, K, M or G suffix.", parse_buffer_size), 1161 OPT_BOOLEAN(0, "inherit", &ftrace.inherit, 1162 "Trace children processes"), 1163 OPT_UINTEGER('D', "delay", &ftrace.initial_delay, 1164 "Number of milliseconds to wait before starting tracing after program start"), 1165 OPT_PARENT(common_options), 1166 }; 1167 const struct option latency_options[] = { 1168 OPT_CALLBACK('T', "trace-funcs", &ftrace.filters, "func", 1169 "Show latency of given function", parse_filter_func), 1170 #ifdef HAVE_BPF_SKEL 1171 OPT_BOOLEAN('b', "use-bpf", &ftrace.target.use_bpf, 1172 "Use BPF to measure function latency"), 1173 #endif 1174 OPT_PARENT(common_options), 1175 }; 1176 const struct option *options = ftrace_options; 1177 1178 const char * const ftrace_usage[] = { 1179 "perf ftrace [<options>] [<command>]", 1180 "perf ftrace [<options>] -- [<command>] [<options>]", 1181 "perf ftrace {trace|latency} [<options>] [<command>]", 1182 "perf ftrace {trace|latency} [<options>] -- [<command>] [<options>]", 1183 NULL 1184 }; 1185 enum perf_ftrace_subcommand subcmd = PERF_FTRACE_NONE; 1186 1187 INIT_LIST_HEAD(&ftrace.filters); 1188 INIT_LIST_HEAD(&ftrace.notrace); 1189 INIT_LIST_HEAD(&ftrace.graph_funcs); 1190 INIT_LIST_HEAD(&ftrace.nograph_funcs); 1191 1192 signal(SIGINT, sig_handler); 1193 signal(SIGUSR1, sig_handler); 1194 signal(SIGCHLD, sig_handler); 1195 signal(SIGPIPE, sig_handler); 1196 1197 ret = perf_config(perf_ftrace_config, &ftrace); 1198 if (ret < 0) 1199 return -1; 1200 1201 if (argc > 1) { 1202 if (!strcmp(argv[1], "trace")) { 1203 subcmd = PERF_FTRACE_TRACE; 1204 } else if (!strcmp(argv[1], "latency")) { 1205 subcmd = PERF_FTRACE_LATENCY; 1206 options = latency_options; 1207 } 1208 1209 if (subcmd != PERF_FTRACE_NONE) { 1210 argc--; 1211 argv++; 1212 } 1213 } 1214 /* for backward compatibility */ 1215 if (subcmd == PERF_FTRACE_NONE) 1216 subcmd = PERF_FTRACE_TRACE; 1217 1218 argc = parse_options(argc, argv, options, ftrace_usage, 1219 PARSE_OPT_STOP_AT_NON_OPTION); 1220 if (argc < 0) { 1221 ret = -EINVAL; 1222 goto out_delete_filters; 1223 } 1224 1225 switch (subcmd) { 1226 case PERF_FTRACE_TRACE: 1227 if (!argc && target__none(&ftrace.target)) 1228 ftrace.target.system_wide = true; 1229 cmd_func = __cmd_ftrace; 1230 break; 1231 case PERF_FTRACE_LATENCY: 1232 if (list_empty(&ftrace.filters)) { 1233 pr_err("Should provide a function to measure\n"); 1234 parse_options_usage(ftrace_usage, options, "T", 1); 1235 ret = -EINVAL; 1236 goto out_delete_filters; 1237 } 1238 cmd_func = __cmd_latency; 1239 break; 1240 case PERF_FTRACE_NONE: 1241 default: 1242 pr_err("Invalid subcommand\n"); 1243 ret = -EINVAL; 1244 goto out_delete_filters; 1245 } 1246 1247 ret = target__validate(&ftrace.target); 1248 if (ret) { 1249 char errbuf[512]; 1250 1251 target__strerror(&ftrace.target, ret, errbuf, 512); 1252 pr_err("%s\n", errbuf); 1253 goto out_delete_filters; 1254 } 1255 1256 ftrace.evlist = evlist__new(); 1257 if (ftrace.evlist == NULL) { 1258 ret = -ENOMEM; 1259 goto out_delete_filters; 1260 } 1261 1262 ret = evlist__create_maps(ftrace.evlist, &ftrace.target); 1263 if (ret < 0) 1264 goto out_delete_evlist; 1265 1266 if (argc) { 1267 ret = evlist__prepare_workload(ftrace.evlist, &ftrace.target, 1268 argv, false, 1269 ftrace__workload_exec_failed_signal); 1270 if (ret < 0) 1271 goto out_delete_evlist; 1272 } 1273 1274 ret = cmd_func(&ftrace); 1275 1276 out_delete_evlist: 1277 evlist__delete(ftrace.evlist); 1278 1279 out_delete_filters: 1280 delete_filter_func(&ftrace.filters); 1281 delete_filter_func(&ftrace.notrace); 1282 delete_filter_func(&ftrace.graph_funcs); 1283 delete_filter_func(&ftrace.nograph_funcs); 1284 1285 return ret; 1286 } 1287