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