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