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 #include "perf.h" 10 11 #include "util/data.h" 12 #include "util/evlist.h" 13 #include "util/evsel.h" 14 #include "util/header.h" 15 #include "util/kwork.h" 16 #include "util/debug.h" 17 #include "util/session.h" 18 #include "util/symbol.h" 19 #include "util/thread.h" 20 #include "util/string2.h" 21 #include "util/callchain.h" 22 #include "util/evsel_fprintf.h" 23 #include "util/util.h" 24 25 #include <subcmd/pager.h> 26 #include <subcmd/parse-options.h> 27 #include <event-parse.h> 28 29 #include <errno.h> 30 #include <inttypes.h> 31 #include <signal.h> 32 #include <linux/err.h> 33 #include <linux/time64.h> 34 #include <linux/zalloc.h> 35 36 /* 37 * report header elements width 38 */ 39 #define PRINT_CPU_WIDTH 4 40 #define PRINT_COUNT_WIDTH 9 41 #define PRINT_RUNTIME_WIDTH 10 42 #define PRINT_LATENCY_WIDTH 10 43 #define PRINT_TIMESTAMP_WIDTH 17 44 #define PRINT_KWORK_NAME_WIDTH 30 45 #define RPINT_DECIMAL_WIDTH 3 46 #define PRINT_BRACKETPAIR_WIDTH 2 47 #define PRINT_TIME_UNIT_SEC_WIDTH 2 48 #define PRINT_TIME_UNIT_MESC_WIDTH 3 49 #define PRINT_PID_WIDTH 7 50 #define PRINT_TASK_NAME_WIDTH 16 51 #define PRINT_CPU_USAGE_WIDTH 6 52 #define PRINT_CPU_USAGE_DECIMAL_WIDTH 2 53 #define PRINT_CPU_USAGE_HIST_WIDTH 30 54 #define PRINT_RUNTIME_HEADER_WIDTH (PRINT_RUNTIME_WIDTH + PRINT_TIME_UNIT_MESC_WIDTH) 55 #define PRINT_LATENCY_HEADER_WIDTH (PRINT_LATENCY_WIDTH + PRINT_TIME_UNIT_MESC_WIDTH) 56 #define PRINT_TIMEHIST_CPU_WIDTH (PRINT_CPU_WIDTH + PRINT_BRACKETPAIR_WIDTH) 57 #define PRINT_TIMESTAMP_HEADER_WIDTH (PRINT_TIMESTAMP_WIDTH + PRINT_TIME_UNIT_SEC_WIDTH) 58 59 struct sort_dimension { 60 const char *name; 61 int (*cmp)(struct kwork_work *l, struct kwork_work *r); 62 struct list_head list; 63 }; 64 65 static int id_cmp(struct kwork_work *l, struct kwork_work *r) 66 { 67 if (l->cpu > r->cpu) 68 return 1; 69 if (l->cpu < r->cpu) 70 return -1; 71 72 if (l->id > r->id) 73 return 1; 74 if (l->id < r->id) 75 return -1; 76 77 return 0; 78 } 79 80 static int count_cmp(struct kwork_work *l, struct kwork_work *r) 81 { 82 if (l->nr_atoms > r->nr_atoms) 83 return 1; 84 if (l->nr_atoms < r->nr_atoms) 85 return -1; 86 87 return 0; 88 } 89 90 static int runtime_cmp(struct kwork_work *l, struct kwork_work *r) 91 { 92 if (l->total_runtime > r->total_runtime) 93 return 1; 94 if (l->total_runtime < r->total_runtime) 95 return -1; 96 97 return 0; 98 } 99 100 static int max_runtime_cmp(struct kwork_work *l, struct kwork_work *r) 101 { 102 if (l->max_runtime > r->max_runtime) 103 return 1; 104 if (l->max_runtime < r->max_runtime) 105 return -1; 106 107 return 0; 108 } 109 110 static int avg_latency_cmp(struct kwork_work *l, struct kwork_work *r) 111 { 112 u64 avgl, avgr; 113 114 if (!r->nr_atoms) 115 return 1; 116 if (!l->nr_atoms) 117 return -1; 118 119 avgl = l->total_latency / l->nr_atoms; 120 avgr = r->total_latency / r->nr_atoms; 121 122 if (avgl > avgr) 123 return 1; 124 if (avgl < avgr) 125 return -1; 126 127 return 0; 128 } 129 130 static int max_latency_cmp(struct kwork_work *l, struct kwork_work *r) 131 { 132 if (l->max_latency > r->max_latency) 133 return 1; 134 if (l->max_latency < r->max_latency) 135 return -1; 136 137 return 0; 138 } 139 140 static int cpu_usage_cmp(struct kwork_work *l, struct kwork_work *r) 141 { 142 if (l->cpu_usage > r->cpu_usage) 143 return 1; 144 if (l->cpu_usage < r->cpu_usage) 145 return -1; 146 147 return 0; 148 } 149 150 static int id_or_cpu_r_cmp(struct kwork_work *l, struct kwork_work *r) 151 { 152 if (l->id < r->id) 153 return 1; 154 if (l->id > r->id) 155 return -1; 156 157 if (l->id != 0) 158 return 0; 159 160 if (l->cpu < r->cpu) 161 return 1; 162 if (l->cpu > r->cpu) 163 return -1; 164 165 return 0; 166 } 167 168 static int sort_dimension__add(struct perf_kwork *kwork __maybe_unused, 169 const char *tok, struct list_head *list) 170 { 171 size_t i; 172 static struct sort_dimension max_sort_dimension = { 173 .name = "max", 174 .cmp = max_runtime_cmp, 175 }; 176 static struct sort_dimension id_sort_dimension = { 177 .name = "id", 178 .cmp = id_cmp, 179 }; 180 static struct sort_dimension runtime_sort_dimension = { 181 .name = "runtime", 182 .cmp = runtime_cmp, 183 }; 184 static struct sort_dimension count_sort_dimension = { 185 .name = "count", 186 .cmp = count_cmp, 187 }; 188 static struct sort_dimension avg_sort_dimension = { 189 .name = "avg", 190 .cmp = avg_latency_cmp, 191 }; 192 static struct sort_dimension rate_sort_dimension = { 193 .name = "rate", 194 .cmp = cpu_usage_cmp, 195 }; 196 static struct sort_dimension tid_sort_dimension = { 197 .name = "tid", 198 .cmp = id_or_cpu_r_cmp, 199 }; 200 struct sort_dimension *available_sorts[] = { 201 &id_sort_dimension, 202 &max_sort_dimension, 203 &count_sort_dimension, 204 &runtime_sort_dimension, 205 &avg_sort_dimension, 206 &rate_sort_dimension, 207 &tid_sort_dimension, 208 }; 209 210 if (kwork->report == KWORK_REPORT_LATENCY) 211 max_sort_dimension.cmp = max_latency_cmp; 212 213 for (i = 0; i < ARRAY_SIZE(available_sorts); i++) { 214 if (!strcmp(available_sorts[i]->name, tok)) { 215 list_add_tail(&available_sorts[i]->list, list); 216 return 0; 217 } 218 } 219 220 return -1; 221 } 222 223 static void setup_sorting(struct perf_kwork *kwork, 224 const struct option *options, 225 const char * const usage_msg[]) 226 { 227 char *tmp, *tok, *str = strdup(kwork->sort_order); 228 229 for (tok = strtok_r(str, ", ", &tmp); 230 tok; tok = strtok_r(NULL, ", ", &tmp)) { 231 if (sort_dimension__add(kwork, tok, &kwork->sort_list) < 0) 232 usage_with_options_msg(usage_msg, options, 233 "Unknown --sort key: `%s'", tok); 234 } 235 236 pr_debug("Sort order: %s\n", kwork->sort_order); 237 free(str); 238 } 239 240 static struct kwork_atom *atom_new(struct perf_kwork *kwork, 241 struct perf_sample *sample) 242 { 243 unsigned long i; 244 struct kwork_atom_page *page; 245 struct kwork_atom *atom = NULL; 246 247 list_for_each_entry(page, &kwork->atom_page_list, list) { 248 if (!bitmap_full(page->bitmap, NR_ATOM_PER_PAGE)) { 249 i = find_first_zero_bit(page->bitmap, NR_ATOM_PER_PAGE); 250 BUG_ON(i >= NR_ATOM_PER_PAGE); 251 atom = &page->atoms[i]; 252 goto found_atom; 253 } 254 } 255 256 /* 257 * new page 258 */ 259 page = zalloc(sizeof(*page)); 260 if (page == NULL) { 261 pr_err("Failed to zalloc kwork atom page\n"); 262 return NULL; 263 } 264 265 i = 0; 266 atom = &page->atoms[0]; 267 list_add_tail(&page->list, &kwork->atom_page_list); 268 269 found_atom: 270 __set_bit(i, page->bitmap); 271 atom->time = sample->time; 272 atom->prev = NULL; 273 atom->page_addr = page; 274 atom->bit_inpage = i; 275 return atom; 276 } 277 278 static void atom_free(struct kwork_atom *atom) 279 { 280 if (atom->prev != NULL) 281 atom_free(atom->prev); 282 283 __clear_bit(atom->bit_inpage, 284 ((struct kwork_atom_page *)atom->page_addr)->bitmap); 285 } 286 287 static void atom_del(struct kwork_atom *atom) 288 { 289 list_del(&atom->list); 290 atom_free(atom); 291 } 292 293 static int work_cmp(struct list_head *list, 294 struct kwork_work *l, struct kwork_work *r) 295 { 296 int ret = 0; 297 struct sort_dimension *sort; 298 299 BUG_ON(list_empty(list)); 300 301 list_for_each_entry(sort, list, list) { 302 ret = sort->cmp(l, r); 303 if (ret) 304 return ret; 305 } 306 307 return ret; 308 } 309 310 static struct kwork_work *work_search(struct rb_root_cached *root, 311 struct kwork_work *key, 312 struct list_head *sort_list) 313 { 314 int cmp; 315 struct kwork_work *work; 316 struct rb_node *node = root->rb_root.rb_node; 317 318 while (node) { 319 work = container_of(node, struct kwork_work, node); 320 cmp = work_cmp(sort_list, key, work); 321 if (cmp > 0) 322 node = node->rb_left; 323 else if (cmp < 0) 324 node = node->rb_right; 325 else { 326 if (work->name == NULL) 327 work->name = key->name; 328 return work; 329 } 330 } 331 return NULL; 332 } 333 334 static void work_insert(struct rb_root_cached *root, 335 struct kwork_work *key, struct list_head *sort_list) 336 { 337 int cmp; 338 bool leftmost = true; 339 struct kwork_work *cur; 340 struct rb_node **new = &(root->rb_root.rb_node), *parent = NULL; 341 342 while (*new) { 343 cur = container_of(*new, struct kwork_work, node); 344 parent = *new; 345 cmp = work_cmp(sort_list, key, cur); 346 347 if (cmp > 0) 348 new = &((*new)->rb_left); 349 else { 350 new = &((*new)->rb_right); 351 leftmost = false; 352 } 353 } 354 355 rb_link_node(&key->node, parent, new); 356 rb_insert_color_cached(&key->node, root, leftmost); 357 } 358 359 static struct kwork_work *work_new(struct kwork_work *key) 360 { 361 int i; 362 struct kwork_work *work = zalloc(sizeof(*work)); 363 364 if (work == NULL) { 365 pr_err("Failed to zalloc kwork work\n"); 366 return NULL; 367 } 368 369 for (i = 0; i < KWORK_TRACE_MAX; i++) 370 INIT_LIST_HEAD(&work->atom_list[i]); 371 372 work->id = key->id; 373 work->cpu = key->cpu; 374 work->name = key->name; 375 work->class = key->class; 376 return work; 377 } 378 379 static struct kwork_work *work_findnew(struct rb_root_cached *root, 380 struct kwork_work *key, 381 struct list_head *sort_list) 382 { 383 struct kwork_work *work = work_search(root, key, sort_list); 384 385 if (work != NULL) 386 return work; 387 388 work = work_new(key); 389 if (work) 390 work_insert(root, work, sort_list); 391 392 return work; 393 } 394 395 static void profile_update_timespan(struct perf_kwork *kwork, 396 struct perf_sample *sample) 397 { 398 if (!kwork->summary) 399 return; 400 401 if ((kwork->timestart == 0) || (kwork->timestart > sample->time)) 402 kwork->timestart = sample->time; 403 404 if (kwork->timeend < sample->time) 405 kwork->timeend = sample->time; 406 } 407 408 static bool profile_name_match(struct perf_kwork *kwork, 409 struct kwork_work *work) 410 { 411 if (kwork->profile_name && work->name && 412 (strcmp(work->name, kwork->profile_name) != 0)) { 413 return false; 414 } 415 416 return true; 417 } 418 419 static bool profile_event_match(struct perf_kwork *kwork, 420 struct kwork_work *work, 421 struct perf_sample *sample) 422 { 423 int cpu = work->cpu; 424 u64 time = sample->time; 425 struct perf_time_interval *ptime = &kwork->ptime; 426 427 if ((kwork->cpu_list != NULL) && !test_bit(cpu, kwork->cpu_bitmap)) 428 return false; 429 430 if (((ptime->start != 0) && (ptime->start > time)) || 431 ((ptime->end != 0) && (ptime->end < time))) 432 return false; 433 434 /* 435 * report top needs to collect the runtime of all tasks to 436 * calculate the load of each core. 437 */ 438 if ((kwork->report != KWORK_REPORT_TOP) && 439 !profile_name_match(kwork, work)) { 440 return false; 441 } 442 443 profile_update_timespan(kwork, sample); 444 return true; 445 } 446 447 static int work_push_atom(struct perf_kwork *kwork, 448 struct kwork_class *class, 449 enum kwork_trace_type src_type, 450 enum kwork_trace_type dst_type, 451 struct evsel *evsel, 452 struct perf_sample *sample, 453 struct machine *machine, 454 struct kwork_work **ret_work, 455 bool overwrite) 456 { 457 struct kwork_atom *atom, *dst_atom, *last_atom; 458 struct kwork_work *work, key; 459 460 BUG_ON(class->work_init == NULL); 461 class->work_init(kwork, class, &key, src_type, evsel, sample, machine); 462 463 atom = atom_new(kwork, sample); 464 if (atom == NULL) 465 return -1; 466 467 work = work_findnew(&class->work_root, &key, &kwork->cmp_id); 468 if (work == NULL) { 469 atom_free(atom); 470 return -1; 471 } 472 473 if (!profile_event_match(kwork, work, sample)) { 474 atom_free(atom); 475 return 0; 476 } 477 478 if (dst_type < KWORK_TRACE_MAX) { 479 dst_atom = list_last_entry_or_null(&work->atom_list[dst_type], 480 struct kwork_atom, list); 481 if (dst_atom != NULL) { 482 atom->prev = dst_atom; 483 list_del(&dst_atom->list); 484 } 485 } 486 487 if (ret_work != NULL) 488 *ret_work = work; 489 490 if (overwrite) { 491 last_atom = list_last_entry_or_null(&work->atom_list[src_type], 492 struct kwork_atom, list); 493 if (last_atom) { 494 atom_del(last_atom); 495 496 kwork->nr_skipped_events[src_type]++; 497 kwork->nr_skipped_events[KWORK_TRACE_MAX]++; 498 } 499 } 500 501 list_add_tail(&atom->list, &work->atom_list[src_type]); 502 503 return 0; 504 } 505 506 static struct kwork_atom *work_pop_atom(struct perf_kwork *kwork, 507 struct kwork_class *class, 508 enum kwork_trace_type src_type, 509 enum kwork_trace_type dst_type, 510 struct evsel *evsel, 511 struct perf_sample *sample, 512 struct machine *machine, 513 struct kwork_work **ret_work) 514 { 515 struct kwork_atom *atom, *src_atom; 516 struct kwork_work *work, key; 517 518 BUG_ON(class->work_init == NULL); 519 class->work_init(kwork, class, &key, src_type, evsel, sample, machine); 520 521 work = work_findnew(&class->work_root, &key, &kwork->cmp_id); 522 if (ret_work != NULL) 523 *ret_work = work; 524 525 if (work == NULL) 526 return NULL; 527 528 if (!profile_event_match(kwork, work, sample)) 529 return NULL; 530 531 atom = list_last_entry_or_null(&work->atom_list[dst_type], 532 struct kwork_atom, list); 533 if (atom != NULL) 534 return atom; 535 536 src_atom = atom_new(kwork, sample); 537 if (src_atom != NULL) 538 list_add_tail(&src_atom->list, &work->atom_list[src_type]); 539 else { 540 if (ret_work != NULL) 541 *ret_work = NULL; 542 } 543 544 return NULL; 545 } 546 547 static struct kwork_work *find_work_by_id(struct rb_root_cached *root, 548 u64 id, int cpu) 549 { 550 struct rb_node *next; 551 struct kwork_work *work; 552 553 next = rb_first_cached(root); 554 while (next) { 555 work = rb_entry(next, struct kwork_work, node); 556 if ((cpu != -1 && work->id == id && work->cpu == cpu) || 557 (cpu == -1 && work->id == id)) 558 return work; 559 560 next = rb_next(next); 561 } 562 563 return NULL; 564 } 565 566 static struct kwork_class *get_kwork_class(struct perf_kwork *kwork, 567 enum kwork_class_type type) 568 { 569 struct kwork_class *class; 570 571 list_for_each_entry(class, &kwork->class_list, list) { 572 if (class->type == type) 573 return class; 574 } 575 576 return NULL; 577 } 578 579 static void report_update_exit_event(struct kwork_work *work, 580 struct kwork_atom *atom, 581 struct perf_sample *sample) 582 { 583 u64 delta; 584 u64 exit_time = sample->time; 585 u64 entry_time = atom->time; 586 587 if ((entry_time != 0) && (exit_time >= entry_time)) { 588 delta = exit_time - entry_time; 589 if ((delta > work->max_runtime) || 590 (work->max_runtime == 0)) { 591 work->max_runtime = delta; 592 work->max_runtime_start = entry_time; 593 work->max_runtime_end = exit_time; 594 } 595 work->total_runtime += delta; 596 work->nr_atoms++; 597 } 598 } 599 600 static int report_entry_event(struct perf_kwork *kwork, 601 struct kwork_class *class, 602 struct evsel *evsel, 603 struct perf_sample *sample, 604 struct machine *machine) 605 { 606 return work_push_atom(kwork, class, KWORK_TRACE_ENTRY, 607 KWORK_TRACE_MAX, evsel, sample, 608 machine, NULL, true); 609 } 610 611 static int report_exit_event(struct perf_kwork *kwork, 612 struct kwork_class *class, 613 struct evsel *evsel, 614 struct perf_sample *sample, 615 struct machine *machine) 616 { 617 struct kwork_atom *atom = NULL; 618 struct kwork_work *work = NULL; 619 620 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 621 KWORK_TRACE_ENTRY, evsel, sample, 622 machine, &work); 623 if (work == NULL) 624 return -1; 625 626 if (atom != NULL) { 627 report_update_exit_event(work, atom, sample); 628 atom_del(atom); 629 } 630 631 return 0; 632 } 633 634 static void latency_update_entry_event(struct kwork_work *work, 635 struct kwork_atom *atom, 636 struct perf_sample *sample) 637 { 638 u64 delta; 639 u64 entry_time = sample->time; 640 u64 raise_time = atom->time; 641 642 if ((raise_time != 0) && (entry_time >= raise_time)) { 643 delta = entry_time - raise_time; 644 if ((delta > work->max_latency) || 645 (work->max_latency == 0)) { 646 work->max_latency = delta; 647 work->max_latency_start = raise_time; 648 work->max_latency_end = entry_time; 649 } 650 work->total_latency += delta; 651 work->nr_atoms++; 652 } 653 } 654 655 static int latency_raise_event(struct perf_kwork *kwork, 656 struct kwork_class *class, 657 struct evsel *evsel, 658 struct perf_sample *sample, 659 struct machine *machine) 660 { 661 return work_push_atom(kwork, class, KWORK_TRACE_RAISE, 662 KWORK_TRACE_MAX, evsel, sample, 663 machine, NULL, true); 664 } 665 666 static int latency_entry_event(struct perf_kwork *kwork, 667 struct kwork_class *class, 668 struct evsel *evsel, 669 struct perf_sample *sample, 670 struct machine *machine) 671 { 672 struct kwork_atom *atom = NULL; 673 struct kwork_work *work = NULL; 674 675 atom = work_pop_atom(kwork, class, KWORK_TRACE_ENTRY, 676 KWORK_TRACE_RAISE, evsel, sample, 677 machine, &work); 678 if (work == NULL) 679 return -1; 680 681 if (atom != NULL) { 682 latency_update_entry_event(work, atom, sample); 683 atom_del(atom); 684 } 685 686 return 0; 687 } 688 689 static void timehist_save_callchain(struct perf_kwork *kwork, 690 struct perf_sample *sample, 691 struct evsel *evsel, 692 struct machine *machine) 693 { 694 struct symbol *sym; 695 struct thread *thread; 696 struct callchain_cursor_node *node; 697 struct callchain_cursor *cursor; 698 699 if (!kwork->show_callchain || sample->callchain == NULL) 700 return; 701 702 /* want main thread for process - has maps */ 703 thread = machine__findnew_thread(machine, sample->pid, sample->pid); 704 if (thread == NULL) { 705 pr_debug("Failed to get thread for pid %d\n", sample->pid); 706 return; 707 } 708 709 cursor = get_tls_callchain_cursor(); 710 711 if (thread__resolve_callchain(thread, cursor, evsel, sample, 712 NULL, NULL, kwork->max_stack + 2) != 0) { 713 pr_debug("Failed to resolve callchain, skipping\n"); 714 goto out_put; 715 } 716 717 callchain_cursor_commit(cursor); 718 719 while (true) { 720 node = callchain_cursor_current(cursor); 721 if (node == NULL) 722 break; 723 724 sym = node->ms.sym; 725 if (sym) { 726 if (!strcmp(sym->name, "__softirqentry_text_start") || 727 !strcmp(sym->name, "__do_softirq")) 728 sym->ignore = 1; 729 } 730 731 callchain_cursor_advance(cursor); 732 } 733 734 out_put: 735 thread__put(thread); 736 } 737 738 static void timehist_print_event(struct perf_kwork *kwork, 739 struct kwork_work *work, 740 struct kwork_atom *atom, 741 struct perf_sample *sample, 742 struct addr_location *al) 743 { 744 char entrytime[32], exittime[32]; 745 char kwork_name[PRINT_KWORK_NAME_WIDTH]; 746 747 /* 748 * runtime start 749 */ 750 timestamp__scnprintf_usec(atom->time, 751 entrytime, sizeof(entrytime)); 752 printf(" %*s ", PRINT_TIMESTAMP_WIDTH, entrytime); 753 754 /* 755 * runtime end 756 */ 757 timestamp__scnprintf_usec(sample->time, 758 exittime, sizeof(exittime)); 759 printf(" %*s ", PRINT_TIMESTAMP_WIDTH, exittime); 760 761 /* 762 * cpu 763 */ 764 printf(" [%0*d] ", PRINT_CPU_WIDTH, work->cpu); 765 766 /* 767 * kwork name 768 */ 769 if (work->class && work->class->work_name) { 770 work->class->work_name(work, kwork_name, 771 PRINT_KWORK_NAME_WIDTH); 772 printf(" %-*s ", PRINT_KWORK_NAME_WIDTH, kwork_name); 773 } else 774 printf(" %-*s ", PRINT_KWORK_NAME_WIDTH, ""); 775 776 /* 777 *runtime 778 */ 779 printf(" %*.*f ", 780 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 781 (double)(sample->time - atom->time) / NSEC_PER_MSEC); 782 783 /* 784 * delaytime 785 */ 786 if (atom->prev != NULL) 787 printf(" %*.*f ", PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH, 788 (double)(atom->time - atom->prev->time) / NSEC_PER_MSEC); 789 else 790 printf(" %*s ", PRINT_LATENCY_WIDTH, " "); 791 792 /* 793 * callchain 794 */ 795 if (kwork->show_callchain) { 796 struct callchain_cursor *cursor = get_tls_callchain_cursor(); 797 798 if (cursor == NULL) 799 return; 800 801 printf(" "); 802 803 sample__fprintf_sym(sample, al, 0, 804 EVSEL__PRINT_SYM | EVSEL__PRINT_ONELINE | 805 EVSEL__PRINT_CALLCHAIN_ARROW | 806 EVSEL__PRINT_SKIP_IGNORED, 807 cursor, symbol_conf.bt_stop_list, 808 stdout); 809 } 810 811 printf("\n"); 812 } 813 814 static int timehist_raise_event(struct perf_kwork *kwork, 815 struct kwork_class *class, 816 struct evsel *evsel, 817 struct perf_sample *sample, 818 struct machine *machine) 819 { 820 return work_push_atom(kwork, class, KWORK_TRACE_RAISE, 821 KWORK_TRACE_MAX, evsel, sample, 822 machine, NULL, true); 823 } 824 825 static int timehist_entry_event(struct perf_kwork *kwork, 826 struct kwork_class *class, 827 struct evsel *evsel, 828 struct perf_sample *sample, 829 struct machine *machine) 830 { 831 int ret; 832 struct kwork_work *work = NULL; 833 834 ret = work_push_atom(kwork, class, KWORK_TRACE_ENTRY, 835 KWORK_TRACE_RAISE, evsel, sample, 836 machine, &work, true); 837 if (ret) 838 return ret; 839 840 if (work != NULL) 841 timehist_save_callchain(kwork, sample, evsel, machine); 842 843 return 0; 844 } 845 846 static int timehist_exit_event(struct perf_kwork *kwork, 847 struct kwork_class *class, 848 struct evsel *evsel, 849 struct perf_sample *sample, 850 struct machine *machine) 851 { 852 struct kwork_atom *atom = NULL; 853 struct kwork_work *work = NULL; 854 struct addr_location al; 855 int ret = 0; 856 857 addr_location__init(&al); 858 if (machine__resolve(machine, &al, sample) < 0) { 859 pr_debug("Problem processing event, skipping it\n"); 860 ret = -1; 861 goto out; 862 } 863 864 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 865 KWORK_TRACE_ENTRY, evsel, sample, 866 machine, &work); 867 if (work == NULL) { 868 ret = -1; 869 goto out; 870 } 871 872 if (atom != NULL) { 873 work->nr_atoms++; 874 timehist_print_event(kwork, work, atom, sample, &al); 875 atom_del(atom); 876 } 877 878 out: 879 addr_location__exit(&al); 880 return ret; 881 } 882 883 static void top_update_runtime(struct kwork_work *work, 884 struct kwork_atom *atom, 885 struct perf_sample *sample) 886 { 887 u64 delta; 888 u64 exit_time = sample->time; 889 u64 entry_time = atom->time; 890 891 if ((entry_time != 0) && (exit_time >= entry_time)) { 892 delta = exit_time - entry_time; 893 work->total_runtime += delta; 894 } 895 } 896 897 static int top_entry_event(struct perf_kwork *kwork, 898 struct kwork_class *class, 899 struct evsel *evsel, 900 struct perf_sample *sample, 901 struct machine *machine) 902 { 903 return work_push_atom(kwork, class, KWORK_TRACE_ENTRY, 904 KWORK_TRACE_MAX, evsel, sample, 905 machine, NULL, true); 906 } 907 908 static int top_exit_event(struct perf_kwork *kwork, 909 struct kwork_class *class, 910 struct evsel *evsel, 911 struct perf_sample *sample, 912 struct machine *machine) 913 { 914 struct kwork_work *work, *sched_work; 915 struct kwork_class *sched_class; 916 struct kwork_atom *atom; 917 918 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 919 KWORK_TRACE_ENTRY, evsel, sample, 920 machine, &work); 921 if (!work) 922 return -1; 923 924 if (atom) { 925 sched_class = get_kwork_class(kwork, KWORK_CLASS_SCHED); 926 if (sched_class) { 927 sched_work = find_work_by_id(&sched_class->work_root, 928 work->id, work->cpu); 929 if (sched_work) 930 top_update_runtime(work, atom, sample); 931 } 932 atom_del(atom); 933 } 934 935 return 0; 936 } 937 938 static int top_sched_switch_event(struct perf_kwork *kwork, 939 struct kwork_class *class, 940 struct evsel *evsel, 941 struct perf_sample *sample, 942 struct machine *machine) 943 { 944 struct kwork_atom *atom; 945 struct kwork_work *work; 946 947 atom = work_pop_atom(kwork, class, KWORK_TRACE_EXIT, 948 KWORK_TRACE_ENTRY, evsel, sample, 949 machine, &work); 950 if (!work) 951 return -1; 952 953 if (atom) { 954 top_update_runtime(work, atom, sample); 955 atom_del(atom); 956 } 957 958 return top_entry_event(kwork, class, evsel, sample, machine); 959 } 960 961 static struct kwork_class kwork_irq; 962 static int process_irq_handler_entry_event(const struct perf_tool *tool, 963 struct evsel *evsel, 964 struct perf_sample *sample, 965 struct machine *machine) 966 { 967 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 968 969 if (kwork->tp_handler->entry_event) 970 return kwork->tp_handler->entry_event(kwork, &kwork_irq, 971 evsel, sample, machine); 972 return 0; 973 } 974 975 static int process_irq_handler_exit_event(const struct perf_tool *tool, 976 struct evsel *evsel, 977 struct perf_sample *sample, 978 struct machine *machine) 979 { 980 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 981 982 if (kwork->tp_handler->exit_event) 983 return kwork->tp_handler->exit_event(kwork, &kwork_irq, 984 evsel, sample, machine); 985 return 0; 986 } 987 988 static const struct evsel_str_handler irq_tp_handlers[] = { 989 { "irq:irq_handler_entry", process_irq_handler_entry_event, }, 990 { "irq:irq_handler_exit", process_irq_handler_exit_event, }, 991 }; 992 993 static int irq_class_init(struct kwork_class *class, 994 struct perf_session *session) 995 { 996 if (perf_session__set_tracepoints_handlers(session, irq_tp_handlers)) { 997 pr_err("Failed to set irq tracepoints handlers\n"); 998 return -1; 999 } 1000 1001 class->work_root = RB_ROOT_CACHED; 1002 return 0; 1003 } 1004 1005 static void irq_work_init(struct perf_kwork *kwork, 1006 struct kwork_class *class, 1007 struct kwork_work *work, 1008 enum kwork_trace_type src_type __maybe_unused, 1009 struct evsel *evsel __maybe_unused, 1010 struct perf_sample *sample, 1011 struct machine *machine __maybe_unused) 1012 { 1013 work->class = class; 1014 work->cpu = sample->cpu; 1015 1016 if (kwork->report == KWORK_REPORT_TOP) { 1017 work->id = perf_sample__intval_common(sample, "common_pid"); 1018 work->name = NULL; 1019 } else { 1020 work->id = perf_sample__intval(sample, "irq"); 1021 work->name = perf_sample__strval(sample, "name"); 1022 } 1023 } 1024 1025 static void irq_work_name(struct kwork_work *work, char *buf, int len) 1026 { 1027 snprintf(buf, len, "%s:%" PRIu64 "", work->name, work->id); 1028 } 1029 1030 static struct kwork_class kwork_irq = { 1031 .name = "irq", 1032 .type = KWORK_CLASS_IRQ, 1033 .nr_tracepoints = 2, 1034 .tp_handlers = irq_tp_handlers, 1035 .class_init = irq_class_init, 1036 .work_init = irq_work_init, 1037 .work_name = irq_work_name, 1038 }; 1039 1040 static struct kwork_class kwork_softirq; 1041 static int process_softirq_raise_event(const struct perf_tool *tool, 1042 struct evsel *evsel, 1043 struct perf_sample *sample, 1044 struct machine *machine) 1045 { 1046 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1047 1048 if (kwork->tp_handler->raise_event) 1049 return kwork->tp_handler->raise_event(kwork, &kwork_softirq, 1050 evsel, sample, machine); 1051 1052 return 0; 1053 } 1054 1055 static int process_softirq_entry_event(const struct perf_tool *tool, 1056 struct evsel *evsel, 1057 struct perf_sample *sample, 1058 struct machine *machine) 1059 { 1060 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1061 1062 if (kwork->tp_handler->entry_event) 1063 return kwork->tp_handler->entry_event(kwork, &kwork_softirq, 1064 evsel, sample, machine); 1065 1066 return 0; 1067 } 1068 1069 static int process_softirq_exit_event(const struct perf_tool *tool, 1070 struct evsel *evsel, 1071 struct perf_sample *sample, 1072 struct machine *machine) 1073 { 1074 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1075 1076 if (kwork->tp_handler->exit_event) 1077 return kwork->tp_handler->exit_event(kwork, &kwork_softirq, 1078 evsel, sample, machine); 1079 1080 return 0; 1081 } 1082 1083 static const struct evsel_str_handler softirq_tp_handlers[] = { 1084 { "irq:softirq_raise", process_softirq_raise_event, }, 1085 { "irq:softirq_entry", process_softirq_entry_event, }, 1086 { "irq:softirq_exit", process_softirq_exit_event, }, 1087 }; 1088 1089 static int softirq_class_init(struct kwork_class *class, 1090 struct perf_session *session) 1091 { 1092 if (perf_session__set_tracepoints_handlers(session, 1093 softirq_tp_handlers)) { 1094 pr_err("Failed to set softirq tracepoints handlers\n"); 1095 return -1; 1096 } 1097 1098 class->work_root = RB_ROOT_CACHED; 1099 return 0; 1100 } 1101 1102 static char *evsel__softirq_name(struct evsel *evsel, u64 num) 1103 { 1104 char *name = NULL; 1105 bool found = false; 1106 struct tep_print_flag_sym *sym = NULL; 1107 const struct tep_event *tp_format = evsel__tp_format(evsel); 1108 struct tep_print_arg *args = tp_format ? tp_format->print_fmt.args : NULL; 1109 1110 if ((args == NULL) || (args->next == NULL)) 1111 return NULL; 1112 1113 /* skip softirq field: "REC->vec" */ 1114 for (sym = args->next->symbol.symbols; sym != NULL; sym = sym->next) { 1115 if ((eval_flag(sym->value) == (unsigned long long)num) && 1116 (strlen(sym->str) != 0)) { 1117 found = true; 1118 break; 1119 } 1120 } 1121 1122 if (!found) 1123 return NULL; 1124 1125 name = strdup(sym->str); 1126 if (name == NULL) { 1127 pr_err("Failed to copy symbol name\n"); 1128 return NULL; 1129 } 1130 return name; 1131 } 1132 1133 static void softirq_work_init(struct perf_kwork *kwork, 1134 struct kwork_class *class, 1135 struct kwork_work *work, 1136 enum kwork_trace_type src_type __maybe_unused, 1137 struct evsel *evsel, 1138 struct perf_sample *sample, 1139 struct machine *machine __maybe_unused) 1140 { 1141 u64 num; 1142 1143 work->class = class; 1144 work->cpu = sample->cpu; 1145 1146 if (kwork->report == KWORK_REPORT_TOP) { 1147 work->id = perf_sample__intval_common(sample, "common_pid"); 1148 work->name = NULL; 1149 } else { 1150 num = perf_sample__intval(sample, "vec"); 1151 work->id = num; 1152 work->name = evsel__softirq_name(evsel, num); 1153 } 1154 } 1155 1156 static void softirq_work_name(struct kwork_work *work, char *buf, int len) 1157 { 1158 snprintf(buf, len, "(s)%s:%" PRIu64 "", work->name, work->id); 1159 } 1160 1161 static struct kwork_class kwork_softirq = { 1162 .name = "softirq", 1163 .type = KWORK_CLASS_SOFTIRQ, 1164 .nr_tracepoints = 3, 1165 .tp_handlers = softirq_tp_handlers, 1166 .class_init = softirq_class_init, 1167 .work_init = softirq_work_init, 1168 .work_name = softirq_work_name, 1169 }; 1170 1171 static struct kwork_class kwork_workqueue; 1172 static int process_workqueue_activate_work_event(const struct perf_tool *tool, 1173 struct evsel *evsel, 1174 struct perf_sample *sample, 1175 struct machine *machine) 1176 { 1177 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1178 1179 if (kwork->tp_handler->raise_event) 1180 return kwork->tp_handler->raise_event(kwork, &kwork_workqueue, 1181 evsel, sample, machine); 1182 1183 return 0; 1184 } 1185 1186 static int process_workqueue_execute_start_event(const struct perf_tool *tool, 1187 struct evsel *evsel, 1188 struct perf_sample *sample, 1189 struct machine *machine) 1190 { 1191 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1192 1193 if (kwork->tp_handler->entry_event) 1194 return kwork->tp_handler->entry_event(kwork, &kwork_workqueue, 1195 evsel, sample, machine); 1196 1197 return 0; 1198 } 1199 1200 static int process_workqueue_execute_end_event(const struct perf_tool *tool, 1201 struct evsel *evsel, 1202 struct perf_sample *sample, 1203 struct machine *machine) 1204 { 1205 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1206 1207 if (kwork->tp_handler->exit_event) 1208 return kwork->tp_handler->exit_event(kwork, &kwork_workqueue, 1209 evsel, sample, machine); 1210 1211 return 0; 1212 } 1213 1214 static const struct evsel_str_handler workqueue_tp_handlers[] = { 1215 { "workqueue:workqueue_activate_work", process_workqueue_activate_work_event, }, 1216 { "workqueue:workqueue_execute_start", process_workqueue_execute_start_event, }, 1217 { "workqueue:workqueue_execute_end", process_workqueue_execute_end_event, }, 1218 }; 1219 1220 static int workqueue_class_init(struct kwork_class *class, 1221 struct perf_session *session) 1222 { 1223 if (perf_session__set_tracepoints_handlers(session, 1224 workqueue_tp_handlers)) { 1225 pr_err("Failed to set workqueue tracepoints handlers\n"); 1226 return -1; 1227 } 1228 1229 class->work_root = RB_ROOT_CACHED; 1230 return 0; 1231 } 1232 1233 static void workqueue_work_init(struct perf_kwork *kwork __maybe_unused, 1234 struct kwork_class *class, 1235 struct kwork_work *work, 1236 enum kwork_trace_type src_type __maybe_unused, 1237 struct evsel *evsel __maybe_unused, 1238 struct perf_sample *sample, 1239 struct machine *machine) 1240 { 1241 char *modp = NULL; 1242 unsigned long long function_addr = perf_sample__intval(sample, "function"); 1243 1244 work->class = class; 1245 work->cpu = sample->cpu; 1246 work->id = perf_sample__intval(sample, "work"); 1247 work->name = function_addr == 0 ? NULL : 1248 machine__resolve_kernel_addr(machine, &function_addr, &modp); 1249 } 1250 1251 static void workqueue_work_name(struct kwork_work *work, char *buf, int len) 1252 { 1253 if (work->name != NULL) 1254 snprintf(buf, len, "(w)%s", work->name); 1255 else 1256 snprintf(buf, len, "(w)0x%" PRIx64, work->id); 1257 } 1258 1259 static struct kwork_class kwork_workqueue = { 1260 .name = "workqueue", 1261 .type = KWORK_CLASS_WORKQUEUE, 1262 .nr_tracepoints = 3, 1263 .tp_handlers = workqueue_tp_handlers, 1264 .class_init = workqueue_class_init, 1265 .work_init = workqueue_work_init, 1266 .work_name = workqueue_work_name, 1267 }; 1268 1269 static struct kwork_class kwork_sched; 1270 static int process_sched_switch_event(const struct perf_tool *tool, 1271 struct evsel *evsel, 1272 struct perf_sample *sample, 1273 struct machine *machine) 1274 { 1275 struct perf_kwork *kwork = container_of(tool, struct perf_kwork, tool); 1276 1277 if (kwork->tp_handler->sched_switch_event) 1278 return kwork->tp_handler->sched_switch_event(kwork, &kwork_sched, 1279 evsel, sample, machine); 1280 return 0; 1281 } 1282 1283 static const struct evsel_str_handler sched_tp_handlers[] = { 1284 { "sched:sched_switch", process_sched_switch_event, }, 1285 }; 1286 1287 static int sched_class_init(struct kwork_class *class, 1288 struct perf_session *session) 1289 { 1290 if (perf_session__set_tracepoints_handlers(session, 1291 sched_tp_handlers)) { 1292 pr_err("Failed to set sched tracepoints handlers\n"); 1293 return -1; 1294 } 1295 1296 class->work_root = RB_ROOT_CACHED; 1297 return 0; 1298 } 1299 1300 static void sched_work_init(struct perf_kwork *kwork __maybe_unused, 1301 struct kwork_class *class, 1302 struct kwork_work *work, 1303 enum kwork_trace_type src_type, 1304 struct evsel *evsel __maybe_unused, 1305 struct perf_sample *sample, 1306 struct machine *machine __maybe_unused) 1307 { 1308 work->class = class; 1309 work->cpu = sample->cpu; 1310 1311 if (src_type == KWORK_TRACE_EXIT) { 1312 work->id = perf_sample__intval(sample, "prev_pid"); 1313 work->name = strdup(perf_sample__strval(sample, "prev_comm")); 1314 } else if (src_type == KWORK_TRACE_ENTRY) { 1315 work->id = perf_sample__intval(sample, "next_pid"); 1316 work->name = strdup(perf_sample__strval(sample, "next_comm")); 1317 } 1318 } 1319 1320 static void sched_work_name(struct kwork_work *work, char *buf, int len) 1321 { 1322 snprintf(buf, len, "%s", work->name); 1323 } 1324 1325 static struct kwork_class kwork_sched = { 1326 .name = "sched", 1327 .type = KWORK_CLASS_SCHED, 1328 .nr_tracepoints = ARRAY_SIZE(sched_tp_handlers), 1329 .tp_handlers = sched_tp_handlers, 1330 .class_init = sched_class_init, 1331 .work_init = sched_work_init, 1332 .work_name = sched_work_name, 1333 }; 1334 1335 static struct kwork_class *kwork_class_supported_list[KWORK_CLASS_MAX] = { 1336 [KWORK_CLASS_IRQ] = &kwork_irq, 1337 [KWORK_CLASS_SOFTIRQ] = &kwork_softirq, 1338 [KWORK_CLASS_WORKQUEUE] = &kwork_workqueue, 1339 [KWORK_CLASS_SCHED] = &kwork_sched, 1340 }; 1341 1342 static void print_separator(int len) 1343 { 1344 printf(" %.*s\n", len, graph_dotted_line); 1345 } 1346 1347 static int report_print_work(struct perf_kwork *kwork, struct kwork_work *work) 1348 { 1349 int ret = 0; 1350 char kwork_name[PRINT_KWORK_NAME_WIDTH]; 1351 char max_runtime_start[32], max_runtime_end[32]; 1352 char max_latency_start[32], max_latency_end[32]; 1353 1354 printf(" "); 1355 1356 /* 1357 * kwork name 1358 */ 1359 if (work->class && work->class->work_name) { 1360 work->class->work_name(work, kwork_name, 1361 PRINT_KWORK_NAME_WIDTH); 1362 ret += printf(" %-*s |", PRINT_KWORK_NAME_WIDTH, kwork_name); 1363 } else { 1364 ret += printf(" %-*s |", PRINT_KWORK_NAME_WIDTH, ""); 1365 } 1366 1367 /* 1368 * cpu 1369 */ 1370 ret += printf(" %0*d |", PRINT_CPU_WIDTH, work->cpu); 1371 1372 /* 1373 * total runtime 1374 */ 1375 if (kwork->report == KWORK_REPORT_RUNTIME) { 1376 ret += printf(" %*.*f ms |", 1377 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 1378 (double)work->total_runtime / NSEC_PER_MSEC); 1379 } else if (kwork->report == KWORK_REPORT_LATENCY) { // avg delay 1380 ret += printf(" %*.*f ms |", 1381 PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH, 1382 (double)work->total_latency / 1383 work->nr_atoms / NSEC_PER_MSEC); 1384 } 1385 1386 /* 1387 * count 1388 */ 1389 ret += printf(" %*" PRIu64 " |", PRINT_COUNT_WIDTH, work->nr_atoms); 1390 1391 /* 1392 * max runtime, max runtime start, max runtime end 1393 */ 1394 if (kwork->report == KWORK_REPORT_RUNTIME) { 1395 timestamp__scnprintf_usec(work->max_runtime_start, 1396 max_runtime_start, 1397 sizeof(max_runtime_start)); 1398 timestamp__scnprintf_usec(work->max_runtime_end, 1399 max_runtime_end, 1400 sizeof(max_runtime_end)); 1401 ret += printf(" %*.*f ms | %*s s | %*s s |", 1402 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 1403 (double)work->max_runtime / NSEC_PER_MSEC, 1404 PRINT_TIMESTAMP_WIDTH, max_runtime_start, 1405 PRINT_TIMESTAMP_WIDTH, max_runtime_end); 1406 } 1407 /* 1408 * max delay, max delay start, max delay end 1409 */ 1410 else if (kwork->report == KWORK_REPORT_LATENCY) { 1411 timestamp__scnprintf_usec(work->max_latency_start, 1412 max_latency_start, 1413 sizeof(max_latency_start)); 1414 timestamp__scnprintf_usec(work->max_latency_end, 1415 max_latency_end, 1416 sizeof(max_latency_end)); 1417 ret += printf(" %*.*f ms | %*s s | %*s s |", 1418 PRINT_LATENCY_WIDTH, RPINT_DECIMAL_WIDTH, 1419 (double)work->max_latency / NSEC_PER_MSEC, 1420 PRINT_TIMESTAMP_WIDTH, max_latency_start, 1421 PRINT_TIMESTAMP_WIDTH, max_latency_end); 1422 } 1423 1424 printf("\n"); 1425 return ret; 1426 } 1427 1428 static int report_print_header(struct perf_kwork *kwork) 1429 { 1430 int ret; 1431 1432 printf("\n "); 1433 ret = printf(" %-*s | %-*s |", 1434 PRINT_KWORK_NAME_WIDTH, "Kwork Name", 1435 PRINT_CPU_WIDTH, "Cpu"); 1436 1437 if (kwork->report == KWORK_REPORT_RUNTIME) { 1438 ret += printf(" %-*s |", 1439 PRINT_RUNTIME_HEADER_WIDTH, "Total Runtime"); 1440 } else if (kwork->report == KWORK_REPORT_LATENCY) { 1441 ret += printf(" %-*s |", 1442 PRINT_LATENCY_HEADER_WIDTH, "Avg delay"); 1443 } 1444 1445 ret += printf(" %-*s |", PRINT_COUNT_WIDTH, "Count"); 1446 1447 if (kwork->report == KWORK_REPORT_RUNTIME) { 1448 ret += printf(" %-*s | %-*s | %-*s |", 1449 PRINT_RUNTIME_HEADER_WIDTH, "Max runtime", 1450 PRINT_TIMESTAMP_HEADER_WIDTH, "Max runtime start", 1451 PRINT_TIMESTAMP_HEADER_WIDTH, "Max runtime end"); 1452 } else if (kwork->report == KWORK_REPORT_LATENCY) { 1453 ret += printf(" %-*s | %-*s | %-*s |", 1454 PRINT_LATENCY_HEADER_WIDTH, "Max delay", 1455 PRINT_TIMESTAMP_HEADER_WIDTH, "Max delay start", 1456 PRINT_TIMESTAMP_HEADER_WIDTH, "Max delay end"); 1457 } 1458 1459 printf("\n"); 1460 print_separator(ret); 1461 return ret; 1462 } 1463 1464 static void timehist_print_header(void) 1465 { 1466 /* 1467 * header row 1468 */ 1469 printf(" %-*s %-*s %-*s %-*s %-*s %-*s\n", 1470 PRINT_TIMESTAMP_WIDTH, "Runtime start", 1471 PRINT_TIMESTAMP_WIDTH, "Runtime end", 1472 PRINT_TIMEHIST_CPU_WIDTH, "Cpu", 1473 PRINT_KWORK_NAME_WIDTH, "Kwork name", 1474 PRINT_RUNTIME_WIDTH, "Runtime", 1475 PRINT_RUNTIME_WIDTH, "Delaytime"); 1476 1477 /* 1478 * units row 1479 */ 1480 printf(" %-*s %-*s %-*s %-*s %-*s %-*s\n", 1481 PRINT_TIMESTAMP_WIDTH, "", 1482 PRINT_TIMESTAMP_WIDTH, "", 1483 PRINT_TIMEHIST_CPU_WIDTH, "", 1484 PRINT_KWORK_NAME_WIDTH, "(TYPE)NAME:NUM", 1485 PRINT_RUNTIME_WIDTH, "(msec)", 1486 PRINT_RUNTIME_WIDTH, "(msec)"); 1487 1488 /* 1489 * separator 1490 */ 1491 printf(" %.*s %.*s %.*s %.*s %.*s %.*s\n", 1492 PRINT_TIMESTAMP_WIDTH, graph_dotted_line, 1493 PRINT_TIMESTAMP_WIDTH, graph_dotted_line, 1494 PRINT_TIMEHIST_CPU_WIDTH, graph_dotted_line, 1495 PRINT_KWORK_NAME_WIDTH, graph_dotted_line, 1496 PRINT_RUNTIME_WIDTH, graph_dotted_line, 1497 PRINT_RUNTIME_WIDTH, graph_dotted_line); 1498 } 1499 1500 static void print_summary(struct perf_kwork *kwork) 1501 { 1502 u64 time = kwork->timeend - kwork->timestart; 1503 1504 printf(" Total count : %9" PRIu64 "\n", kwork->all_count); 1505 printf(" Total runtime (msec) : %9.3f (%.3f%% load average)\n", 1506 (double)kwork->all_runtime / NSEC_PER_MSEC, 1507 time == 0 ? 0 : (double)kwork->all_runtime / time); 1508 printf(" Total time span (msec) : %9.3f\n", 1509 (double)time / NSEC_PER_MSEC); 1510 } 1511 1512 static unsigned long long nr_list_entry(struct list_head *head) 1513 { 1514 struct list_head *pos; 1515 unsigned long long n = 0; 1516 1517 list_for_each(pos, head) 1518 n++; 1519 1520 return n; 1521 } 1522 1523 static void print_skipped_events(struct perf_kwork *kwork) 1524 { 1525 int i; 1526 const char *const kwork_event_str[] = { 1527 [KWORK_TRACE_RAISE] = "raise", 1528 [KWORK_TRACE_ENTRY] = "entry", 1529 [KWORK_TRACE_EXIT] = "exit", 1530 }; 1531 1532 if ((kwork->nr_skipped_events[KWORK_TRACE_MAX] != 0) && 1533 (kwork->nr_events != 0)) { 1534 printf(" INFO: %.3f%% skipped events (%" PRIu64 " including ", 1535 (double)kwork->nr_skipped_events[KWORK_TRACE_MAX] / 1536 (double)kwork->nr_events * 100.0, 1537 kwork->nr_skipped_events[KWORK_TRACE_MAX]); 1538 1539 for (i = 0; i < KWORK_TRACE_MAX; i++) { 1540 printf("%" PRIu64 " %s%s", 1541 kwork->nr_skipped_events[i], 1542 kwork_event_str[i], 1543 (i == KWORK_TRACE_MAX - 1) ? ")\n" : ", "); 1544 } 1545 } 1546 1547 if (verbose > 0) 1548 printf(" INFO: use %lld atom pages\n", 1549 nr_list_entry(&kwork->atom_page_list)); 1550 } 1551 1552 static void print_bad_events(struct perf_kwork *kwork) 1553 { 1554 if ((kwork->nr_lost_events != 0) && (kwork->nr_events != 0)) { 1555 printf(" INFO: %.3f%% lost events (%ld out of %ld, in %ld chunks)\n", 1556 (double)kwork->nr_lost_events / 1557 (double)kwork->nr_events * 100.0, 1558 kwork->nr_lost_events, kwork->nr_events, 1559 kwork->nr_lost_chunks); 1560 } 1561 } 1562 1563 static void top_print_per_cpu_load(struct perf_kwork *kwork) 1564 { 1565 int i, load_width; 1566 u64 total, load, load_ratio; 1567 struct kwork_top_stat *stat = &kwork->top_stat; 1568 const char *graph_load = "||||||||||||||||||||||||||||||||||||||||||||||||"; 1569 const char *graph_idle = " "; 1570 1571 for (i = 0; i < MAX_NR_CPUS; i++) { 1572 total = stat->cpus_runtime[i].total; 1573 load = stat->cpus_runtime[i].load; 1574 if (test_bit(i, stat->all_cpus_bitmap) && total) { 1575 load_ratio = load * 10000 / total; 1576 load_width = PRINT_CPU_USAGE_HIST_WIDTH * 1577 load_ratio / 10000; 1578 1579 printf("%%Cpu%-*d[%.*s%.*s %*.*f%%]\n", 1580 PRINT_CPU_WIDTH, i, 1581 load_width, graph_load, 1582 PRINT_CPU_USAGE_HIST_WIDTH - load_width, 1583 graph_idle, 1584 PRINT_CPU_USAGE_WIDTH, 1585 PRINT_CPU_USAGE_DECIMAL_WIDTH, 1586 (double)load_ratio / 100); 1587 } 1588 } 1589 } 1590 1591 static void top_print_cpu_usage(struct perf_kwork *kwork) 1592 { 1593 struct kwork_top_stat *stat = &kwork->top_stat; 1594 u64 idle_time = stat->cpus_runtime[MAX_NR_CPUS].idle; 1595 u64 hardirq_time = stat->cpus_runtime[MAX_NR_CPUS].irq; 1596 u64 softirq_time = stat->cpus_runtime[MAX_NR_CPUS].softirq; 1597 int cpus_nr = bitmap_weight(stat->all_cpus_bitmap, MAX_NR_CPUS); 1598 u64 cpus_total_time = stat->cpus_runtime[MAX_NR_CPUS].total; 1599 1600 printf("Total : %*.*f ms, %d cpus\n", 1601 PRINT_RUNTIME_WIDTH, RPINT_DECIMAL_WIDTH, 1602 (double)cpus_total_time / NSEC_PER_MSEC, 1603 cpus_nr); 1604 1605 printf("%%Cpu(s): %*.*f%% id, %*.*f%% hi, %*.*f%% si\n", 1606 PRINT_CPU_USAGE_WIDTH, PRINT_CPU_USAGE_DECIMAL_WIDTH, 1607 cpus_total_time ? (double)idle_time * 100 / cpus_total_time : 0, 1608 1609 PRINT_CPU_USAGE_WIDTH, PRINT_CPU_USAGE_DECIMAL_WIDTH, 1610 cpus_total_time ? (double)hardirq_time * 100 / cpus_total_time : 0, 1611 1612 PRINT_CPU_USAGE_WIDTH, PRINT_CPU_USAGE_DECIMAL_WIDTH, 1613 cpus_total_time ? (double)softirq_time * 100 / cpus_total_time : 0); 1614 1615 top_print_per_cpu_load(kwork); 1616 } 1617 1618 static void top_print_header(struct perf_kwork *kwork __maybe_unused) 1619 { 1620 int ret; 1621 1622 printf("\n "); 1623 ret = printf(" %*s %s%*s%s %*s %*s %-*s", 1624 PRINT_PID_WIDTH, "PID", 1625 1626 kwork->use_bpf ? " " : "", 1627 kwork->use_bpf ? PRINT_PID_WIDTH : 0, 1628 kwork->use_bpf ? "SPID" : "", 1629 kwork->use_bpf ? " " : "", 1630 1631 PRINT_CPU_USAGE_WIDTH, "%CPU", 1632 PRINT_RUNTIME_HEADER_WIDTH + RPINT_DECIMAL_WIDTH, "RUNTIME", 1633 PRINT_TASK_NAME_WIDTH, "COMMAND"); 1634 printf("\n "); 1635 print_separator(ret); 1636 } 1637 1638 static int top_print_work(struct perf_kwork *kwork __maybe_unused, struct kwork_work *work) 1639 { 1640 int ret = 0; 1641 1642 printf(" "); 1643 1644 /* 1645 * pid 1646 */ 1647 ret += printf(" %*" PRIu64 " ", PRINT_PID_WIDTH, work->id); 1648 1649 /* 1650 * tgid 1651 */ 1652 if (kwork->use_bpf) 1653 ret += printf(" %*d ", PRINT_PID_WIDTH, work->tgid); 1654 1655 /* 1656 * cpu usage 1657 */ 1658 ret += printf(" %*.*f ", 1659 PRINT_CPU_USAGE_WIDTH, PRINT_CPU_USAGE_DECIMAL_WIDTH, 1660 (double)work->cpu_usage / 100); 1661 1662 /* 1663 * total runtime 1664 */ 1665 ret += printf(" %*.*f ms ", 1666 PRINT_RUNTIME_WIDTH + RPINT_DECIMAL_WIDTH, RPINT_DECIMAL_WIDTH, 1667 (double)work->total_runtime / NSEC_PER_MSEC); 1668 1669 /* 1670 * command 1671 */ 1672 if (kwork->use_bpf) 1673 ret += printf(" %s%s%s", 1674 work->is_kthread ? "[" : "", 1675 work->name, 1676 work->is_kthread ? "]" : ""); 1677 else 1678 ret += printf(" %-*s", PRINT_TASK_NAME_WIDTH, work->name); 1679 1680 printf("\n"); 1681 return ret; 1682 } 1683 1684 static void work_sort(struct perf_kwork *kwork, 1685 struct kwork_class *class, struct rb_root_cached *root) 1686 { 1687 struct rb_node *node; 1688 struct kwork_work *data; 1689 1690 pr_debug("Sorting %s ...\n", class->name); 1691 for (;;) { 1692 node = rb_first_cached(root); 1693 if (!node) 1694 break; 1695 1696 rb_erase_cached(node, root); 1697 data = rb_entry(node, struct kwork_work, node); 1698 work_insert(&kwork->sorted_work_root, 1699 data, &kwork->sort_list); 1700 } 1701 } 1702 1703 static void perf_kwork__sort(struct perf_kwork *kwork) 1704 { 1705 struct kwork_class *class; 1706 1707 list_for_each_entry(class, &kwork->class_list, list) 1708 work_sort(kwork, class, &class->work_root); 1709 } 1710 1711 static int perf_kwork__check_config(struct perf_kwork *kwork, 1712 struct perf_session *session) 1713 { 1714 int ret; 1715 struct evsel *evsel; 1716 struct kwork_class *class; 1717 1718 static struct trace_kwork_handler report_ops = { 1719 .entry_event = report_entry_event, 1720 .exit_event = report_exit_event, 1721 }; 1722 static struct trace_kwork_handler latency_ops = { 1723 .raise_event = latency_raise_event, 1724 .entry_event = latency_entry_event, 1725 }; 1726 static struct trace_kwork_handler timehist_ops = { 1727 .raise_event = timehist_raise_event, 1728 .entry_event = timehist_entry_event, 1729 .exit_event = timehist_exit_event, 1730 }; 1731 static struct trace_kwork_handler top_ops = { 1732 .entry_event = timehist_entry_event, 1733 .exit_event = top_exit_event, 1734 .sched_switch_event = top_sched_switch_event, 1735 }; 1736 1737 switch (kwork->report) { 1738 case KWORK_REPORT_RUNTIME: 1739 kwork->tp_handler = &report_ops; 1740 break; 1741 case KWORK_REPORT_LATENCY: 1742 kwork->tp_handler = &latency_ops; 1743 break; 1744 case KWORK_REPORT_TIMEHIST: 1745 kwork->tp_handler = &timehist_ops; 1746 break; 1747 case KWORK_REPORT_TOP: 1748 kwork->tp_handler = &top_ops; 1749 break; 1750 default: 1751 pr_debug("Invalid report type %d\n", kwork->report); 1752 return -1; 1753 } 1754 1755 list_for_each_entry(class, &kwork->class_list, list) 1756 if ((class->class_init != NULL) && 1757 (class->class_init(class, session) != 0)) 1758 return -1; 1759 1760 if (kwork->cpu_list != NULL) { 1761 ret = perf_session__cpu_bitmap(session, 1762 kwork->cpu_list, 1763 kwork->cpu_bitmap); 1764 if (ret < 0) { 1765 pr_err("Invalid cpu bitmap\n"); 1766 return -1; 1767 } 1768 } 1769 1770 if (kwork->time_str != NULL) { 1771 ret = perf_time__parse_str(&kwork->ptime, kwork->time_str); 1772 if (ret != 0) { 1773 pr_err("Invalid time span\n"); 1774 return -1; 1775 } 1776 } 1777 1778 list_for_each_entry(evsel, &session->evlist->core.entries, core.node) { 1779 if (kwork->show_callchain && !evsel__has_callchain(evsel)) { 1780 pr_debug("Samples do not have callchains\n"); 1781 kwork->show_callchain = 0; 1782 symbol_conf.use_callchain = 0; 1783 } 1784 } 1785 1786 return 0; 1787 } 1788 1789 static int perf_kwork__read_events(struct perf_kwork *kwork) 1790 { 1791 int ret = -1; 1792 struct perf_session *session = NULL; 1793 1794 struct perf_data data = { 1795 .path = input_name, 1796 .mode = PERF_DATA_MODE_READ, 1797 .force = kwork->force, 1798 }; 1799 1800 session = perf_session__new(&data, &kwork->tool); 1801 if (IS_ERR(session)) { 1802 pr_debug("Error creating perf session\n"); 1803 return PTR_ERR(session); 1804 } 1805 1806 symbol__init(perf_session__env(session)); 1807 1808 if (perf_kwork__check_config(kwork, session) != 0) 1809 goto out_delete; 1810 1811 if (session->tevent.pevent && 1812 tep_set_function_resolver(session->tevent.pevent, 1813 machine__resolve_kernel_addr, 1814 &session->machines.host) < 0) { 1815 pr_err("Failed to set libtraceevent function resolver\n"); 1816 goto out_delete; 1817 } 1818 1819 if (kwork->report == KWORK_REPORT_TIMEHIST) 1820 timehist_print_header(); 1821 1822 ret = perf_session__process_events(session); 1823 if (ret) { 1824 pr_debug("Failed to process events, error %d\n", ret); 1825 goto out_delete; 1826 } 1827 1828 kwork->nr_events = session->evlist->stats.nr_events[0]; 1829 kwork->nr_lost_events = session->evlist->stats.total_lost; 1830 kwork->nr_lost_chunks = session->evlist->stats.nr_events[PERF_RECORD_LOST]; 1831 1832 out_delete: 1833 perf_session__delete(session); 1834 return ret; 1835 } 1836 1837 static void process_skipped_events(struct perf_kwork *kwork, 1838 struct kwork_work *work) 1839 { 1840 int i; 1841 unsigned long long count; 1842 1843 for (i = 0; i < KWORK_TRACE_MAX; i++) { 1844 count = nr_list_entry(&work->atom_list[i]); 1845 kwork->nr_skipped_events[i] += count; 1846 kwork->nr_skipped_events[KWORK_TRACE_MAX] += count; 1847 } 1848 } 1849 1850 static struct kwork_work *perf_kwork_add_work(struct perf_kwork *kwork, 1851 struct kwork_class *class, 1852 struct kwork_work *key) 1853 { 1854 struct kwork_work *work = NULL; 1855 1856 work = work_new(key); 1857 if (work == NULL) 1858 return NULL; 1859 1860 work_insert(&class->work_root, work, &kwork->cmp_id); 1861 return work; 1862 } 1863 1864 static void sig_handler(int sig) 1865 { 1866 /* 1867 * Simply capture termination signal so that 1868 * the program can continue after pause returns 1869 */ 1870 pr_debug("Capture signal %d\n", sig); 1871 } 1872 1873 static int perf_kwork__report_bpf(struct perf_kwork *kwork) 1874 { 1875 int ret; 1876 1877 signal(SIGINT, sig_handler); 1878 signal(SIGTERM, sig_handler); 1879 1880 ret = perf_kwork__trace_prepare_bpf(kwork); 1881 if (ret) 1882 return -1; 1883 1884 printf("Starting trace, Hit <Ctrl+C> to stop and report\n"); 1885 1886 perf_kwork__trace_start(); 1887 1888 /* 1889 * a simple pause, wait here for stop signal 1890 */ 1891 pause(); 1892 1893 perf_kwork__trace_finish(); 1894 1895 perf_kwork__report_read_bpf(kwork); 1896 1897 perf_kwork__report_cleanup_bpf(); 1898 1899 return 0; 1900 } 1901 1902 static int perf_kwork__report(struct perf_kwork *kwork) 1903 { 1904 int ret; 1905 struct rb_node *next; 1906 struct kwork_work *work; 1907 1908 if (kwork->use_bpf) 1909 ret = perf_kwork__report_bpf(kwork); 1910 else 1911 ret = perf_kwork__read_events(kwork); 1912 1913 if (ret != 0) 1914 return -1; 1915 1916 perf_kwork__sort(kwork); 1917 1918 setup_pager(); 1919 1920 ret = report_print_header(kwork); 1921 next = rb_first_cached(&kwork->sorted_work_root); 1922 while (next) { 1923 work = rb_entry(next, struct kwork_work, node); 1924 process_skipped_events(kwork, work); 1925 1926 if (work->nr_atoms != 0) { 1927 report_print_work(kwork, work); 1928 if (kwork->summary) { 1929 kwork->all_runtime += work->total_runtime; 1930 kwork->all_count += work->nr_atoms; 1931 } 1932 } 1933 next = rb_next(next); 1934 } 1935 print_separator(ret); 1936 1937 if (kwork->summary) { 1938 print_summary(kwork); 1939 print_separator(ret); 1940 } 1941 1942 print_bad_events(kwork); 1943 print_skipped_events(kwork); 1944 printf("\n"); 1945 1946 return 0; 1947 } 1948 1949 typedef int (*tracepoint_handler)(const struct perf_tool *tool, 1950 struct evsel *evsel, 1951 struct perf_sample *sample, 1952 struct machine *machine); 1953 1954 static int perf_kwork__process_tracepoint_sample(const struct perf_tool *tool, 1955 union perf_event *event __maybe_unused, 1956 struct perf_sample *sample, 1957 struct machine *machine) 1958 { 1959 struct evsel *evsel = sample->evsel; 1960 int err = 0; 1961 1962 if (evsel->handler != NULL) { 1963 tracepoint_handler f = evsel->handler; 1964 1965 err = f(tool, evsel, sample, machine); 1966 } 1967 1968 return err; 1969 } 1970 1971 static int perf_kwork__timehist(struct perf_kwork *kwork) 1972 { 1973 /* 1974 * event handlers for timehist option 1975 */ 1976 kwork->tool.comm = perf_event__process_comm; 1977 kwork->tool.exit = perf_event__process_exit; 1978 kwork->tool.fork = perf_event__process_fork; 1979 kwork->tool.attr = perf_event__process_attr; 1980 kwork->tool.tracing_data = perf_event__process_tracing_data; 1981 kwork->tool.build_id = perf_event__process_build_id; 1982 kwork->tool.ordered_events = true; 1983 kwork->tool.ordering_requires_timestamps = true; 1984 symbol_conf.use_callchain = kwork->show_callchain; 1985 1986 if (symbol__validate_sym_arguments()) { 1987 pr_err("Failed to validate sym arguments\n"); 1988 return -1; 1989 } 1990 1991 setup_pager(); 1992 1993 return perf_kwork__read_events(kwork); 1994 } 1995 1996 static void top_calc_total_runtime(struct perf_kwork *kwork) 1997 { 1998 struct kwork_class *class; 1999 struct kwork_work *work; 2000 struct rb_node *next; 2001 struct kwork_top_stat *stat = &kwork->top_stat; 2002 2003 class = get_kwork_class(kwork, KWORK_CLASS_SCHED); 2004 if (!class) 2005 return; 2006 2007 next = rb_first_cached(&class->work_root); 2008 while (next) { 2009 work = rb_entry(next, struct kwork_work, node); 2010 BUG_ON(work->cpu >= MAX_NR_CPUS); 2011 stat->cpus_runtime[work->cpu].total += work->total_runtime; 2012 stat->cpus_runtime[MAX_NR_CPUS].total += work->total_runtime; 2013 next = rb_next(next); 2014 } 2015 } 2016 2017 static void top_calc_idle_time(struct perf_kwork *kwork, 2018 struct kwork_work *work) 2019 { 2020 struct kwork_top_stat *stat = &kwork->top_stat; 2021 2022 if (work->id == 0) { 2023 stat->cpus_runtime[work->cpu].idle += work->total_runtime; 2024 stat->cpus_runtime[MAX_NR_CPUS].idle += work->total_runtime; 2025 } 2026 } 2027 2028 static void top_calc_irq_runtime(struct perf_kwork *kwork, 2029 enum kwork_class_type type, 2030 struct kwork_work *work) 2031 { 2032 struct kwork_top_stat *stat = &kwork->top_stat; 2033 2034 if (type == KWORK_CLASS_IRQ) { 2035 stat->cpus_runtime[work->cpu].irq += work->total_runtime; 2036 stat->cpus_runtime[MAX_NR_CPUS].irq += work->total_runtime; 2037 } else if (type == KWORK_CLASS_SOFTIRQ) { 2038 stat->cpus_runtime[work->cpu].softirq += work->total_runtime; 2039 stat->cpus_runtime[MAX_NR_CPUS].softirq += work->total_runtime; 2040 } 2041 } 2042 2043 static void top_subtract_irq_runtime(struct perf_kwork *kwork, 2044 struct kwork_work *work) 2045 { 2046 struct kwork_class *class; 2047 struct kwork_work *data; 2048 unsigned int i; 2049 int irq_class_list[] = {KWORK_CLASS_IRQ, KWORK_CLASS_SOFTIRQ}; 2050 2051 for (i = 0; i < ARRAY_SIZE(irq_class_list); i++) { 2052 class = get_kwork_class(kwork, irq_class_list[i]); 2053 if (!class) 2054 continue; 2055 2056 data = find_work_by_id(&class->work_root, 2057 work->id, work->cpu); 2058 if (!data) 2059 continue; 2060 2061 if (work->total_runtime > data->total_runtime) { 2062 work->total_runtime -= data->total_runtime; 2063 top_calc_irq_runtime(kwork, irq_class_list[i], data); 2064 } 2065 } 2066 } 2067 2068 static void top_calc_cpu_usage(struct perf_kwork *kwork) 2069 { 2070 struct kwork_class *class; 2071 struct kwork_work *work; 2072 struct rb_node *next; 2073 struct kwork_top_stat *stat = &kwork->top_stat; 2074 2075 class = get_kwork_class(kwork, KWORK_CLASS_SCHED); 2076 if (!class) 2077 return; 2078 2079 next = rb_first_cached(&class->work_root); 2080 while (next) { 2081 work = rb_entry(next, struct kwork_work, node); 2082 2083 if (work->total_runtime == 0) 2084 goto next; 2085 2086 __set_bit(work->cpu, stat->all_cpus_bitmap); 2087 2088 top_subtract_irq_runtime(kwork, work); 2089 2090 work->cpu_usage = work->total_runtime * 10000 / 2091 stat->cpus_runtime[work->cpu].total; 2092 2093 top_calc_idle_time(kwork, work); 2094 next: 2095 next = rb_next(next); 2096 } 2097 } 2098 2099 static void top_calc_load_runtime(struct perf_kwork *kwork, 2100 struct kwork_work *work) 2101 { 2102 struct kwork_top_stat *stat = &kwork->top_stat; 2103 2104 if (work->id != 0) { 2105 stat->cpus_runtime[work->cpu].load += work->total_runtime; 2106 stat->cpus_runtime[MAX_NR_CPUS].load += work->total_runtime; 2107 } 2108 } 2109 2110 static void top_merge_tasks(struct perf_kwork *kwork) 2111 { 2112 struct kwork_work *merged_work, *data; 2113 struct kwork_class *class; 2114 struct rb_node *node; 2115 int cpu; 2116 struct rb_root_cached merged_root = RB_ROOT_CACHED; 2117 2118 class = get_kwork_class(kwork, KWORK_CLASS_SCHED); 2119 if (!class) 2120 return; 2121 2122 for (;;) { 2123 node = rb_first_cached(&class->work_root); 2124 if (!node) 2125 break; 2126 2127 rb_erase_cached(node, &class->work_root); 2128 data = rb_entry(node, struct kwork_work, node); 2129 2130 if (!profile_name_match(kwork, data)) 2131 continue; 2132 2133 cpu = data->cpu; 2134 merged_work = find_work_by_id(&merged_root, data->id, 2135 data->id == 0 ? cpu : -1); 2136 if (!merged_work) { 2137 work_insert(&merged_root, data, &kwork->cmp_id); 2138 } else { 2139 merged_work->total_runtime += data->total_runtime; 2140 merged_work->cpu_usage += data->cpu_usage; 2141 } 2142 2143 top_calc_load_runtime(kwork, data); 2144 } 2145 2146 work_sort(kwork, class, &merged_root); 2147 } 2148 2149 static void perf_kwork__top_report(struct perf_kwork *kwork) 2150 { 2151 struct kwork_work *work; 2152 struct rb_node *next; 2153 2154 printf("\n"); 2155 2156 top_print_cpu_usage(kwork); 2157 top_print_header(kwork); 2158 next = rb_first_cached(&kwork->sorted_work_root); 2159 while (next) { 2160 work = rb_entry(next, struct kwork_work, node); 2161 process_skipped_events(kwork, work); 2162 2163 if (work->total_runtime == 0) 2164 goto next; 2165 2166 top_print_work(kwork, work); 2167 2168 next: 2169 next = rb_next(next); 2170 } 2171 2172 printf("\n"); 2173 } 2174 2175 static int perf_kwork__top_bpf(struct perf_kwork *kwork) 2176 { 2177 int ret; 2178 2179 signal(SIGINT, sig_handler); 2180 signal(SIGTERM, sig_handler); 2181 2182 ret = perf_kwork__top_prepare_bpf(kwork); 2183 if (ret) 2184 return -1; 2185 2186 printf("Starting trace, Hit <Ctrl+C> to stop and report\n"); 2187 2188 perf_kwork__top_start(); 2189 2190 /* 2191 * a simple pause, wait here for stop signal 2192 */ 2193 pause(); 2194 2195 perf_kwork__top_finish(); 2196 2197 perf_kwork__top_read_bpf(kwork); 2198 2199 perf_kwork__top_cleanup_bpf(); 2200 2201 return 0; 2202 2203 } 2204 2205 static int perf_kwork__top(struct perf_kwork *kwork) 2206 { 2207 struct __top_cpus_runtime *cpus_runtime; 2208 int ret = 0; 2209 2210 cpus_runtime = calloc(MAX_NR_CPUS + 1, sizeof(struct __top_cpus_runtime)); 2211 if (!cpus_runtime) 2212 return -1; 2213 2214 kwork->top_stat.cpus_runtime = cpus_runtime; 2215 bitmap_zero(kwork->top_stat.all_cpus_bitmap, MAX_NR_CPUS); 2216 2217 if (kwork->use_bpf) 2218 ret = perf_kwork__top_bpf(kwork); 2219 else 2220 ret = perf_kwork__read_events(kwork); 2221 2222 if (ret) 2223 goto out; 2224 2225 top_calc_total_runtime(kwork); 2226 top_calc_cpu_usage(kwork); 2227 top_merge_tasks(kwork); 2228 2229 setup_pager(); 2230 2231 perf_kwork__top_report(kwork); 2232 2233 out: 2234 zfree(&kwork->top_stat.cpus_runtime); 2235 return ret; 2236 } 2237 2238 static void setup_event_list(struct perf_kwork *kwork, 2239 const struct option *options, 2240 const char * const usage_msg[]) 2241 { 2242 int i; 2243 struct kwork_class *class; 2244 char *tmp, *tok, *str; 2245 2246 /* 2247 * set default events list if not specified 2248 */ 2249 if (kwork->event_list_str == NULL) 2250 kwork->event_list_str = "irq, softirq, workqueue"; 2251 2252 str = strdup(kwork->event_list_str); 2253 for (tok = strtok_r(str, ", ", &tmp); 2254 tok; tok = strtok_r(NULL, ", ", &tmp)) { 2255 for (i = 0; i < KWORK_CLASS_MAX; i++) { 2256 class = kwork_class_supported_list[i]; 2257 if (strcmp(tok, class->name) == 0) { 2258 list_add_tail(&class->list, &kwork->class_list); 2259 break; 2260 } 2261 } 2262 if (i == KWORK_CLASS_MAX) { 2263 usage_with_options_msg(usage_msg, options, 2264 "Unknown --event key: `%s'", tok); 2265 } 2266 } 2267 free(str); 2268 2269 pr_debug("Config event list:"); 2270 list_for_each_entry(class, &kwork->class_list, list) 2271 pr_debug(" %s", class->name); 2272 pr_debug("\n"); 2273 } 2274 2275 #define STRDUP_FAIL_EXIT(s) \ 2276 ({ char *_p; \ 2277 _p = strdup(s); \ 2278 if (!_p) { \ 2279 ret = -ENOMEM; \ 2280 goto EXIT; \ 2281 } \ 2282 _p; \ 2283 }) 2284 2285 static int perf_kwork__record(struct perf_kwork *kwork, 2286 int argc, const char **argv) 2287 { 2288 const char **rec_argv; 2289 unsigned int rec_argc, i, j; 2290 struct kwork_class *class; 2291 int ret; 2292 2293 const char *const record_args[] = { 2294 "record", 2295 "-a", 2296 "-R", 2297 "-m", "1024", 2298 "-c", "1", 2299 }; 2300 2301 rec_argc = ARRAY_SIZE(record_args) + argc - 1; 2302 2303 list_for_each_entry(class, &kwork->class_list, list) 2304 rec_argc += 2 * class->nr_tracepoints; 2305 2306 rec_argv = calloc(rec_argc + 1, sizeof(char *)); 2307 if (rec_argv == NULL) 2308 return -ENOMEM; 2309 2310 for (i = 0; i < ARRAY_SIZE(record_args); i++) 2311 rec_argv[i] = STRDUP_FAIL_EXIT(record_args[i]); 2312 2313 list_for_each_entry(class, &kwork->class_list, list) { 2314 for (j = 0; j < class->nr_tracepoints; j++) { 2315 rec_argv[i++] = STRDUP_FAIL_EXIT("-e"); 2316 rec_argv[i++] = STRDUP_FAIL_EXIT(class->tp_handlers[j].name); 2317 } 2318 } 2319 2320 for (j = 1; j < (unsigned int)argc; j++, i++) 2321 rec_argv[i] = STRDUP_FAIL_EXIT(argv[j]); 2322 2323 BUG_ON(i != rec_argc); 2324 2325 pr_debug("record comm: "); 2326 for (j = 0; j < rec_argc; j++) 2327 pr_debug("%s ", rec_argv[j]); 2328 pr_debug("\n"); 2329 2330 ret = cmd_record(i, rec_argv); 2331 2332 EXIT: 2333 for (i = 0; i < rec_argc; i++) 2334 free((void *)rec_argv[i]); 2335 free(rec_argv); 2336 return ret; 2337 } 2338 2339 int cmd_kwork(int argc, const char **argv) 2340 { 2341 static struct perf_kwork kwork = { 2342 .class_list = LIST_HEAD_INIT(kwork.class_list), 2343 .atom_page_list = LIST_HEAD_INIT(kwork.atom_page_list), 2344 .sort_list = LIST_HEAD_INIT(kwork.sort_list), 2345 .cmp_id = LIST_HEAD_INIT(kwork.cmp_id), 2346 .sorted_work_root = RB_ROOT_CACHED, 2347 .tp_handler = NULL, 2348 .profile_name = NULL, 2349 .cpu_list = NULL, 2350 .time_str = NULL, 2351 .force = false, 2352 .event_list_str = NULL, 2353 .summary = false, 2354 .sort_order = NULL, 2355 .show_callchain = false, 2356 .max_stack = 5, 2357 .timestart = 0, 2358 .timeend = 0, 2359 .nr_events = 0, 2360 .nr_lost_chunks = 0, 2361 .nr_lost_events = 0, 2362 .all_runtime = 0, 2363 .all_count = 0, 2364 .nr_skipped_events = { 0 }, 2365 .add_work = perf_kwork_add_work, 2366 }; 2367 static const char default_report_sort_order[] = "runtime, max, count"; 2368 static const char default_latency_sort_order[] = "avg, max, count"; 2369 static const char default_top_sort_order[] = "rate, runtime"; 2370 const struct option kwork_options[] = { 2371 OPT_INCR('v', "verbose", &verbose, 2372 "be more verbose (show symbol address, etc)"), 2373 OPT_BOOLEAN('D', "dump-raw-trace", &dump_trace, 2374 "dump raw trace in ASCII"), 2375 OPT_STRING('k', "kwork", &kwork.event_list_str, "kwork", 2376 "list of kwork to profile (irq, softirq, workqueue, sched, etc)"), 2377 OPT_BOOLEAN('f', "force", &kwork.force, "don't complain, do it"), 2378 OPT_END() 2379 }; 2380 const struct option report_options[] = { 2381 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]", 2382 "sort by key(s): runtime, max, count"), 2383 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 2384 "list of cpus to profile"), 2385 OPT_STRING('n', "name", &kwork.profile_name, "name", 2386 "event name to profile"), 2387 OPT_STRING(0, "time", &kwork.time_str, "str", 2388 "Time span for analysis (start,stop)"), 2389 OPT_STRING('i', "input", &input_name, "file", 2390 "input file name"), 2391 OPT_BOOLEAN('S', "with-summary", &kwork.summary, 2392 "Show summary with statistics"), 2393 #ifdef HAVE_BPF_SKEL 2394 OPT_BOOLEAN('b', "use-bpf", &kwork.use_bpf, 2395 "Use BPF to measure kwork runtime"), 2396 #endif 2397 OPT_PARENT(kwork_options) 2398 }; 2399 const struct option latency_options[] = { 2400 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]", 2401 "sort by key(s): avg, max, count"), 2402 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 2403 "list of cpus to profile"), 2404 OPT_STRING('n', "name", &kwork.profile_name, "name", 2405 "event name to profile"), 2406 OPT_STRING(0, "time", &kwork.time_str, "str", 2407 "Time span for analysis (start,stop)"), 2408 OPT_STRING('i', "input", &input_name, "file", 2409 "input file name"), 2410 #ifdef HAVE_BPF_SKEL 2411 OPT_BOOLEAN('b', "use-bpf", &kwork.use_bpf, 2412 "Use BPF to measure kwork latency"), 2413 #endif 2414 OPT_PARENT(kwork_options) 2415 }; 2416 const struct option timehist_options[] = { 2417 OPT_STRING('k', "vmlinux", &symbol_conf.vmlinux_name, 2418 "file", "vmlinux pathname"), 2419 OPT_STRING(0, "kallsyms", &symbol_conf.kallsyms_name, 2420 "file", "kallsyms pathname"), 2421 OPT_BOOLEAN('g', "call-graph", &kwork.show_callchain, 2422 "Display call chains if present"), 2423 OPT_UINTEGER(0, "max-stack", &kwork.max_stack, 2424 "Maximum number of functions to display backtrace."), 2425 OPT_CALLBACK(0, "symfs", NULL, "directory[,layout]", SYMFS_HELP, 2426 symbol__config_symfs), 2427 OPT_STRING(0, "time", &kwork.time_str, "str", 2428 "Time span for analysis (start,stop)"), 2429 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 2430 "list of cpus to profile"), 2431 OPT_STRING('n', "name", &kwork.profile_name, "name", 2432 "event name to profile"), 2433 OPT_STRING('i', "input", &input_name, "file", 2434 "input file name"), 2435 OPT_PARENT(kwork_options) 2436 }; 2437 const struct option top_options[] = { 2438 OPT_STRING('s', "sort", &kwork.sort_order, "key[,key2...]", 2439 "sort by key(s): rate, runtime, tid"), 2440 OPT_STRING('C', "cpu", &kwork.cpu_list, "cpu", 2441 "list of cpus to profile"), 2442 OPT_STRING('n', "name", &kwork.profile_name, "name", 2443 "event name to profile"), 2444 OPT_STRING(0, "time", &kwork.time_str, "str", 2445 "Time span for analysis (start,stop)"), 2446 OPT_STRING('i', "input", &input_name, "file", 2447 "input file name"), 2448 #ifdef HAVE_BPF_SKEL 2449 OPT_BOOLEAN('b', "use-bpf", &kwork.use_bpf, 2450 "Use BPF to measure task cpu usage"), 2451 #endif 2452 OPT_PARENT(kwork_options) 2453 }; 2454 const char *kwork_usage[] = { 2455 NULL, 2456 NULL 2457 }; 2458 const char * const report_usage[] = { 2459 "perf kwork report [<options>]", 2460 NULL 2461 }; 2462 const char * const latency_usage[] = { 2463 "perf kwork latency [<options>]", 2464 NULL 2465 }; 2466 const char * const timehist_usage[] = { 2467 "perf kwork timehist [<options>]", 2468 NULL 2469 }; 2470 const char * const top_usage[] = { 2471 "perf kwork top [<options>]", 2472 NULL 2473 }; 2474 const char *const kwork_subcommands[] = { 2475 "record", "report", "latency", "timehist", "top", NULL 2476 }; 2477 2478 perf_tool__init(&kwork.tool, /*ordered_events=*/true); 2479 kwork.tool.mmap = perf_event__process_mmap; 2480 kwork.tool.mmap2 = perf_event__process_mmap2; 2481 kwork.tool.sample = perf_kwork__process_tracepoint_sample; 2482 2483 argc = parse_options_subcommand(argc, argv, kwork_options, 2484 kwork_subcommands, kwork_usage, 2485 PARSE_OPT_STOP_AT_NON_OPTION); 2486 if (!argc) 2487 usage_with_options(kwork_usage, kwork_options); 2488 2489 sort_dimension__add(&kwork, "id", &kwork.cmp_id); 2490 2491 if (strlen(argv[0]) > 2 && strstarts("record", argv[0])) { 2492 setup_event_list(&kwork, kwork_options, kwork_usage); 2493 return perf_kwork__record(&kwork, argc, argv); 2494 } else if (strlen(argv[0]) > 2 && strstarts("report", argv[0])) { 2495 kwork.sort_order = default_report_sort_order; 2496 if (argc > 1) { 2497 argc = parse_options(argc, argv, report_options, report_usage, 0); 2498 if (argc) 2499 usage_with_options(report_usage, report_options); 2500 } 2501 kwork.report = KWORK_REPORT_RUNTIME; 2502 setup_sorting(&kwork, report_options, report_usage); 2503 setup_event_list(&kwork, kwork_options, kwork_usage); 2504 return perf_kwork__report(&kwork); 2505 } else if (strlen(argv[0]) > 2 && strstarts("latency", argv[0])) { 2506 kwork.sort_order = default_latency_sort_order; 2507 if (argc > 1) { 2508 argc = parse_options(argc, argv, latency_options, latency_usage, 0); 2509 if (argc) 2510 usage_with_options(latency_usage, latency_options); 2511 } 2512 kwork.report = KWORK_REPORT_LATENCY; 2513 setup_sorting(&kwork, latency_options, latency_usage); 2514 setup_event_list(&kwork, kwork_options, kwork_usage); 2515 return perf_kwork__report(&kwork); 2516 } else if (strlen(argv[0]) > 2 && strstarts("timehist", argv[0])) { 2517 if (argc > 1) { 2518 argc = parse_options(argc, argv, timehist_options, timehist_usage, 0); 2519 if (argc) 2520 usage_with_options(timehist_usage, timehist_options); 2521 } 2522 kwork.report = KWORK_REPORT_TIMEHIST; 2523 setup_event_list(&kwork, kwork_options, kwork_usage); 2524 return perf_kwork__timehist(&kwork); 2525 } else if (strlen(argv[0]) > 2 && strstarts("top", argv[0])) { 2526 kwork.sort_order = default_top_sort_order; 2527 if (argc > 1) { 2528 argc = parse_options(argc, argv, top_options, top_usage, 0); 2529 if (argc) 2530 usage_with_options(top_usage, top_options); 2531 } 2532 kwork.report = KWORK_REPORT_TOP; 2533 if (!kwork.event_list_str) 2534 kwork.event_list_str = "sched, irq, softirq"; 2535 setup_event_list(&kwork, kwork_options, kwork_usage); 2536 setup_sorting(&kwork, top_options, top_usage); 2537 return perf_kwork__top(&kwork); 2538 } else 2539 usage_with_options(kwork_usage, kwork_options); 2540 2541 /* free usage string allocated by parse_options_subcommand */ 2542 free((void *)kwork_usage[0]); 2543 2544 return 0; 2545 } 2546