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