1 // SPDX-License-Identifier: GPL-2.0 2 /* 3 * builtin-kwork.c 4 * 5 * Copyright (c) 2022 Huawei Inc, Yang Jihong <yangjihong1@huawei.com> 6 */ 7 8 #include "builtin.h" 9 10 #include "util/data.h" 11 #include "util/kwork.h" 12 #include "util/debug.h" 13 #include "util/symbol.h" 14 #include "util/thread.h" 15 #include "util/string2.h" 16 #include "util/callchain.h" 17 #include "util/evsel_fprintf.h" 18 19 #include <subcmd/pager.h> 20 #include <subcmd/parse-options.h> 21 22 #include <errno.h> 23 #include <inttypes.h> 24 #include <linux/err.h> 25 #include <linux/time64.h> 26 #include <linux/zalloc.h> 27 28 /* 29 * report header elements width 30 */ 31 #define PRINT_CPU_WIDTH 4 32 #define PRINT_COUNT_WIDTH 9 33 #define PRINT_RUNTIME_WIDTH 10 34 #define PRINT_LATENCY_WIDTH 10 35 #define PRINT_TIMESTAMP_WIDTH 17 36 #define PRINT_KWORK_NAME_WIDTH 30 37 #define RPINT_DECIMAL_WIDTH 3 38 #define PRINT_BRACKETPAIR_WIDTH 2 39 #define PRINT_TIME_UNIT_SEC_WIDTH 2 40 #define PRINT_TIME_UNIT_MESC_WIDTH 3 41 #define PRINT_RUNTIME_HEADER_WIDTH (PRINT_RUNTIME_WIDTH + PRINT_TIME_UNIT_MESC_WIDTH) 42 #define PRINT_LATENCY_HEADER_WIDTH (PRINT_LATENCY_WIDTH + PRINT_TIME_UNIT_MESC_WIDTH) 43 #define PRINT_TIMEHIST_CPU_WIDTH (PRINT_CPU_WIDTH + PRINT_BRACKETPAIR_WIDTH) 44 #define PRINT_TIMESTAMP_HEADER_WIDTH (PRINT_TIMESTAMP_WIDTH + PRINT_TIME_UNIT_SEC_WIDTH) 45 46 struct sort_dimension { 47 const char *name; 48 int (*cmp)(struct kwork_work *l, struct kwork_work *r); 49 struct list_head list; 50 }; 51 52 static int id_cmp(struct kwork_work *l, struct kwork_work *r) 53 { 54 if (l->cpu > r->cpu) 55 return 1; 56 if (l->cpu < r->cpu) 57 return -1; 58 59 if (l->id > r->id) 60 return 1; 61 if (l->id < r->id) 62 return -1; 63 64 return 0; 65 } 66 67 static int count_cmp(struct kwork_work *l, struct kwork_work *r) 68 { 69 if (l->nr_atoms > r->nr_atoms) 70 return 1; 71 if (l->nr_atoms < r->nr_atoms) 72 return -1; 73 74 return 0; 75 } 76 77 static int runtime_cmp(struct kwork_work *l, struct kwork_work *r) 78 { 79 if (l->total_runtime > r->total_runtime) 80 return 1; 81 if (l->total_runtime < r->total_runtime) 82 return -1; 83 84 return 0; 85 } 86 87 static int max_runtime_cmp(struct kwork_work *l, struct kwork_work *r) 88 { 89 if (l->max_runtime > r->max_runtime) 90 return 1; 91 if (l->max_runtime < r->max_runtime) 92 return -1; 93 94 return 0; 95 } 96 97 static int avg_latency_cmp(struct kwork_work *l, struct kwork_work *r) 98 { 99 u64 avgl, avgr; 100 101 if (!r->nr_atoms) 102 return 1; 103 if (!l->nr_atoms) 104 return -1; 105 106 avgl = l->total_latency / l->nr_atoms; 107 avgr = r->total_latency / r->nr_atoms; 108 109 if (avgl > avgr) 110 return 1; 111 if (avgl < avgr) 112 return -1; 113 114 return 0; 115 } 116 117 static int max_latency_cmp(struct kwork_work *l, struct kwork_work *r) 118 { 119 if (l->max_latency > r->max_latency) 120 return 1; 121 if (l->max_latency < r->max_latency) 122 return -1; 123 124 return 0; 125 } 126 127 static int sort_dimension__add(struct perf_kwork *kwork __maybe_unused, 128 const char *tok, struct list_head *list) 129 { 130 size_t i; 131 static struct sort_dimension max_sort_dimension = { 132 .name = "max", 133 .cmp = max_runtime_cmp, 134 }; 135 static struct sort_dimension id_sort_dimension = { 136 .name = "id", 137 .cmp = id_cmp, 138 }; 139 static struct sort_dimension runtime_sort_dimension = { 140 .name = "runtime", 141 .cmp = runtime_cmp, 142 }; 143 static struct sort_dimension count_sort_dimension = { 144 .name = "count", 145 .cmp = count_cmp, 146 }; 147 static struct sort_dimension avg_sort_dimension = { 148 .name = "avg", 149 .cmp = avg_latency_cmp, 150 }; 151 struct sort_dimension *available_sorts[] = { 152 &id_sort_dimension, 153 &max_sort_dimension, 154 &count_sort_dimension, 155 &runtime_sort_dimension, 156 &avg_sort_dimension, 157 }; 158 159 if (kwork->report == KWORK_REPORT_LATENCY) 160 max_sort_dimension.cmp = max_latency_cmp; 161 162 for (i = 0; i < ARRAY_SIZE(available_sorts); i++) { 163 if (!strcmp(available_sorts[i]->name, tok)) { 164 list_add_tail(&available_sorts[i]->list, list); 165 return 0; 166 } 167 } 168 169 return -1; 170 } 171 172 static void setup_sorting(struct perf_kwork *kwork, 173 const struct option *options, 174 const char * const usage_msg[]) 175 { 176 char *tmp, *tok, *str = strdup(kwork->sort_order); 177 178 for (tok = strtok_r(str, ", ", &tmp); 179 tok; tok = strtok_r(NULL, ", ", &tmp)) { 180 if (sort_dimension__add(kwork, tok, &kwork->sort_list) < 0) 181 usage_with_options_msg(usage_msg, options, 182 "Unknown --sort key: `%s'", tok); 183 } 184 185 pr_debug("Sort order: %s\n", kwork->sort_order); 186 free(str); 187 } 188 189 static struct kwork_atom *atom_new(struct perf_kwork *kwork, 190 struct perf_sample *sample) 191 { 192 unsigned long i; 193 struct kwork_atom_page *page; 194 struct kwork_atom *atom = NULL; 195 196 list_for_each_entry(page, &kwork->atom_page_list, list) { 197 if (!bitmap_full(page->bitmap, NR_ATOM_PER_PAGE)) { 198 i = find_first_zero_bit(page->bitmap, NR_ATOM_PER_PAGE); 199 BUG_ON(i >= NR_ATOM_PER_PAGE); 200 atom = &page->atoms[i]; 201 goto found_atom; 202 } 203 } 204 205 /* 206 * new page 207 */ 208 page = zalloc(sizeof(*page)); 209 if (page == NULL) { 210 pr_err("Failed to zalloc kwork atom page\n"); 211 return NULL; 212 } 213 214 i = 0; 215 atom = &page->atoms[0]; 216 list_add_tail(&page->list, &kwork->atom_page_list); 217 218 found_atom: 219 __set_bit(i, page->bitmap); 220 atom->time = sample->time; 221 atom->prev = NULL; 222 atom->page_addr = page; 223 atom->bit_inpage = i; 224 return atom; 225 } 226 227 static void atom_free(struct kwork_atom *atom) 228 { 229 if (atom->prev != NULL) 230 atom_free(atom->prev); 231 232 __clear_bit(atom->bit_inpage, 233 ((struct kwork_atom_page *)atom->page_addr)->bitmap); 234 } 235 236 static void atom_del(struct kwork_atom *atom) 237 { 238 list_del(&atom->list); 239 atom_free(atom); 240 } 241 242 static int work_cmp(struct list_head *list, 243 struct kwork_work *l, struct kwork_work *r) 244 { 245 int ret = 0; 246 struct sort_dimension *sort; 247 248 BUG_ON(list_empty(list)); 249 250 list_for_each_entry(sort, list, list) { 251 ret = sort->cmp(l, r); 252 if (ret) 253 return ret; 254 } 255 256 return ret; 257 } 258 259 static struct kwork_work *work_search(struct rb_root_cached *root, 260 struct kwork_work *key, 261 struct list_head *sort_list) 262 { 263 int cmp; 264 struct kwork_work *work; 265 struct rb_node *node = root->rb_root.rb_node; 266 267 while (node) { 268 work = container_of(node, struct kwork_work, node); 269 cmp = work_cmp(sort_list, key, work); 270 if (cmp > 0) 271 node = node->rb_left; 272 else if (cmp < 0) 273 node = node->rb_right; 274 else { 275 if (work->name == NULL) 276 work->name = key->name; 277 return work; 278 } 279 } 280 return NULL; 281 } 282 283 static void work_insert(struct rb_root_cached *root, 284 struct kwork_work *key, struct list_head *sort_list) 285 { 286 int cmp; 287 bool leftmost = true; 288 struct kwork_work *cur; 289 struct rb_node **new = &(root->rb_root.rb_node), *parent = NULL; 290 291 while (*new) { 292 cur = container_of(*new, struct kwork_work, node); 293 parent = *new; 294 cmp = work_cmp(sort_list, key, cur); 295 296 if (cmp > 0) 297 new = &((*new)->rb_left); 298 else { 299 new = &((*new)->rb_right); 300 leftmost = false; 301 } 302 } 303 304 rb_link_node(&key->node, parent, new); 305 rb_insert_color_cached(&key->node, root, leftmost); 306 } 307 308 static struct kwork_work *work_new(struct kwork_work *key) 309 { 310 int i; 311 struct kwork_work *work = zalloc(sizeof(*work)); 312 313 if (work == NULL) { 314 pr_err("Failed to zalloc kwork work\n"); 315 return NULL; 316 } 317 318 for (i = 0; i < KWORK_TRACE_MAX; i++) 319 INIT_LIST_HEAD(&work->atom_list[i]); 320 321 work->id = key->id; 322 work->cpu = key->cpu; 323 work->name = key->name; 324 work->class = key->class; 325 return work; 326 } 327 328 static struct kwork_work *work_findnew(struct rb_root_cached *root, 329 struct kwork_work *key, 330 struct list_head *sort_list) 331 { 332 struct kwork_work *work = work_search(root, key, sort_list); 333 334 if (work != NULL) 335 return work; 336 337 work = work_new(key); 338 if (work) 339 work_insert(root, work, sort_list); 340 341 return work; 342 } 343 344 static void profile_update_timespan(struct perf_kwork *kwork, 345 struct perf_sample *sample) 346 { 347 if (!kwork->summary) 348 return; 349 350 if ((kwork->timestart == 0) || (kwork->timestart > sample->time)) 351 kwork->timestart = sample->time; 352 353 if (kwork->timeend < sample->time) 354 kwork->timeend = sample->time; 355 } 356 357 static bool profile_event_match(struct perf_kwork *kwork, 358 struct kwork_work *work, 359 struct perf_sample *sample) 360 { 361 int cpu = work->cpu; 362 u64 time = sample->time; 363 struct perf_time_interval *ptime = &kwork->ptime; 364 365 if ((kwork->cpu_list != NULL) && !test_bit(cpu, kwork->cpu_bitmap)) 366 return false; 367 368 if (((ptime->start != 0) && (ptime->start > time)) || 369 ((ptime->end != 0) && (ptime->end < time))) 370 return false; 371 372 if ((kwork->profile_name != NULL) && 373 (work->name != NULL) && 374 (strcmp(work->name, kwork->profile_name) != 0)) 375 return false; 376 377 profile_update_timespan(kwork, sample); 378 return true; 379 } 380 381 static int work_push_atom(struct perf_kwork *kwork, 382 struct kwork_class *class, 383 enum kwork_trace_type src_type, 384 enum kwork_trace_type dst_type, 385 struct evsel *evsel, 386 struct perf_sample *sample, 387 struct machine *machine, 388 struct kwork_work **ret_work) 389 { 390 struct kwork_atom *atom, *dst_atom; 391 struct kwork_work *work, key; 392 393 BUG_ON(class->work_init == NULL); 394 class->work_init(class, &key, evsel, sample, machine); 395 396 atom = atom_new(kwork, sample); 397 if (atom == NULL) 398 return -1; 399 400 work = work_findnew(&class->work_root, &key, &kwork->cmp_id); 401 if (work == NULL) { 402 free(atom); 403 return -1; 404 } 405 406 if (!profile_event_match(kwork, work, sample)) 407 return 0; 408 409 if (dst_type < KWORK_TRACE_MAX) { 410 dst_atom = list_last_entry_or_null(&work->atom_list[dst_type], 411 struct kwork_atom, list); 412 if (dst_atom != NULL) { 413 atom->prev = dst_atom; 414 list_del(&dst_atom->list); 415 } 416 } 417 418 if (ret_work != NULL) 419 *ret_work = work; 420 421 list_add_tail(&atom->list, &work->atom_list[src_type]); 422 423 return 0; 424 } 425 426 static struct kwork_atom *work_pop_atom(struct perf_kwork *kwork, 427 struct kwork_class *class, 428 enum kwork_trace_type src_type, 429 enum kwork_trace_type dst_type, 430 struct evsel *evsel, 431 struct perf_sample *sample, 432 struct machine *machine, 433 struct kwork_work **ret_work) 434 { 435 struct kwork_atom *atom, *src_atom; 436 struct kwork_work *work, key; 437 438 BUG_ON(class->work_init == NULL); 439 class->work_init(class, &key, evsel, sample, machine); 440 441 work = work_findnew(&class->work_root, &key, &kwork->cmp_id); 442 if (ret_work != NULL) 443 *ret_work = work; 444 445 if (work == NULL) 446 return NULL; 447 448 if (!profile_event_match(kwork, work, sample)) 449 return NULL; 450 451 atom = list_last_entry_or_null(&work->atom_list[dst_type], 452 struct kwork_atom, list); 453 if (atom != NULL) 454 return atom; 455 456 src_atom = atom_new(kwork, sample); 457 if (src_atom != NULL) 458 list_add_tail(&src_atom->list, &work->atom_list[src_type]); 459 else { 460 if (ret_work != NULL) 461 *ret_work = NULL; 462 } 463 464 return NULL; 465 } 466 467 static void report_update_exit_event(struct kwork_work *work, 468 struct kwork_atom *atom, 469 struct perf_sample *sample) 470 { 471 u64 delta; 472 u64 exit_time = sample->time; 473 u64 entry_time = atom->time; 474 475 if ((entry_time != 0) && (exit_time >= entry_time)) { 476 delta = exit_time - entry_time; 477 if ((delta > work->max_runtime) || 478 (work->max_runtime == 0)) { 479 work->max_runtime = delta; 480 work->max_runtime_start = entry_time; 481 work->max_runtime_end = exit_time; 482 } 483 work->total_runtime += delta; 484 work->nr_atoms++; 485 } 486 } 487 488 static int report_entry_event(struct perf_kwork *kwork, 489 struct kwork_class *class, 490 struct evsel *evsel, 491 struct perf_sample *sample, 492 struct machine *machine) 493 { 494 return work_push_atom(kwork, class, KWORK_TRACE_ENTRY, 495 KWORK_TRACE_MAX, evsel, sample, 496 machine, NULL); 497 } 498 499 static int report_exit_event(struct perf_kwork *kwork, 500 struct kwork_class *class, 501 struct evsel *evsel, 502 struct perf_sample *sample, 503 struct machine *machine) 504 { 505 struct kwork_atom *atom = NULL; 506 struct kwork_work *work = NULL; 507 508 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 509 KWORK_TRACE_ENTRY, evsel, sample, 510 machine, &work); 511 if (work == NULL) 512 return -1; 513 514 if (atom != NULL) { 515 report_update_exit_event(work, atom, sample); 516 atom_del(atom); 517 } 518 519 return 0; 520 } 521 522 static void latency_update_entry_event(struct kwork_work *work, 523 struct kwork_atom *atom, 524 struct perf_sample *sample) 525 { 526 u64 delta; 527 u64 entry_time = sample->time; 528 u64 raise_time = atom->time; 529 530 if ((raise_time != 0) && (entry_time >= raise_time)) { 531 delta = entry_time - raise_time; 532 if ((delta > work->max_latency) || 533 (work->max_latency == 0)) { 534 work->max_latency = delta; 535 work->max_latency_start = raise_time; 536 work->max_latency_end = entry_time; 537 } 538 work->total_latency += delta; 539 work->nr_atoms++; 540 } 541 } 542 543 static int latency_raise_event(struct perf_kwork *kwork, 544 struct kwork_class *class, 545 struct evsel *evsel, 546 struct perf_sample *sample, 547 struct machine *machine) 548 { 549 return work_push_atom(kwork, class, KWORK_TRACE_RAISE, 550 KWORK_TRACE_MAX, evsel, sample, 551 machine, NULL); 552 } 553 554 static int latency_entry_event(struct perf_kwork *kwork, 555 struct kwork_class *class, 556 struct evsel *evsel, 557 struct perf_sample *sample, 558 struct machine *machine) 559 { 560 struct kwork_atom *atom = NULL; 561 struct kwork_work *work = NULL; 562 563 atom = work_pop_atom(kwork, class, KWORK_TRACE_ENTRY, 564 KWORK_TRACE_RAISE, evsel, sample, 565 machine, &work); 566 if (work == NULL) 567 return -1; 568 569 if (atom != NULL) { 570 latency_update_entry_event(work, atom, sample); 571 atom_del(atom); 572 } 573 574 return 0; 575 } 576 577 static void timehist_save_callchain(struct perf_kwork *kwork, 578 struct perf_sample *sample, 579 struct evsel *evsel, 580 struct machine *machine) 581 { 582 struct symbol *sym; 583 struct thread *thread; 584 struct callchain_cursor_node *node; 585 struct callchain_cursor *cursor = &callchain_cursor; 586 587 if (!kwork->show_callchain || sample->callchain == NULL) 588 return; 589 590 /* want main thread for process - has maps */ 591 thread = machine__findnew_thread(machine, sample->pid, sample->pid); 592 if (thread == NULL) { 593 pr_debug("Failed to get thread for pid %d\n", sample->pid); 594 return; 595 } 596 597 if (thread__resolve_callchain(thread, cursor, evsel, sample, 598 NULL, NULL, kwork->max_stack + 2) != 0) { 599 pr_debug("Failed to resolve callchain, skipping\n"); 600 goto out_put; 601 } 602 603 callchain_cursor_commit(cursor); 604 605 while (true) { 606 node = callchain_cursor_current(cursor); 607 if (node == NULL) 608 break; 609 610 sym = node->ms.sym; 611 if (sym) { 612 if (!strcmp(sym->name, "__softirqentry_text_start") || 613 !strcmp(sym->name, "__do_softirq")) 614 sym->ignore = 1; 615 } 616 617 callchain_cursor_advance(cursor); 618 } 619 620 out_put: 621 thread__put(thread); 622 } 623 624 static void timehist_print_event(struct perf_kwork *kwork, 625 struct kwork_work *work, 626 struct kwork_atom *atom, 627 struct perf_sample *sample, 628 struct addr_location *al) 629 { 630 char entrytime[32], exittime[32]; 631 char kwork_name[PRINT_KWORK_NAME_WIDTH]; 632 633 /* 634 * runtime start 635 */ 636 timestamp__scnprintf_usec(atom->time, 637 entrytime, sizeof(entrytime)); 638 printf(" %*s ", PRINT_TIMESTAMP_WIDTH, entrytime); 639 640 /* 641 * runtime end 642 */ 643 timestamp__scnprintf_usec(sample->time, 644 exittime, sizeof(exittime)); 645 printf(" %*s ", PRINT_TIMESTAMP_WIDTH, exittime); 646 647 /* 648 * cpu 649 */ 650 printf(" [%0*d] ", PRINT_CPU_WIDTH, work->cpu); 651 652 /* 653 * kwork name 654 */ 655 if (work->class && work->class->work_name) { 656 work->class->work_name(work, kwork_name, 657 PRINT_KWORK_NAME_WIDTH); 658 printf(" %-*s ", PRINT_KWORK_NAME_WIDTH, kwork_name); 659 } else 660 printf(" %-*s ", PRINT_KWORK_NAME_WIDTH, ""); 661 662 /* 663 *runtime 664 */ 665 printf(" %*.*f ", 666 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 667 (double)(sample->time - atom->time) / NSEC_PER_MSEC); 668 669 /* 670 * delaytime 671 */ 672 if (atom->prev != NULL) 673 printf(" %*.*f ", PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH, 674 (double)(atom->time - atom->prev->time) / NSEC_PER_MSEC); 675 else 676 printf(" %*s ", PRINT_LATENCY_WIDTH, " "); 677 678 /* 679 * callchain 680 */ 681 if (kwork->show_callchain) { 682 printf(" "); 683 sample__fprintf_sym(sample, al, 0, 684 EVSEL__PRINT_SYM | EVSEL__PRINT_ONELINE | 685 EVSEL__PRINT_CALLCHAIN_ARROW | 686 EVSEL__PRINT_SKIP_IGNORED, 687 &callchain_cursor, symbol_conf.bt_stop_list, 688 stdout); 689 } 690 691 printf("\n"); 692 } 693 694 static int timehist_raise_event(struct perf_kwork *kwork, 695 struct kwork_class *class, 696 struct evsel *evsel, 697 struct perf_sample *sample, 698 struct machine *machine) 699 { 700 return work_push_atom(kwork, class, KWORK_TRACE_RAISE, 701 KWORK_TRACE_MAX, evsel, sample, 702 machine, NULL); 703 } 704 705 static int timehist_entry_event(struct perf_kwork *kwork, 706 struct kwork_class *class, 707 struct evsel *evsel, 708 struct perf_sample *sample, 709 struct machine *machine) 710 { 711 int ret; 712 struct kwork_work *work = NULL; 713 714 ret = work_push_atom(kwork, class, KWORK_TRACE_ENTRY, 715 KWORK_TRACE_RAISE, evsel, sample, 716 machine, &work); 717 if (ret) 718 return ret; 719 720 if (work != NULL) 721 timehist_save_callchain(kwork, sample, evsel, machine); 722 723 return 0; 724 } 725 726 static int timehist_exit_event(struct perf_kwork *kwork, 727 struct kwork_class *class, 728 struct evsel *evsel, 729 struct perf_sample *sample, 730 struct machine *machine) 731 { 732 struct kwork_atom *atom = NULL; 733 struct kwork_work *work = NULL; 734 struct addr_location al; 735 736 if (machine__resolve(machine, &al, sample) < 0) { 737 pr_debug("Problem processing event, skipping it\n"); 738 return -1; 739 } 740 741 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 742 KWORK_TRACE_ENTRY, evsel, sample, 743 machine, &work); 744 if (work == NULL) 745 return -1; 746 747 if (atom != NULL) { 748 work->nr_atoms++; 749 timehist_print_event(kwork, work, atom, sample, &al); 750 atom_del(atom); 751 } 752 753 return 0; 754 } 755 756 static struct kwork_class kwork_irq; 757 static int process_irq_handler_entry_event(struct perf_tool *tool, 758 struct evsel *evsel, 759 struct perf_sample *sample, 760 struct machine *machine) 761 { 762 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 763 764 if (kwork->tp_handler->entry_event) 765 return kwork->tp_handler->entry_event(kwork, &kwork_irq, 766 evsel, sample, machine); 767 return 0; 768 } 769 770 static int process_irq_handler_exit_event(struct perf_tool *tool, 771 struct evsel *evsel, 772 struct perf_sample *sample, 773 struct machine *machine) 774 { 775 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 776 777 if (kwork->tp_handler->exit_event) 778 return kwork->tp_handler->exit_event(kwork, &kwork_irq, 779 evsel, sample, machine); 780 return 0; 781 } 782 783 const struct evsel_str_handler irq_tp_handlers[] = { 784 { "irq:irq_handler_entry", process_irq_handler_entry_event, }, 785 { "irq:irq_handler_exit", process_irq_handler_exit_event, }, 786 }; 787 788 static int irq_class_init(struct kwork_class *class, 789 struct perf_session *session) 790 { 791 if (perf_session__set_tracepoints_handlers(session, irq_tp_handlers)) { 792 pr_err("Failed to set irq tracepoints handlers\n"); 793 return -1; 794 } 795 796 class->work_root = RB_ROOT_CACHED; 797 return 0; 798 } 799 800 static void irq_work_init(struct kwork_class *class, 801 struct kwork_work *work, 802 struct evsel *evsel, 803 struct perf_sample *sample, 804 struct machine *machine __maybe_unused) 805 { 806 work->class = class; 807 work->cpu = sample->cpu; 808 work->id = evsel__intval(evsel, sample, "irq"); 809 work->name = evsel__strval(evsel, sample, "name"); 810 } 811 812 static void irq_work_name(struct kwork_work *work, char *buf, int len) 813 { 814 snprintf(buf, len, "%s:%" PRIu64 "", work->name, work->id); 815 } 816 817 static struct kwork_class kwork_irq = { 818 .name = "irq", 819 .type = KWORK_CLASS_IRQ, 820 .nr_tracepoints = 2, 821 .tp_handlers = irq_tp_handlers, 822 .class_init = irq_class_init, 823 .work_init = irq_work_init, 824 .work_name = irq_work_name, 825 }; 826 827 static struct kwork_class kwork_softirq; 828 static int process_softirq_raise_event(struct perf_tool *tool, 829 struct evsel *evsel, 830 struct perf_sample *sample, 831 struct machine *machine) 832 { 833 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 834 835 if (kwork->tp_handler->raise_event) 836 return kwork->tp_handler->raise_event(kwork, &kwork_softirq, 837 evsel, sample, machine); 838 839 return 0; 840 } 841 842 static int process_softirq_entry_event(struct perf_tool *tool, 843 struct evsel *evsel, 844 struct perf_sample *sample, 845 struct machine *machine) 846 { 847 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 848 849 if (kwork->tp_handler->entry_event) 850 return kwork->tp_handler->entry_event(kwork, &kwork_softirq, 851 evsel, sample, machine); 852 853 return 0; 854 } 855 856 static int process_softirq_exit_event(struct perf_tool *tool, 857 struct evsel *evsel, 858 struct perf_sample *sample, 859 struct machine *machine) 860 { 861 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 862 863 if (kwork->tp_handler->exit_event) 864 return kwork->tp_handler->exit_event(kwork, &kwork_softirq, 865 evsel, sample, machine); 866 867 return 0; 868 } 869 870 const struct evsel_str_handler softirq_tp_handlers[] = { 871 { "irq:softirq_raise", process_softirq_raise_event, }, 872 { "irq:softirq_entry", process_softirq_entry_event, }, 873 { "irq:softirq_exit", process_softirq_exit_event, }, 874 }; 875 876 static int softirq_class_init(struct kwork_class *class, 877 struct perf_session *session) 878 { 879 if (perf_session__set_tracepoints_handlers(session, 880 softirq_tp_handlers)) { 881 pr_err("Failed to set softirq tracepoints handlers\n"); 882 return -1; 883 } 884 885 class->work_root = RB_ROOT_CACHED; 886 return 0; 887 } 888 889 static char *evsel__softirq_name(struct evsel *evsel, u64 num) 890 { 891 char *name = NULL; 892 bool found = false; 893 struct tep_print_flag_sym *sym = NULL; 894 struct tep_print_arg *args = evsel->tp_format->print_fmt.args; 895 896 if ((args == NULL) || (args->next == NULL)) 897 return NULL; 898 899 /* skip softirq field: "REC->vec" */ 900 for (sym = args->next->symbol.symbols; sym != NULL; sym = sym->next) { 901 if ((eval_flag(sym->value) == (unsigned long long)num) && 902 (strlen(sym->str) != 0)) { 903 found = true; 904 break; 905 } 906 } 907 908 if (!found) 909 return NULL; 910 911 name = strdup(sym->str); 912 if (name == NULL) { 913 pr_err("Failed to copy symbol name\n"); 914 return NULL; 915 } 916 return name; 917 } 918 919 static void softirq_work_init(struct kwork_class *class, 920 struct kwork_work *work, 921 struct evsel *evsel, 922 struct perf_sample *sample, 923 struct machine *machine __maybe_unused) 924 { 925 u64 num = evsel__intval(evsel, sample, "vec"); 926 927 work->id = num; 928 work->class = class; 929 work->cpu = sample->cpu; 930 work->name = evsel__softirq_name(evsel, num); 931 } 932 933 static void softirq_work_name(struct kwork_work *work, char *buf, int len) 934 { 935 snprintf(buf, len, "(s)%s:%" PRIu64 "", work->name, work->id); 936 } 937 938 static struct kwork_class kwork_softirq = { 939 .name = "softirq", 940 .type = KWORK_CLASS_SOFTIRQ, 941 .nr_tracepoints = 3, 942 .tp_handlers = softirq_tp_handlers, 943 .class_init = softirq_class_init, 944 .work_init = softirq_work_init, 945 .work_name = softirq_work_name, 946 }; 947 948 static struct kwork_class kwork_workqueue; 949 static int process_workqueue_activate_work_event(struct perf_tool *tool, 950 struct evsel *evsel, 951 struct perf_sample *sample, 952 struct machine *machine) 953 { 954 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 955 956 if (kwork->tp_handler->raise_event) 957 return kwork->tp_handler->raise_event(kwork, &kwork_workqueue, 958 evsel, sample, machine); 959 960 return 0; 961 } 962 963 static int process_workqueue_execute_start_event(struct perf_tool *tool, 964 struct evsel *evsel, 965 struct perf_sample *sample, 966 struct machine *machine) 967 { 968 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 969 970 if (kwork->tp_handler->entry_event) 971 return kwork->tp_handler->entry_event(kwork, &kwork_workqueue, 972 evsel, sample, machine); 973 974 return 0; 975 } 976 977 static int process_workqueue_execute_end_event(struct perf_tool *tool, 978 struct evsel *evsel, 979 struct perf_sample *sample, 980 struct machine *machine) 981 { 982 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 983 984 if (kwork->tp_handler->exit_event) 985 return kwork->tp_handler->exit_event(kwork, &kwork_workqueue, 986 evsel, sample, machine); 987 988 return 0; 989 } 990 991 const struct evsel_str_handler workqueue_tp_handlers[] = { 992 { "workqueue:workqueue_activate_work", process_workqueue_activate_work_event, }, 993 { "workqueue:workqueue_execute_start", process_workqueue_execute_start_event, }, 994 { "workqueue:workqueue_execute_end", process_workqueue_execute_end_event, }, 995 }; 996 997 static int workqueue_class_init(struct kwork_class *class, 998 struct perf_session *session) 999 { 1000 if (perf_session__set_tracepoints_handlers(session, 1001 workqueue_tp_handlers)) { 1002 pr_err("Failed to set workqueue tracepoints handlers\n"); 1003 return -1; 1004 } 1005 1006 class->work_root = RB_ROOT_CACHED; 1007 return 0; 1008 } 1009 1010 static void workqueue_work_init(struct kwork_class *class, 1011 struct kwork_work *work, 1012 struct evsel *evsel, 1013 struct perf_sample *sample, 1014 struct machine *machine) 1015 { 1016 char *modp = NULL; 1017 unsigned long long function_addr = evsel__intval(evsel, 1018 sample, "function"); 1019 1020 work->class = class; 1021 work->cpu = sample->cpu; 1022 work->id = evsel__intval(evsel, sample, "work"); 1023 work->name = function_addr == 0 ? NULL : 1024 machine__resolve_kernel_addr(machine, &function_addr, &modp); 1025 } 1026 1027 static void workqueue_work_name(struct kwork_work *work, char *buf, int len) 1028 { 1029 if (work->name != NULL) 1030 snprintf(buf, len, "(w)%s", work->name); 1031 else 1032 snprintf(buf, len, "(w)0x%" PRIx64, work->id); 1033 } 1034 1035 static struct kwork_class kwork_workqueue = { 1036 .name = "workqueue", 1037 .type = KWORK_CLASS_WORKQUEUE, 1038 .nr_tracepoints = 3, 1039 .tp_handlers = workqueue_tp_handlers, 1040 .class_init = workqueue_class_init, 1041 .work_init = workqueue_work_init, 1042 .work_name = workqueue_work_name, 1043 }; 1044 1045 static struct kwork_class *kwork_class_supported_list[KWORK_CLASS_MAX] = { 1046 [KWORK_CLASS_IRQ] = &kwork_irq, 1047 [KWORK_CLASS_SOFTIRQ] = &kwork_softirq, 1048 [KWORK_CLASS_WORKQUEUE] = &kwork_workqueue, 1049 }; 1050 1051 static void print_separator(int len) 1052 { 1053 printf(" %.*s\n", len, graph_dotted_line); 1054 } 1055 1056 static int report_print_work(struct perf_kwork *kwork, struct kwork_work *work) 1057 { 1058 int ret = 0; 1059 char kwork_name[PRINT_KWORK_NAME_WIDTH]; 1060 char max_runtime_start[32], max_runtime_end[32]; 1061 char max_latency_start[32], max_latency_end[32]; 1062 1063 printf(" "); 1064 1065 /* 1066 * kwork name 1067 */ 1068 if (work->class && work->class->work_name) { 1069 work->class->work_name(work, kwork_name, 1070 PRINT_KWORK_NAME_WIDTH); 1071 ret += printf(" %-*s |", PRINT_KWORK_NAME_WIDTH, kwork_name); 1072 } else { 1073 ret += printf(" %-*s |", PRINT_KWORK_NAME_WIDTH, ""); 1074 } 1075 1076 /* 1077 * cpu 1078 */ 1079 ret += printf(" %0*d |", PRINT_CPU_WIDTH, work->cpu); 1080 1081 /* 1082 * total runtime 1083 */ 1084 if (kwork->report == KWORK_REPORT_RUNTIME) { 1085 ret += printf(" %*.*f ms |", 1086 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 1087 (double)work->total_runtime / NSEC_PER_MSEC); 1088 } else if (kwork->report == KWORK_REPORT_LATENCY) { // avg delay 1089 ret += printf(" %*.*f ms |", 1090 PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH, 1091 (double)work->total_latency / 1092 work->nr_atoms / NSEC_PER_MSEC); 1093 } 1094 1095 /* 1096 * count 1097 */ 1098 ret += printf(" %*" PRIu64 " |", PRINT_COUNT_WIDTH, work->nr_atoms); 1099 1100 /* 1101 * max runtime, max runtime start, max runtime end 1102 */ 1103 if (kwork->report == KWORK_REPORT_RUNTIME) { 1104 timestamp__scnprintf_usec(work->max_runtime_start, 1105 max_runtime_start, 1106 sizeof(max_runtime_start)); 1107 timestamp__scnprintf_usec(work->max_runtime_end, 1108 max_runtime_end, 1109 sizeof(max_runtime_end)); 1110 ret += printf(" %*.*f ms | %*s s | %*s s |", 1111 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 1112 (double)work->max_runtime / NSEC_PER_MSEC, 1113 PRINT_TIMESTAMP_WIDTH, max_runtime_start, 1114 PRINT_TIMESTAMP_WIDTH, max_runtime_end); 1115 } 1116 /* 1117 * max delay, max delay start, max delay end 1118 */ 1119 else if (kwork->report == KWORK_REPORT_LATENCY) { 1120 timestamp__scnprintf_usec(work->max_latency_start, 1121 max_latency_start, 1122 sizeof(max_latency_start)); 1123 timestamp__scnprintf_usec(work->max_latency_end, 1124 max_latency_end, 1125 sizeof(max_latency_end)); 1126 ret += printf(" %*.*f ms | %*s s | %*s s |", 1127 PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH, 1128 (double)work->max_latency / NSEC_PER_MSEC, 1129 PRINT_TIMESTAMP_WIDTH, max_latency_start, 1130 PRINT_TIMESTAMP_WIDTH, max_latency_end); 1131 } 1132 1133 printf("\n"); 1134 return ret; 1135 } 1136 1137 static int report_print_header(struct perf_kwork *kwork) 1138 { 1139 int ret; 1140 1141 printf("\n "); 1142 ret = printf(" %-*s | %-*s |", 1143 PRINT_KWORK_NAME_WIDTH, "Kwork Name", 1144 PRINT_CPU_WIDTH, "Cpu"); 1145 1146 if (kwork->report == KWORK_REPORT_RUNTIME) { 1147 ret += printf(" %-*s |", 1148 PRINT_RUNTIME_HEADER_WIDTH, "Total Runtime"); 1149 } else if (kwork->report == KWORK_REPORT_LATENCY) { 1150 ret += printf(" %-*s |", 1151 PRINT_LATENCY_HEADER_WIDTH, "Avg delay"); 1152 } 1153 1154 ret += printf(" %-*s |", PRINT_COUNT_WIDTH, "Count"); 1155 1156 if (kwork->report == KWORK_REPORT_RUNTIME) { 1157 ret += printf(" %-*s | %-*s | %-*s |", 1158 PRINT_RUNTIME_HEADER_WIDTH, "Max runtime", 1159 PRINT_TIMESTAMP_HEADER_WIDTH, "Max runtime start", 1160 PRINT_TIMESTAMP_HEADER_WIDTH, "Max runtime end"); 1161 } else if (kwork->report == KWORK_REPORT_LATENCY) { 1162 ret += printf(" %-*s | %-*s | %-*s |", 1163 PRINT_LATENCY_HEADER_WIDTH, "Max delay", 1164 PRINT_TIMESTAMP_HEADER_WIDTH, "Max delay start", 1165 PRINT_TIMESTAMP_HEADER_WIDTH, "Max delay end"); 1166 } 1167 1168 printf("\n"); 1169 print_separator(ret); 1170 return ret; 1171 } 1172 1173 static void timehist_print_header(void) 1174 { 1175 /* 1176 * header row 1177 */ 1178 printf(" %-*s %-*s %-*s %-*s %-*s %-*s\n", 1179 PRINT_TIMESTAMP_WIDTH, "Runtime start", 1180 PRINT_TIMESTAMP_WIDTH, "Runtime end", 1181 PRINT_TIMEHIST_CPU_WIDTH, "Cpu", 1182 PRINT_KWORK_NAME_WIDTH, "Kwork name", 1183 PRINT_RUNTIME_WIDTH, "Runtime", 1184 PRINT_RUNTIME_WIDTH, "Delaytime"); 1185 1186 /* 1187 * units row 1188 */ 1189 printf(" %-*s %-*s %-*s %-*s %-*s %-*s\n", 1190 PRINT_TIMESTAMP_WIDTH, "", 1191 PRINT_TIMESTAMP_WIDTH, "", 1192 PRINT_TIMEHIST_CPU_WIDTH, "", 1193 PRINT_KWORK_NAME_WIDTH, "(TYPE)NAME:NUM", 1194 PRINT_RUNTIME_WIDTH, "(msec)", 1195 PRINT_RUNTIME_WIDTH, "(msec)"); 1196 1197 /* 1198 * separator 1199 */ 1200 printf(" %.*s %.*s %.*s %.*s %.*s %.*s\n", 1201 PRINT_TIMESTAMP_WIDTH, graph_dotted_line, 1202 PRINT_TIMESTAMP_WIDTH, graph_dotted_line, 1203 PRINT_TIMEHIST_CPU_WIDTH, graph_dotted_line, 1204 PRINT_KWORK_NAME_WIDTH, graph_dotted_line, 1205 PRINT_RUNTIME_WIDTH, graph_dotted_line, 1206 PRINT_RUNTIME_WIDTH, graph_dotted_line); 1207 } 1208 1209 static void print_summary(struct perf_kwork *kwork) 1210 { 1211 u64 time = kwork->timeend - kwork->timestart; 1212 1213 printf(" Total count : %9" PRIu64 "\n", kwork->all_count); 1214 printf(" Total runtime (msec) : %9.3f (%.3f%% load average)\n", 1215 (double)kwork->all_runtime / NSEC_PER_MSEC, 1216 time == 0 ? 0 : (double)kwork->all_runtime / time); 1217 printf(" Total time span (msec) : %9.3f\n", 1218 (double)time / NSEC_PER_MSEC); 1219 } 1220 1221 static unsigned long long nr_list_entry(struct list_head *head) 1222 { 1223 struct list_head *pos; 1224 unsigned long long n = 0; 1225 1226 list_for_each(pos, head) 1227 n++; 1228 1229 return n; 1230 } 1231 1232 static void print_skipped_events(struct perf_kwork *kwork) 1233 { 1234 int i; 1235 const char *const kwork_event_str[] = { 1236 [KWORK_TRACE_RAISE] = "raise", 1237 [KWORK_TRACE_ENTRY] = "entry", 1238 [KWORK_TRACE_EXIT] = "exit", 1239 }; 1240 1241 if ((kwork->nr_skipped_events[KWORK_TRACE_MAX] != 0) && 1242 (kwork->nr_events != 0)) { 1243 printf(" INFO: %.3f%% skipped events (%" PRIu64 " including ", 1244 (double)kwork->nr_skipped_events[KWORK_TRACE_MAX] / 1245 (double)kwork->nr_events * 100.0, 1246 kwork->nr_skipped_events[KWORK_TRACE_MAX]); 1247 1248 for (i = 0; i < KWORK_TRACE_MAX; i++) { 1249 printf("%" PRIu64 " %s%s", 1250 kwork->nr_skipped_events[i], 1251 kwork_event_str[i], 1252 (i == KWORK_TRACE_MAX - 1) ? ")\n" : ", "); 1253 } 1254 } 1255 1256 if (verbose > 0) 1257 printf(" INFO: use %lld atom pages\n", 1258 nr_list_entry(&kwork->atom_page_list)); 1259 } 1260 1261 static void print_bad_events(struct perf_kwork *kwork) 1262 { 1263 if ((kwork->nr_lost_events != 0) && (kwork->nr_events != 0)) { 1264 printf(" INFO: %.3f%% lost events (%ld out of %ld, in %ld chunks)\n", 1265 (double)kwork->nr_lost_events / 1266 (double)kwork->nr_events * 100.0, 1267 kwork->nr_lost_events, kwork->nr_events, 1268 kwork->nr_lost_chunks); 1269 } 1270 } 1271 1272 static void work_sort(struct perf_kwork *kwork, struct kwork_class *class) 1273 { 1274 struct rb_node *node; 1275 struct kwork_work *data; 1276 struct rb_root_cached *root = &class->work_root; 1277 1278 pr_debug("Sorting %s ...\n", class->name); 1279 for (;;) { 1280 node = rb_first_cached(root); 1281 if (!node) 1282 break; 1283 1284 rb_erase_cached(node, root); 1285 data = rb_entry(node, struct kwork_work, node); 1286 work_insert(&kwork->sorted_work_root, 1287 data, &kwork->sort_list); 1288 } 1289 } 1290 1291 static void perf_kwork__sort(struct perf_kwork *kwork) 1292 { 1293 struct kwork_class *class; 1294 1295 list_for_each_entry(class, &kwork->class_list, list) 1296 work_sort(kwork, class); 1297 } 1298 1299 static int perf_kwork__check_config(struct perf_kwork *kwork, 1300 struct perf_session *session) 1301 { 1302 int ret; 1303 struct evsel *evsel; 1304 struct kwork_class *class; 1305 1306 static struct trace_kwork_handler report_ops = { 1307 .entry_event = report_entry_event, 1308 .exit_event = report_exit_event, 1309 }; 1310 static struct trace_kwork_handler latency_ops = { 1311 .raise_event = latency_raise_event, 1312 .entry_event = latency_entry_event, 1313 }; 1314 static struct trace_kwork_handler timehist_ops = { 1315 .raise_event = timehist_raise_event, 1316 .entry_event = timehist_entry_event, 1317 .exit_event = timehist_exit_event, 1318 }; 1319 1320 switch (kwork->report) { 1321 case KWORK_REPORT_RUNTIME: 1322 kwork->tp_handler = &report_ops; 1323 break; 1324 case KWORK_REPORT_LATENCY: 1325 kwork->tp_handler = &latency_ops; 1326 break; 1327 case KWORK_REPORT_TIMEHIST: 1328 kwork->tp_handler = &timehist_ops; 1329 break; 1330 default: 1331 pr_debug("Invalid report type %d\n", kwork->report); 1332 return -1; 1333 } 1334 1335 list_for_each_entry(class, &kwork->class_list, list) 1336 if ((class->class_init != NULL) && 1337 (class->class_init(class, session) != 0)) 1338 return -1; 1339 1340 if (kwork->cpu_list != NULL) { 1341 ret = perf_session__cpu_bitmap(session, 1342 kwork->cpu_list, 1343 kwork->cpu_bitmap); 1344 if (ret < 0) { 1345 pr_err("Invalid cpu bitmap\n"); 1346 return -1; 1347 } 1348 } 1349 1350 if (kwork->time_str != NULL) { 1351 ret = perf_time__parse_str(&kwork->ptime, kwork->time_str); 1352 if (ret != 0) { 1353 pr_err("Invalid time span\n"); 1354 return -1; 1355 } 1356 } 1357 1358 list_for_each_entry(evsel, &session->evlist->core.entries, core.node) { 1359 if (kwork->show_callchain && !evsel__has_callchain(evsel)) { 1360 pr_debug("Samples do not have callchains\n"); 1361 kwork->show_callchain = 0; 1362 symbol_conf.use_callchain = 0; 1363 } 1364 } 1365 1366 return 0; 1367 } 1368 1369 static int perf_kwork__read_events(struct perf_kwork *kwork) 1370 { 1371 int ret = -1; 1372 struct perf_session *session = NULL; 1373 1374 struct perf_data data = { 1375 .path = input_name, 1376 .mode = PERF_DATA_MODE_READ, 1377 .force = kwork->force, 1378 }; 1379 1380 session = perf_session__new(&data, &kwork->tool); 1381 if (IS_ERR(session)) { 1382 pr_debug("Error creating perf session\n"); 1383 return PTR_ERR(session); 1384 } 1385 1386 symbol__init(&session->header.env); 1387 1388 if (perf_kwork__check_config(kwork, session) != 0) 1389 goto out_delete; 1390 1391 if (session->tevent.pevent && 1392 tep_set_function_resolver(session->tevent.pevent, 1393 machine__resolve_kernel_addr, 1394 &session->machines.host) < 0) { 1395 pr_err("Failed to set libtraceevent function resolver\n"); 1396 goto out_delete; 1397 } 1398 1399 if (kwork->report == KWORK_REPORT_TIMEHIST) 1400 timehist_print_header(); 1401 1402 ret = perf_session__process_events(session); 1403 if (ret) { 1404 pr_debug("Failed to process events, error %d\n", ret); 1405 goto out_delete; 1406 } 1407 1408 kwork->nr_events = session->evlist->stats.nr_events[0]; 1409 kwork->nr_lost_events = session->evlist->stats.total_lost; 1410 kwork->nr_lost_chunks = session->evlist->stats.nr_events[PERF_RECORD_LOST]; 1411 1412 out_delete: 1413 perf_session__delete(session); 1414 return ret; 1415 } 1416 1417 static void process_skipped_events(struct perf_kwork *kwork, 1418 struct kwork_work *work) 1419 { 1420 int i; 1421 unsigned long long count; 1422 1423 for (i = 0; i < KWORK_TRACE_MAX; i++) { 1424 count = nr_list_entry(&work->atom_list[i]); 1425 kwork->nr_skipped_events[i] += count; 1426 kwork->nr_skipped_events[KWORK_TRACE_MAX] += count; 1427 } 1428 } 1429 1430 struct kwork_work *perf_kwork_add_work(struct perf_kwork *kwork, 1431 struct kwork_class *class, 1432 struct kwork_work *key) 1433 { 1434 struct kwork_work *work = NULL; 1435 1436 work = work_new(key); 1437 if (work == NULL) 1438 return NULL; 1439 1440 work_insert(&class->work_root, work, &kwork->cmp_id); 1441 return work; 1442 } 1443 1444 static void sig_handler(int sig) 1445 { 1446 /* 1447 * Simply capture termination signal so that 1448 * the program can continue after pause returns 1449 */ 1450 pr_debug("Captuer signal %d\n", sig); 1451 } 1452 1453 static int perf_kwork__report_bpf(struct perf_kwork *kwork) 1454 { 1455 int ret; 1456 1457 signal(SIGINT, sig_handler); 1458 signal(SIGTERM, sig_handler); 1459 1460 ret = perf_kwork__trace_prepare_bpf(kwork); 1461 if (ret) 1462 return -1; 1463 1464 printf("Starting trace, Hit <Ctrl+C> to stop and report\n"); 1465 1466 perf_kwork__trace_start(); 1467 1468 /* 1469 * a simple pause, wait here for stop signal 1470 */ 1471 pause(); 1472 1473 perf_kwork__trace_finish(); 1474 1475 perf_kwork__report_read_bpf(kwork); 1476 1477 perf_kwork__report_cleanup_bpf(); 1478 1479 return 0; 1480 } 1481 1482 static int perf_kwork__report(struct perf_kwork *kwork) 1483 { 1484 int ret; 1485 struct rb_node *next; 1486 struct kwork_work *work; 1487 1488 if (kwork->use_bpf) 1489 ret = perf_kwork__report_bpf(kwork); 1490 else 1491 ret = perf_kwork__read_events(kwork); 1492 1493 if (ret != 0) 1494 return -1; 1495 1496 perf_kwork__sort(kwork); 1497 1498 setup_pager(); 1499 1500 ret = report_print_header(kwork); 1501 next = rb_first_cached(&kwork->sorted_work_root); 1502 while (next) { 1503 work = rb_entry(next, struct kwork_work, node); 1504 process_skipped_events(kwork, work); 1505 1506 if (work->nr_atoms != 0) { 1507 report_print_work(kwork, work); 1508 if (kwork->summary) { 1509 kwork->all_runtime += work->total_runtime; 1510 kwork->all_count += work->nr_atoms; 1511 } 1512 } 1513 next = rb_next(next); 1514 } 1515 print_separator(ret); 1516 1517 if (kwork->summary) { 1518 print_summary(kwork); 1519 print_separator(ret); 1520 } 1521 1522 print_bad_events(kwork); 1523 print_skipped_events(kwork); 1524 printf("\n"); 1525 1526 return 0; 1527 } 1528 1529 typedef int (*tracepoint_handler)(struct perf_tool *tool, 1530 struct evsel *evsel, 1531 struct perf_sample *sample, 1532 struct machine *machine); 1533 1534 static int perf_kwork__process_tracepoint_sample(struct perf_tool *tool, 1535 union perf_event *event __maybe_unused, 1536 struct perf_sample *sample, 1537 struct evsel *evsel, 1538 struct machine *machine) 1539 { 1540 int err = 0; 1541 1542 if (evsel->handler != NULL) { 1543 tracepoint_handler f = evsel->handler; 1544 1545 err = f(tool, evsel, sample, machine); 1546 } 1547 1548 return err; 1549 } 1550 1551 static int perf_kwork__timehist(struct perf_kwork *kwork) 1552 { 1553 /* 1554 * event handlers for timehist option 1555 */ 1556 kwork->tool.comm = perf_event__process_comm; 1557 kwork->tool.exit = perf_event__process_exit; 1558 kwork->tool.fork = perf_event__process_fork; 1559 kwork->tool.attr = perf_event__process_attr; 1560 kwork->tool.tracing_data = perf_event__process_tracing_data; 1561 kwork->tool.build_id = perf_event__process_build_id; 1562 kwork->tool.ordered_events = true; 1563 kwork->tool.ordering_requires_timestamps = true; 1564 symbol_conf.use_callchain = kwork->show_callchain; 1565 1566 if (symbol__validate_sym_arguments()) { 1567 pr_err("Failed to validate sym arguments\n"); 1568 return -1; 1569 } 1570 1571 setup_pager(); 1572 1573 return perf_kwork__read_events(kwork); 1574 } 1575 1576 static void setup_event_list(struct perf_kwork *kwork, 1577 const struct option *options, 1578 const char * const usage_msg[]) 1579 { 1580 int i; 1581 struct kwork_class *class; 1582 char *tmp, *tok, *str; 1583 1584 if (kwork->event_list_str == NULL) 1585 goto null_event_list_str; 1586 1587 str = strdup(kwork->event_list_str); 1588 for (tok = strtok_r(str, ", ", &tmp); 1589 tok; tok = strtok_r(NULL, ", ", &tmp)) { 1590 for (i = 0; i < KWORK_CLASS_MAX; i++) { 1591 class = kwork_class_supported_list[i]; 1592 if (strcmp(tok, class->name) == 0) { 1593 list_add_tail(&class->list, &kwork->class_list); 1594 break; 1595 } 1596 } 1597 if (i == KWORK_CLASS_MAX) { 1598 usage_with_options_msg(usage_msg, options, 1599 "Unknown --event key: `%s'", tok); 1600 } 1601 } 1602 free(str); 1603 1604 null_event_list_str: 1605 /* 1606 * config all kwork events if not specified 1607 */ 1608 if (list_empty(&kwork->class_list)) { 1609 for (i = 0; i < KWORK_CLASS_MAX; i++) { 1610 list_add_tail(&kwork_class_supported_list[i]->list, 1611 &kwork->class_list); 1612 } 1613 } 1614 1615 pr_debug("Config event list:"); 1616 list_for_each_entry(class, &kwork->class_list, list) 1617 pr_debug(" %s", class->name); 1618 pr_debug("\n"); 1619 } 1620 1621 static int perf_kwork__record(struct perf_kwork *kwork, 1622 int argc, const char **argv) 1623 { 1624 const char **rec_argv; 1625 unsigned int rec_argc, i, j; 1626 struct kwork_class *class; 1627 1628 const char *const record_args[] = { 1629 "record", 1630 "-a", 1631 "-R", 1632 "-m", "1024", 1633 "-c", "1", 1634 }; 1635 1636 rec_argc = ARRAY_SIZE(record_args) + argc - 1; 1637 1638 list_for_each_entry(class, &kwork->class_list, list) 1639 rec_argc += 2 * class->nr_tracepoints; 1640 1641 rec_argv = calloc(rec_argc + 1, sizeof(char *)); 1642 if (rec_argv == NULL) 1643 return -ENOMEM; 1644 1645 for (i = 0; i < ARRAY_SIZE(record_args); i++) 1646 rec_argv[i] = strdup(record_args[i]); 1647 1648 list_for_each_entry(class, &kwork->class_list, list) { 1649 for (j = 0; j < class->nr_tracepoints; j++) { 1650 rec_argv[i++] = strdup("-e"); 1651 rec_argv[i++] = strdup(class->tp_handlers[j].name); 1652 } 1653 } 1654 1655 for (j = 1; j < (unsigned int)argc; j++, i++) 1656 rec_argv[i] = argv[j]; 1657 1658 BUG_ON(i != rec_argc); 1659 1660 pr_debug("record comm: "); 1661 for (j = 0; j < rec_argc; j++) 1662 pr_debug("%s ", rec_argv[j]); 1663 pr_debug("\n"); 1664 1665 return cmd_record(i, rec_argv); 1666 } 1667 1668 int cmd_kwork(int argc, const char **argv) 1669 { 1670 static struct perf_kwork kwork = { 1671 .class_list = LIST_HEAD_INIT(kwork.class_list), 1672 .tool = { 1673 .mmap = perf_event__process_mmap, 1674 .mmap2 = perf_event__process_mmap2, 1675 .sample = perf_kwork__process_tracepoint_sample, 1676 }, 1677 .atom_page_list = LIST_HEAD_INIT(kwork.atom_page_list), 1678 .sort_list = LIST_HEAD_INIT(kwork.sort_list), 1679 .cmp_id = LIST_HEAD_INIT(kwork.cmp_id), 1680 .sorted_work_root = RB_ROOT_CACHED, 1681 .tp_handler = NULL, 1682 .profile_name = NULL, 1683 .cpu_list = NULL, 1684 .time_str = NULL, 1685 .force = false, 1686 .event_list_str = NULL, 1687 .summary = false, 1688 .sort_order = NULL, 1689 .show_callchain = false, 1690 .max_stack = 5, 1691 .timestart = 0, 1692 .timeend = 0, 1693 .nr_events = 0, 1694 .nr_lost_chunks = 0, 1695 .nr_lost_events = 0, 1696 .all_runtime = 0, 1697 .all_count = 0, 1698 .nr_skipped_events = { 0 }, 1699 }; 1700 static const char default_report_sort_order[] = "runtime, max, count"; 1701 static const char default_latency_sort_order[] = "avg, max, count"; 1702 const struct option kwork_options[] = { 1703 OPT_INCR('v', "verbose", &verbose, 1704 "be more verbose (show symbol address, etc)"), 1705 OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, 1706 "dump raw trace in ASCII"), 1707 OPT_STRING('k', "kwork", &kwork.event_list_str, "kwork", 1708 "list of kwork to profile (irq, softirq, workqueue, etc)"), 1709 OPT_BOOLEAN('f', "force", &kwork.force, "don't complain, do it"), 1710 OPT_END() 1711 }; 1712 const struct option report_options[] = { 1713 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]", 1714 "sort by key(s): runtime, max, count"), 1715 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 1716 "list of cpus to profile"), 1717 OPT_STRING('n', "name", &kwork.profile_name, "name", 1718 "event name to profile"), 1719 OPT_STRING(0, "time", &kwork.time_str, "str", 1720 "Time span for analysis (start,stop)"), 1721 OPT_STRING('i', "input", &input_name, "file", 1722 "input file name"), 1723 OPT_BOOLEAN('S', "with-summary", &kwork.summary, 1724 "Show summary with statistics"), 1725 #ifdef HAVE_BPF_SKEL 1726 OPT_BOOLEAN('b', "use-bpf", &kwork.use_bpf, 1727 "Use BPF to measure kwork runtime"), 1728 #endif 1729 OPT_PARENT(kwork_options) 1730 }; 1731 const struct option latency_options[] = { 1732 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]", 1733 "sort by key(s): avg, max, count"), 1734 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 1735 "list of cpus to profile"), 1736 OPT_STRING('n', "name", &kwork.profile_name, "name", 1737 "event name to profile"), 1738 OPT_STRING(0, "time", &kwork.time_str, "str", 1739 "Time span for analysis (start,stop)"), 1740 OPT_STRING('i', "input", &input_name, "file", 1741 "input file name"), 1742 #ifdef HAVE_BPF_SKEL 1743 OPT_BOOLEAN('b', "use-bpf", &kwork.use_bpf, 1744 "Use BPF to measure kwork latency"), 1745 #endif 1746 OPT_PARENT(kwork_options) 1747 }; 1748 const struct option timehist_options[] = { 1749 OPT_STRING('k', "vmlinux", &symbol_conf.vmlinux_name, 1750 "file", "vmlinux pathname"), 1751 OPT_STRING(0, "kallsyms", &symbol_conf.kallsyms_name, 1752 "file", "kallsyms pathname"), 1753 OPT_BOOLEAN('g', "call-graph", &kwork.show_callchain, 1754 "Display call chains if present"), 1755 OPT_UINTEGER(0, "max-stack", &kwork.max_stack, 1756 "Maximum number of functions to display backtrace."), 1757 OPT_STRING(0, "symfs", &symbol_conf.symfs, "directory", 1758 "Look for files with symbols relative to this directory"), 1759 OPT_STRING(0, "time", &kwork.time_str, "str", 1760 "Time span for analysis (start,stop)"), 1761 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 1762 "list of cpus to profile"), 1763 OPT_STRING('n', "name", &kwork.profile_name, "name", 1764 "event name to profile"), 1765 OPT_STRING('i', "input", &input_name, "file", 1766 "input file name"), 1767 OPT_PARENT(kwork_options) 1768 }; 1769 const char *kwork_usage[] = { 1770 NULL, 1771 NULL 1772 }; 1773 const char * const report_usage[] = { 1774 "perf kwork report [<options>]", 1775 NULL 1776 }; 1777 const char * const latency_usage[] = { 1778 "perf kwork latency [<options>]", 1779 NULL 1780 }; 1781 const char * const timehist_usage[] = { 1782 "perf kwork timehist [<options>]", 1783 NULL 1784 }; 1785 const char *const kwork_subcommands[] = { 1786 "record", "report", "latency", "timehist", NULL 1787 }; 1788 1789 argc = parse_options_subcommand(argc, argv, kwork_options, 1790 kwork_subcommands, kwork_usage, 1791 PARSE_OPT_STOP_AT_NON_OPTION); 1792 if (!argc) 1793 usage_with_options(kwork_usage, kwork_options); 1794 1795 setup_event_list(&kwork, kwork_options, kwork_usage); 1796 sort_dimension__add(&kwork, "id", &kwork.cmp_id); 1797 1798 if (strlen(argv[0]) > 2 && strstarts("record", argv[0])) 1799 return perf_kwork__record(&kwork, argc, argv); 1800 else if (strlen(argv[0]) > 2 && strstarts("report", argv[0])) { 1801 kwork.sort_order = default_report_sort_order; 1802 if (argc > 1) { 1803 argc = parse_options(argc, argv, report_options, report_usage, 0); 1804 if (argc) 1805 usage_with_options(report_usage, report_options); 1806 } 1807 kwork.report = KWORK_REPORT_RUNTIME; 1808 setup_sorting(&kwork, report_options, report_usage); 1809 return perf_kwork__report(&kwork); 1810 } else if (strlen(argv[0]) > 2 && strstarts("latency", argv[0])) { 1811 kwork.sort_order = default_latency_sort_order; 1812 if (argc > 1) { 1813 argc = parse_options(argc, argv, latency_options, latency_usage, 0); 1814 if (argc) 1815 usage_with_options(latency_usage, latency_options); 1816 } 1817 kwork.report = KWORK_REPORT_LATENCY; 1818 setup_sorting(&kwork, latency_options, latency_usage); 1819 return perf_kwork__report(&kwork); 1820 } else if (strlen(argv[0]) > 2 && strstarts("timehist", argv[0])) { 1821 if (argc > 1) { 1822 argc = parse_options(argc, argv, timehist_options, timehist_usage, 0); 1823 if (argc) 1824 usage_with_options(timehist_usage, timehist_options); 1825 } 1826 kwork.report = KWORK_REPORT_TIMEHIST; 1827 return perf_kwork__timehist(&kwork); 1828 } else 1829 usage_with_options(kwork_usage, kwork_options); 1830 1831 return 0; 1832 } 1833